[07:59:38.135] <TB2> INFO: *** Welcome to pxar ***
[07:59:38.135] <TB2> INFO: *** Today: 2016/09/27
[07:59:38.201] <TB2> INFO: *** Version: f5d3-dirty
[07:59:38.201] <TB2> INFO: readRocDacs: /usr/local/data/M2329_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2329_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//dacParameters35_C15.dat
[07:59:38.202] <TB2> INFO: readTbmDacs: /usr/local/data/M2329_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2329_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//tbmParameters_C0b.dat
[07:59:38.202] <TB2> INFO: readMaskFile: /usr/local/data/M2329_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//defaultMaskFile.dat
[07:59:38.202] <TB2> INFO: readTrimFile: /usr/local/data/M2329_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2329_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//trimParameters35_C15.dat
[07:59:38.290] <TB2> INFO: clk: 4
[07:59:38.290] <TB2> INFO: ctr: 4
[07:59:38.290] <TB2> INFO: sda: 19
[07:59:38.290] <TB2> INFO: tin: 9
[07:59:38.290] <TB2> INFO: level: 15
[07:59:38.290] <TB2> INFO: triggerdelay: 0
[07:59:38.290] <TB2> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[07:59:38.290] <TB2> INFO: Log level: INFO
[07:59:38.303] <TB2> INFO: Found DTB DTB_WXENWR
[07:59:38.314] <TB2> QUIET: Connection to board DTB_WXENWR opened.
[07:59:38.316] <TB2> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 162
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXENWR
MAC address: 40D8551180A2
Hostname: pixelDTB162
Comment:
------------------------------------------------------
[07:59:38.317] <TB2> INFO: RPC call hashes of host and DTB match: 486171790
[07:59:39.865] <TB2> INFO: DUT info:
[07:59:39.865] <TB2> INFO: The DUT currently contains the following objects:
[07:59:39.865] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[07:59:39.865] <TB2> INFO: TBM Core alpha (0): 7 registers set
[07:59:39.865] <TB2> INFO: TBM Core beta (1): 7 registers set
[07:59:39.865] <TB2> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[07:59:39.865] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:39.865] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:40.266] <TB2> INFO: enter 'restricted' command line mode
[07:59:40.266] <TB2> INFO: enter test to run
[07:59:40.266] <TB2> INFO: test: delay setting parameters: ->5<-
[07:59:40.266] <TB2> INFO: delay test by 5 seconds...
[07:59:45.266] <TB2> INFO: enter test to run
[07:59:45.266] <TB2> INFO: test: Xray no parameter change
[07:59:45.266] <TB2> INFO: running: xray
[07:59:45.267] <TB2> INFO: readGainPedestalParameters /usr/local/data/M2329_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2329_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//phCalibrationFitErr35_C15.dat
[07:59:45.405] <TB2> INFO: ######################################################################
[07:59:45.405] <TB2> INFO: PixTestXray::doTest()
[07:59:45.405] <TB2> INFO: ######################################################################
[07:59:45.405] <TB2> INFO: ----------------------------------------------------------------------
[07:59:45.405] <TB2> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[07:59:45.405] <TB2> INFO: ----------------------------------------------------------------------
[07:59:46.128] <TB2> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[07:59:50.208] <TB2> INFO: run duration 4 seconds, buffer almost full (81%), pausing triggers.
[08:00:15.607] <TB2> INFO: Resuming triggers.
[08:00:19.698] <TB2> INFO: run duration 8 seconds, buffer almost full (81%), pausing triggers.
[08:00:45.522] <TB2> INFO: Resuming triggers.
[08:00:49.608] <TB2> INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[08:01:15.303] <TB2> INFO: Resuming triggers.
[08:01:19.387] <TB2> INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[08:01:28.397] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 1 Number of ROCs (5) != Token Chain Length (4)
[08:01:28.397] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[08:01:28.397] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a162 8000 40e0 142 2444 140 2663 40e0 19 266d 859 2a62 40e1 81d 242e 81a 2647 40c1 4d1 2069 e000 c000
[08:01:28.397] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a15c 80b0 4060 40e0 d5 266c 105 284e 401 2882 40c0 b 284f 80 2a6a 9c 222f 708 2a40 40c1 e000 c000
[08:01:28.397] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a15d 80c0 40e0 753 282f 40e0 82 2a4f 40c0 53 2047 519 2a66 74d 284a 74d 204f 40c0 452 284f 84d 2261 e000 c000
[08:01:28.397] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a15e 8000 4040 848 2a60 40c0 811 284a 40c0 c0 284e 755 222f 40e0 71c 2a4c 741 2a4f e000 c000
[08:01:28.397] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a15f 8040 4042 45b 224a 40e2 40e2 2cc 284f 30d 2847 34c 2862 44a 2446 459 2260 481 2a83 40c2 40c1 e000 c000
[08:01:28.397] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a160 80b0 40c0 40c0 da 2248 4c1 2645 562 284d 40c0 741 2a8b 40e0 259 2481 245 226f 29a 2282 4e2 2a69 69a 2461 681 206a 84b 2884 84b 2a4b e000 c000
[08:01:28.397] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a161 80c0 40e1 122 204d 40c1 285 224f 4c8 2045 40c1 488 2864 715 284a 701 2283 40c1 355 2a40 610 264f e000 c000
[08:01:45.963] <TB2> INFO: Resuming triggers.
[08:01:50.044] <TB2> INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[08:02:15.404] <TB2> INFO: Resuming triggers.
[08:02:19.483] <TB2> INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[08:02:45.098] <TB2> INFO: Resuming triggers.
[08:02:49.178] <TB2> INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[08:03:15.284] <TB2> INFO: Resuming triggers.
[08:03:19.361] <TB2> INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[08:03:45.587] <TB2> INFO: Resuming triggers.
[08:03:49.660] <TB2> INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[08:04:15.405] <TB2> INFO: Resuming triggers.
[08:04:19.480] <TB2> INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[08:04:46.054] <TB2> INFO: Resuming triggers.
[08:04:50.120] <TB2> INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[08:05:17.095] <TB2> INFO: Resuming triggers.
[08:05:21.160] <TB2> INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[08:05:46.706] <TB2> INFO: Resuming triggers.
[08:05:50.770] <TB2> INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[08:06:17.564] <TB2> INFO: Resuming triggers.
[08:06:21.629] <TB2> INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[08:06:49.186] <TB2> INFO: Resuming triggers.
[08:06:53.247] <TB2> INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[08:07:19.984] <TB2> INFO: Resuming triggers.
[08:07:24.045] <TB2> INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[08:07:50.394] <TB2> INFO: Resuming triggers.
[08:07:54.454] <TB2> INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[08:08:20.524] <TB2> INFO: Resuming triggers.
[08:08:24.580] <TB2> INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[08:08:51.569] <TB2> INFO: Resuming triggers.
[08:08:55.627] <TB2> INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[08:09:21.849] <TB2> INFO: Resuming triggers.
[08:09:25.903] <TB2> INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[08:09:51.774] <TB2> INFO: Resuming triggers.
[08:09:55.828] <TB2> INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[08:10:20.863] <TB2> INFO: Resuming triggers.
[08:10:24.919] <TB2> INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[08:10:49.956] <TB2> INFO: Resuming triggers.
[08:10:54.008] <TB2> INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[08:11:18.732] <TB2> INFO: Resuming triggers.
[08:11:22.783] <TB2> INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[08:11:48.784] <TB2> INFO: Resuming triggers.
[08:11:51.241] <TB2> INFO: data taking finished, elapsed time: 100 seconds.
[08:12:06.389] <TB2> INFO: PixTest:: pg_setup set to default.
[08:12:06.390] <TB2> INFO: PixTestXray::doPhRun() done
[08:12:06.390] <TB2> INFO: PixTestXray::doTest() done
[08:12:06.581] <TB2> INFO: enter test to run
[08:12:06.581] <TB2> INFO: test: no parameter change
[08:12:06.807] <TB2> QUIET: Connection to board 162 closed.
[08:12:06.886] <TB2> INFO: pXar: this is the end, my friend