[07:59:48.151] <TB3> INFO: *** Welcome to pxar ***
[07:59:48.151] <TB3> INFO: *** Today: 2016/09/27
[07:59:48.219] <TB3> INFO: *** Version: f5d3-dirty
[07:59:48.219] <TB3> INFO: readRocDacs: /usr/local/data/M2338_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2338_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//dacParameters35_C15.dat
[07:59:48.220] <TB3> INFO: readTbmDacs: /usr/local/data/M2338_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2338_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//tbmParameters_C0b.dat
[07:59:48.220] <TB3> INFO: readMaskFile: /usr/local/data/M2338_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//defaultMaskFile.dat
[07:59:48.220] <TB3> INFO: readTrimFile: /usr/local/data/M2338_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2338_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//trimParameters35_C15.dat
[07:59:48.308] <TB3> INFO: clk: 4
[07:59:48.308] <TB3> INFO: ctr: 4
[07:59:48.308] <TB3> INFO: sda: 19
[07:59:48.308] <TB3> INFO: tin: 9
[07:59:48.308] <TB3> INFO: level: 15
[07:59:48.308] <TB3> INFO: triggerdelay: 0
[07:59:48.308] <TB3> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[07:59:48.308] <TB3> INFO: Log level: INFO
[07:59:48.320] <TB3> INFO: Found DTB DTB_WWV6Z5
[07:59:48.331] <TB3> QUIET: Connection to board DTB_WWV6Z5 opened.
[07:59:48.333] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 121
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWV6Z5
MAC address: 40D855118079
Hostname: pixelDTB121
Comment:
------------------------------------------------------
[07:59:48.335] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[07:59:49.888] <TB3> INFO: DUT info:
[07:59:49.888] <TB3> INFO: The DUT currently contains the following objects:
[07:59:49.888] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[07:59:49.888] <TB3> INFO: TBM Core alpha (0): 7 registers set
[07:59:49.888] <TB3> INFO: TBM Core beta (1): 7 registers set
[07:59:49.888] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[07:59:49.888] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.888] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.888] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.888] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.888] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.888] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.888] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.889] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.889] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.889] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.889] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.889] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.889] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.889] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.889] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:49.889] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[07:59:50.290] <TB3> INFO: enter 'restricted' command line mode
[07:59:50.290] <TB3> INFO: enter test to run
[07:59:50.290] <TB3> INFO: test: delay setting parameters: ->5<-
[07:59:50.290] <TB3> INFO: delay test by 5 seconds...
[07:59:55.290] <TB3> INFO: enter test to run
[07:59:55.290] <TB3> INFO: test: Xray no parameter change
[07:59:55.290] <TB3> INFO: running: xray
[07:59:55.290] <TB3> INFO: readGainPedestalParameters /usr/local/data/M2338_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2338_XrayQualification_2016-09-27_09h42m_1474962139//005_HRData_150//phCalibrationFitErr35_C15.dat
[07:59:55.479] <TB3> INFO: ######################################################################
[07:59:55.479] <TB3> INFO: PixTestXray::doTest()
[07:59:55.479] <TB3> INFO: ######################################################################
[07:59:55.479] <TB3> INFO: ----------------------------------------------------------------------
[07:59:55.479] <TB3> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[07:59:55.479] <TB3> INFO: ----------------------------------------------------------------------
[07:59:56.206] <TB3> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[08:00:00.927] <TB3> INFO: run duration 4 seconds, buffer almost full (81%), pausing triggers.
[08:00:26.979] <TB3> INFO: Resuming triggers.
[08:00:31.705] <TB3> INFO: run duration 9 seconds, buffer almost full (81%), pausing triggers.
[08:00:59.052] <TB3> INFO: Resuming triggers.
[08:01:03.773] <TB3> INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[08:01:30.535] <TB3> INFO: Resuming triggers.
[08:01:35.256] <TB3> INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[08:02:00.652] <TB3> INFO: Resuming triggers.
[08:02:05.368] <TB3> INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[08:02:31.457] <TB3> INFO: Resuming triggers.
[08:02:36.173] <TB3> INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[08:03:02.165] <TB3> INFO: Resuming triggers.
[08:03:06.878] <TB3> INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[08:03:32.937] <TB3> INFO: Resuming triggers.
[08:03:37.647] <TB3> INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[08:04:03.536] <TB3> INFO: Resuming triggers.
[08:04:08.240] <TB3> INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[08:04:14.345] <TB3> WARNING: Channel 2 ROC 3: Readback start marker after 3 readouts!
[08:04:14.345] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 2 Number of ROCs (5) != Token Chain Length (4)
[08:04:14.345] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[08:04:14.345] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a254 80b0 4810 1c 2060 109 286d 210 2a63 21a 268e 299 2660 2c2 2081 319 206f 819 246c 4810 611 2046 858 2649 4810 118 204d 25c 2664 291 266e 41c 284d 60b 204c 4810 dc 2228 401 224f 441 204f e000 c000
[08:04:14.345] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a24e 8000 4810 553 2465 540 284d 540 2681 808 2a65 4810 98 2447 82 2862 652 246f 818 266c 4812 310 224c 350 204c 41d 284f 4ca 242c 758 264f 4812 702 2a43 e000 c000
[08:04:14.345] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a24f 8040 4812 4812 4c1 2048 4811 21d 2685 25c 264f 48c 2046 481 2464 488 224a 51d 2a40 4811 e000 c000
[08:04:14.345] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a250 80b0 4811 109 2664 10c 2685 4d3 2064 68b 2268 74d 244c 4811 3 286f 310 2262 410 2644 48c 244e 4810 44d 2a69 4811 e000 c000
[08:04:14.345] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a251 80c0 4810 11d 226f 24a 204a 288 2246 759 2264 840 2464 84d 2263 4810 658 2a61 4811 560 282e 4813 d90 2334 4810 cc 284b e000 c000
[08:04:14.345] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a252 8000 4810 d 2080 281 2863 401 2849 483 2060 658 2227 4810 255 286a 4810 1a 2867 1 2063 93 288a 298 2287 4811 c5 2840 121 2a63 240 2465 355 2062 819 2243 e000 c000
[08:04:14.345] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a253 8040 4810 50d 2a4f 853 2a4d 4811 24c 282d 2ca 2a49 74b 2666 4810 12 2a47 282 2862 513 284a 4811 e000 c000
[08:04:33.885] <TB3> INFO: Resuming triggers.
[08:04:38.589] <TB3> INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[08:05:05.079] <TB3> INFO: Resuming triggers.
[08:05:09.776] <TB3> INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[08:05:36.132] <TB3> INFO: Resuming triggers.
[08:05:40.829] <TB3> INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[08:06:08.006] <TB3> INFO: Resuming triggers.
[08:06:12.698] <TB3> INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[08:06:39.242] <TB3> INFO: Resuming triggers.
[08:06:43.933] <TB3> INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[08:07:10.013] <TB3> INFO: Resuming triggers.
[08:07:14.707] <TB3> INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[08:07:40.309] <TB3> INFO: Resuming triggers.
[08:07:45.000] <TB3> INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[08:08:11.538] <TB3> INFO: Resuming triggers.
[08:08:16.226] <TB3> INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[08:08:42.289] <TB3> INFO: Resuming triggers.
[08:08:46.977] <TB3> INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[08:09:13.210] <TB3> INFO: Resuming triggers.
[08:09:17.895] <TB3> INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[08:09:44.703] <TB3> INFO: Resuming triggers.
[08:09:49.390] <TB3> INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[08:10:15.852] <TB3> INFO: Resuming triggers.
[08:10:20.534] <TB3> INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[08:10:44.961] <TB3> INFO: Resuming triggers.
[08:10:46.268] <TB3> INFO: data taking finished, elapsed time: 100 seconds.
[08:10:53.726] <TB3> INFO: PixTest:: pg_setup set to default.
[08:10:53.727] <TB3> INFO: PixTestXray::doPhRun() done
[08:10:53.727] <TB3> INFO: PixTestXray::doTest() done
[08:10:53.916] <TB3> INFO: enter test to run
[08:10:53.916] <TB3> INFO: test: no parameter change
[08:10:54.219] <TB3> QUIET: Connection to board 121 closed.
[08:10:54.299] <TB3> INFO: pXar: this is the end, my friend