[10:42:48.209] INFO: *** Welcome to pxar ***
[10:42:48.209] INFO: *** Today: 2016/05/24
[10:42:48.225] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:42:48.225] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//dacParameters35_C15.dat
[10:42:48.264] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:42:48.264] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//defaultMaskFile.dat
[10:42:48.266] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C15.dat
[10:42:48.343] INFO: clk: 4
[10:42:48.343] INFO: ctr: 4
[10:42:48.343] INFO: sda: 19
[10:42:48.343] INFO: tin: 9
[10:42:48.343] INFO: level: 15
[10:42:48.343] INFO: triggerdelay: 0
[10:42:48.343] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:42:48.343] INFO: Log level: INFO
[10:42:48.362] QUIET: Connection to board DTB_WREKRL opened.
[10:42:48.365] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[10:42:48.368] INFO: RPC call hashes of host and DTB match: 398089610
[10:42:49.900] INFO: DUT info:
[10:42:49.900] INFO: The DUT currently contains the following objects:
[10:42:49.900] INFO: 2 TBM Cores tbm08c (2 ON)
[10:42:49.900] INFO: TBM Core alpha (0): 7 registers set
[10:42:49.900] INFO: TBM Core beta (1): 7 registers set
[10:42:49.900] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:42:49.900] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.900] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:49.901] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:42:50.312] INFO: enter 'restricted' command line mode
[10:42:50.312] INFO: enter test to run
[10:43:03.641] INFO: test: PixelAlive no parameter change
[10:43:03.641] INFO: running: pixelalive
[10:43:03.650] INFO: ----------------------------------------------------------------------
[10:43:03.650] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:43:03.650] INFO: ----------------------------------------------------------------------
[10:43:03.967] INFO: Expecting 41600 events.
[10:43:08.305] INFO: 41600 events read in total (3619ms).
[10:43:08.470] INFO: Test took 4817ms.
[10:43:08.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:08.746] INFO: PixTestAlive::aliveTest() done
[10:43:08.746] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 1
[10:43:08.781] INFO: enter test to run
[10:44:30.040] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:44:30.040] INFO: running: highrate
[10:44:30.041] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:44:30.308] INFO: ----------------------------------------------------------------------
[10:44:30.308] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:44:30.308] INFO: ----------------------------------------------------------------------
[10:44:30.308] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:44:30.308] INFO: edge/corner pixel THR is adjusted
[10:44:30.308] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:44:31.267] INFO: Collecting data for 5 seconds...
[10:44:36.283] INFO: Done with hot pixel readout
[10:44:47.794] INFO: PixTest:: pg_setup set to default.
[10:44:47.795] INFO: 0 hot pixels found in step 0
[10:44:47.807] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:44:47.812] INFO: PixTest::trimHotPixels() done
[10:44:47.852] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C0.dat
[10:44:47.857] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C1.dat
[10:44:47.862] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C2.dat
[10:44:47.868] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C3.dat
[10:44:47.873] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C4.dat
[10:44:47.878] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C5.dat
[10:44:47.883] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C6.dat
[10:44:47.888] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C7.dat
[10:44:47.894] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C8.dat
[10:44:47.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C9.dat
[10:44:47.904] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C10.dat
[10:44:47.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C11.dat
[10:44:47.914] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C12.dat
[10:44:47.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C13.dat
[10:44:47.925] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C14.dat
[10:44:47.930] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C15.dat
[10:44:47.935] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//defaultMaskFile.dat
[10:44:47.945] INFO: enter test to run
[10:45:29.576] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:45:29.576] INFO: running: highrate
[10:45:29.580] INFO: ----------------------------------------------------------------------
[10:45:29.580] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:45:29.580] INFO: ----------------------------------------------------------------------
[10:45:29.580] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:45:29.580] INFO: edge/corner pixel THR is adjusted
[10:45:29.580] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:45:30.538] INFO: Collecting data for 1 seconds...
[10:45:31.541] INFO: Done with hot pixel readout
[10:45:35.471] INFO: PixTest:: pg_setup set to default.
[10:45:35.472] INFO: 0 hot pixels found in step 0
[10:45:35.477] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:45:35.574] INFO: PixTest::trimHotPixels() done
[10:45:35.574] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C0.dat
[10:45:35.584] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C1.dat
[10:45:35.589] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C2.dat
[10:45:35.594] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C3.dat
[10:45:35.599] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C4.dat
[10:45:35.605] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C5.dat
[10:45:35.622] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C6.dat
[10:45:35.632] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C7.dat
[10:45:35.637] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C8.dat
[10:45:35.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C9.dat
[10:45:35.647] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C10.dat
[10:45:35.653] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C11.dat
[10:45:35.658] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C12.dat
[10:45:35.663] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C13.dat
[10:45:35.669] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C14.dat
[10:45:35.674] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C15.dat
[10:45:35.679] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//defaultMaskFile.dat
[10:45:35.692] INFO: enter test to run
[10:46:15.959] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:46:15.960] INFO: running: xray
[10:46:15.961] INFO: ----------------------------------------------------------------------
[10:46:15.961] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:46:15.961] INFO: ----------------------------------------------------------------------
[10:46:16.925] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:46:28.600] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:46:58.238] INFO: Resuming triggers.
[10:47:09.918] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:47:39.560] INFO: Resuming triggers.
[10:47:51.240] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:48:20.871] INFO: Resuming triggers.
[10:48:32.552] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:49:02.187] INFO: Resuming triggers.
[10:49:13.866] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[10:49:43.550] INFO: Resuming triggers.
[10:49:55.229] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:50:24.865] INFO: Resuming triggers.
[10:50:36.542] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:51:06.180] INFO: Resuming triggers.
[10:51:17.856] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[10:51:47.206] INFO: Resuming triggers.
[10:51:54.120] INFO: data taking finished, elapsed time: 100 seconds.
[10:52:12.230] INFO: PixTest:: pg_setup set to default.
[10:52:12.233] INFO: PixTestXray::doPhRun() done
[10:52:12.370] INFO: enter test to run
[10:52:55.381] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:52:55.381] INFO: running: xray
[10:52:55.382] INFO: ----------------------------------------------------------------------
[10:52:55.382] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:52:55.382] INFO: ----------------------------------------------------------------------
[10:52:56.345] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:53:03.139] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:53:33.642] INFO: Resuming triggers.
[10:53:40.437] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:54:10.660] INFO: Resuming triggers.
[10:54:17.457] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[10:54:47.832] INFO: Resuming triggers.
[10:54:54.627] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[10:55:24.941] INFO: Resuming triggers.
[10:55:31.740] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:56:02.133] INFO: Resuming triggers.
[10:56:08.930] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[10:56:39.344] INFO: Resuming triggers.
[10:56:46.143] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[10:56:46.351] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[10:56:46.351] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a073 8040 43c8 d 2a49 2c1 2483 43c9 2d9 284d 43c8 511 2443 43c9 10d 2849 43c8 21 204f 4d4 2264 43c9 115 206e 43c8 15 2249 43c9 64c 2440 e000 c000
[10:56:46.351] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06d 80c0 4388 213 2848 4da 2a42 698 2225 4388 4388 40c 2248 515 2a46 4388 540 244f 69c 224c 4388 40b 2467 4388 55b 2a49 4388 249 2862 502 2668 502 2a62 809 2444 4388 5b 244a 154 2266 4c4 262f e000 c000
[10:56:46.351] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06e 8000 4388 20 244c 153 2049 155 2248 458 2242 4388 4388 440 2640 842 2242 4388 4388 48c 2a4d 4388 4388 751 284a 4388 9 2841 e000 c000
[10:56:46.351] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06f 8040 438a 69a 2a4a 85a 2a46 438a 438a 410 2a4f 4d5 2248 84c 2645 438a 11b 264f 438a 438a 4b 2a4b 30b 2262 421 264f 438a 15 2263 438a e000 c000
[10:56:46.351] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a070 80b1 4388 21b 224f 751 244a 4388 459 264f 55c 2a49 4388 44b 2045 4388 44a 286b 455 224f 4388 410 2842 4388 349 2840 65c 2281 708 2062 4388 5 2a6c 4388 e000 d000
[10:56:46.351] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a071 80c0 43c8 43c8 515 2640 43c8 93 2641 494 2649 43c8 12 2649 43c9 43c9 295 284c 552 2a2d 43c9 293 2265 68a 282e 844 2469 43c9 15a 2864 2cc 224b e000 c000
[10:56:46.351] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a072 8000 43c8 9a 2644 43c8 43c9 43c9 6d4 2040 43c8 55b 2686 55b 2a82 70d 246e 715 264f 43c8 43c9 159 2245 159 2642 43c9 103 2443 20a 244c 451 288c e000 c000
[10:57:16.614] INFO: Resuming triggers.
[10:57:23.414] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[10:57:53.820] INFO: Resuming triggers.
[10:58:00.620] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[10:58:00.741] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (0) != Token Chain Length (8)
[10:58:00.741] ERROR: <datapipe.cc/CheckEventID:L463> Channel 1 Event ID mismatch: local ID (103) != TBM ID (96)
[10:58:00.741] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[10:58:00.741] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (103) != TBM ID (104)
[10:58:00.742] ERROR: <datapipe.cc/CheckEventID:L463> Channel 1 Event ID mismatch: local ID (97) != TBM ID (104)
[10:58:00.742] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06b 8040 43c8 715 284e 43c8 43c8 43c8 414 282f 709 284f 43c8 28d 2481 690 2266 43c8 649 206f 43c8 55b 246a 754 284e 43c8 48 2043 e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a065 80c0 4388 4388 d2 284f 152 2242 4388 29c 2242 6c4 244a 4388 2cd 2840 2cd 2644 4388 4388 214 262d 4388 148 222e 4388 14b 284e e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a066 8000 4388 4388 4388 2e1 2462 2e1 2045 453 224f 552 284c 6a1 2481 4388 4388 494 2a6d 4388 68d 2a4a 84d 2062 855 2a65 4388 803 2468 4388 e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a060 c00c
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a068 80b1 43c8 55 2269 255 2046 43c8 5d 286f 43c8 350 244a 543 2a4e 43c8 35b 224b 850 2264 43c8 14 2045 4c8 2486 685 2a4f 688 2244 812 2880 43c8 cb 244f 60b 2265 43c8 5 2640 408 244b 4d1 2a6d 43c8 43 284f 43 2449 e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a069 80c0 43c8 43c8 761 226a 43c8 655 2a4d 43c8 515 2243 43c8 2cb 2a6e 721 22a2 43c8 22 2445 43c8 844 2243 43c8 e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06a 8000 43c8 62 2069 29c 2a46 43c8 69c 2a44 855 2469 43c8 84d 2642 43c8 14a 2a46 250 2a2b 41d 2846 508 2242 43c8 2c8 2846 43c8 43c8 43c8 e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a16b 8040 43c8 28a 282c 40a 2a43 43c8 2c4 2026 44b 2885 71b 206d 43c8 c 2a47 19 2280 29b 2241 43c8 6dd 264d 43c8 43c8 43c9 71a 2843 43c8 e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a165 80c0 4388 818 282e 4388 211 2865 4388 4c4 2a4d 4388 304 2442 31b 22a4 44d 226a 4388 644 2643 4388 4388 4388 e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a166 8000 4388 4388 652 2027 65c 262e 4388 4d0 226a 4388 70d 2a49 713 2a6a 4388 4388 1a 2044 12 262b 4388 45c 2666 4388 5b 2041 dd 2845 15b 2264 e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a160 801e 558 2343 64c 43c8 405 206c 43c8 64b 2847 848 266a 43c8 43c8 43c8 442 202d 43c8 43c8 e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a168 80b1 43c8 43c8 43c8 43c8 43c8 40d 2a6b 43c8 43ca 43c8 661 2665 e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a169 80c0 43c8 43c8 11b 2449 4e1 206e 43c8 351 244f 459 282e 85b 284f 43c8 2dd 2a4f 342 2441 43c8 43c8 c8 262e 43c9 43c8 61 264a e000 c000
[10:58:00.742] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a16a 8000 43c8 43c8 5b 2a4e 43c8 662 2a40 43c8 60b 2865 43c8 21 2862 13 226b 60 2462 514 2221 718 262c 43c8 43c9 43c8 e000 c000
[10:58:31.338] INFO: Resuming triggers.
[10:58:38.138] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[10:59:08.852] INFO: Resuming triggers.
[10:59:15.649] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[10:59:46.039] INFO: Resuming triggers.
[10:59:52.836] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:00:23.177] INFO: Resuming triggers.
[11:00:29.976] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[11:01:00.317] INFO: Resuming triggers.
[11:01:07.116] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[11:01:07.403] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[11:01:07.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b9 80c0 43c8 43c8 43c8 488 2644 43c8 5c 2840 43c8 349 2a4f 490 2444 55a 2268 55a 2665 43c8 43c9 43c8 6dc 2269 e000 c000
[11:01:07.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b3 8040 4388 4d1 2841 4389 c0 2446 2c2 2441 4388 448 2840 61c 2a82 808 264e 4389 409 2a42 4388 4389 4388 4388 e000 c000
[11:01:07.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b4 80b1 4388 80b 2449 4388 144 2648 2cc 2a4b 618 244c 4388 48a 242d 4388 4388 4388 113 206a 4388 608 2246 4388 e000 c000
[11:01:07.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b5 80c0 4388 818 2242 4388 449 284a 4388 4388 291 284a 4388 6c1 2846 4388 4388 4388 e000 c000
[11:01:07.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b6 8000 4388 610 2446 691 2468 4388 4dd 2a48 653 284e 4388 a0 2a66 55b 2661 4388 d2 246a c4 262e 159 2048 4388 6a0 202c 4388 4388 759 284f 4388 e000 d000
[11:01:07.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b7 8040 43c8 818 244c 43c8 43c8 650 2426 43c8 21a 2062 353 2269 4d3 284f 43c8 43c8 43c8 43c8 e000 c000
[11:01:07.403] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b8 80b1 43c8 61b 2268 64d 2646 719 2848 709 2240 43c8 58 2441 43c8 8d 2a88 519 2442 43c8 161 264e 51b 2485 43c8 405 264a 43c8 112 2a4b 2c9 2861 2c9 2a62 43ca 43c8 660 224f e000 c000
[11:01:38.147] INFO: Resuming triggers.
[11:01:43.313] INFO: data taking finished, elapsed time: 100 seconds.
[11:02:06.925] INFO: PixTest:: pg_setup set to default.
[11:02:06.928] INFO: PixTestXray::doPhRun() done
[11:02:07.079] INFO: enter test to run
[11:02:26.928] INFO: test: timing no parameter change
[11:02:26.928] INFO: running: timing
[11:02:26.932] INFO: ######################################################################
[11:02:26.932] INFO: PixTestTiming::doTest()
[11:02:26.932] INFO: ######################################################################
[11:02:26.932] INFO: ----------------------------------------------------------------------
[11:02:26.932] INFO: PixTestTiming::TBMPhaseScan()
[11:02:26.932] INFO: ----------------------------------------------------------------------
[11:12:12.181] INFO: TBM Phase Settings: 232
[11:12:12.181] INFO: 400MHz Phase: 2
[11:12:12.181] INFO: 160MHz Phase: 7
[11:12:12.181] INFO: Functional Phase Area: 3
[11:12:12.184] INFO: Test took 585252 ms.
[11:12:12.184] INFO: PixTestTiming::TBMPhaseScan() done.
[11:12:12.184] INFO: ----------------------------------------------------------------------
[11:12:12.184] INFO: PixTestTiming::ROCDelayScan()
[11:12:12.184] INFO: ----------------------------------------------------------------------
[11:14:14.862] INFO: ROC Delay Settings: 228
[11:14:14.862] INFO: ROC Header-Trailer/Token Delay: 11
[11:14:14.862] INFO: ROC Port 0 Delay: 4
[11:14:14.862] INFO: ROC Port 1 Delay: 4
[11:14:14.862] INFO: Functional ROC Area: 5
[11:14:14.865] INFO: Test took 122681 ms.
[11:14:14.865] INFO: PixTestTiming::ROCDelayScan() done.
[11:14:14.865] INFO: ----------------------------------------------------------------------
[11:14:14.865] INFO: PixTestTiming::TimingTest()
[11:14:14.865] INFO: ----------------------------------------------------------------------
[11:14:31.292] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:14:46.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:15:01.636] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:15:16.794] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:15:32.020] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:15:47.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:02.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:17.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:32.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:47.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:47.615] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:47.629] INFO: ----------------------------------------------------------------------
[11:16:47.629] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[11:16:47.629] INFO: ----------------------------------------------------------------------
[11:16:47.629] INFO: ----------------------------------------------------------------------
[11:16:47.629] INFO: Read back bit status: 1
[11:16:47.629] INFO: ----------------------------------------------------------------------
[11:16:47.629] INFO: ----------------------------------------------------------------------
[11:16:47.629] INFO: Timings are good!
[11:16:47.629] INFO: ----------------------------------------------------------------------
[11:16:47.629] INFO: Test took 152764 ms.
[11:16:47.629] INFO: PixTestTiming::TimingTest() done.
[11:16:47.629] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//tbmParameters_C0a.dat
[11:16:47.629] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-M-3-09_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:16:47.630] INFO: PixTestTiming::doTest took 860701 ms.
[11:16:47.630] INFO: PixTestTiming::doTest() done
[11:16:47.630] INFO: Write out TBMPhaseScan_0_V0
[11:16:47.630] INFO: Write out TBMPhaseScan_1_V0
[11:16:47.630] INFO: Write out CombinedTBMPhaseScan_V0
[11:16:47.632] INFO: Write out ROCDelayScan3_V0
[11:16:47.633] INFO: enter test to run
[11:17:37.762] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:17:37.762] INFO: running: xray
[11:17:37.763] INFO: ----------------------------------------------------------------------
[11:17:37.763] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:17:37.763] INFO: ----------------------------------------------------------------------
[11:17:38.727] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:17:45.528] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:18:15.930] INFO: Resuming triggers.
[11:18:22.728] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:18:53.088] INFO: Resuming triggers.
[11:18:59.887] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[11:19:30.229] INFO: Resuming triggers.
[11:19:37.027] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[11:20:07.458] INFO: Resuming triggers.
[11:20:14.254] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:20:44.092] INFO: Resuming triggers.
[11:20:50.888] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[11:21:20.771] INFO: Resuming triggers.
[11:21:27.568] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[11:21:57.504] INFO: Resuming triggers.
[11:22:04.298] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[11:22:34.133] INFO: Resuming triggers.
[11:22:40.927] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[11:23:10.178] INFO: Resuming triggers.
[11:23:16.973] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[11:23:47.025] INFO: Resuming triggers.
[11:23:53.818] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[11:24:23.786] INFO: Resuming triggers.
[11:24:30.582] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:25:00.223] INFO: Resuming triggers.
[11:25:07.019] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[11:25:36.387] INFO: Resuming triggers.
[11:25:43.187] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[11:26:12.398] INFO: Resuming triggers.
[11:26:17.568] INFO: data taking finished, elapsed time: 100 seconds.
[11:26:40.476] INFO: PixTest:: pg_setup set to default.
[11:26:40.479] INFO: PixTestXray::doPhRun() done
[11:26:40.631] INFO: enter test to run
[11:27:17.637] INFO: test: HighRate no parameter change
[11:27:17.637] INFO: running: highrate
[11:27:17.638] INFO: ----------------------------------------------------------------------
[11:27:17.638] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:27:17.638] INFO: ----------------------------------------------------------------------
[11:27:17.777] INFO: Expecting 768 events.
[11:27:18.911] INFO: 768 events read in total (418ms).
[11:27:18.911] INFO: Test took 1267ms.
[11:27:19.714] INFO: Expecting 41600 events.
[11:27:22.514] INFO: 41600 events read in total (2273ms).
[11:27:22.515] INFO: Test took 3598ms.
[11:27:22.550] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:23.278] INFO: Expecting 41600 events.
[11:27:26.255] INFO: 41600 events read in total (2450ms).
[11:27:26.256] INFO: Test took 3689ms.
[11:27:26.291] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:27.014] INFO: Expecting 41600 events.
[11:27:29.978] INFO: 41600 events read in total (2438ms).
[11:27:29.979] INFO: Test took 3670ms.
[11:27:30.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:30.739] INFO: Expecting 41600 events.
[11:27:33.609] INFO: 41600 events read in total (2343ms).
[11:27:33.610] INFO: Test took 3578ms.
[11:27:33.644] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:34.365] INFO: Expecting 41600 events.
[11:27:37.522] INFO: 41600 events read in total (2630ms).
[11:27:37.523] INFO: Test took 3860ms.
[11:27:37.556] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:38.281] INFO: Expecting 41600 events.
[11:27:41.470] INFO: 41600 events read in total (2662ms).
[11:27:41.471] INFO: Test took 3895ms.
[11:27:41.503] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:42.228] INFO: Expecting 41600 events.
[11:27:45.456] INFO: 41600 events read in total (2701ms).
[11:27:45.457] INFO: Test took 3935ms.
[11:27:45.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:46.217] INFO: Expecting 41600 events.
[11:27:49.437] INFO: 41600 events read in total (2693ms).
[11:27:49.438] INFO: Test took 3930ms.
[11:27:49.470] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:50.195] INFO: Expecting 41600 events.
[11:27:53.408] INFO: 41600 events read in total (2686ms).
[11:27:53.408] INFO: Test took 3919ms.
[11:27:53.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:54.165] INFO: Expecting 41600 events.
[11:27:57.347] INFO: 41600 events read in total (2655ms).
[11:27:57.348] INFO: Test took 3889ms.
[11:27:57.382] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:58.110] INFO: Expecting 41600 events.
[11:28:01.341] INFO: 41600 events read in total (2705ms).
[11:28:01.342] INFO: Test took 3941ms.
[11:28:01.375] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:02.100] INFO: Expecting 41600 events.
[11:28:05.302] INFO: 41600 events read in total (2675ms).
[11:28:05.303] INFO: Test took 3911ms.
[11:28:05.336] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:06.062] INFO: Expecting 41600 events.
[11:28:09.274] INFO: 41600 events read in total (2685ms).
[11:28:09.275] INFO: Test took 3921ms.
[11:28:09.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:10.034] INFO: Expecting 41600 events.
[11:28:13.222] INFO: 41600 events read in total (2661ms).
[11:28:13.223] INFO: Test took 3899ms.
[11:28:13.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:13.980] INFO: Expecting 41600 events.
[11:28:17.167] INFO: 41600 events read in total (2660ms).
[11:28:17.168] INFO: Test took 3894ms.
[11:28:17.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:17.931] INFO: Expecting 41600 events.
[11:28:21.142] INFO: 41600 events read in total (2684ms).
[11:28:21.143] INFO: Test took 3924ms.
[11:28:21.175] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:21.901] INFO: Expecting 41600 events.
[11:28:25.101] INFO: 41600 events read in total (2673ms).
[11:28:25.102] INFO: Test took 3908ms.
[11:28:25.135] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:25.858] INFO: Expecting 41600 events.
[11:28:29.062] INFO: 41600 events read in total (2677ms).
[11:28:29.063] INFO: Test took 3909ms.
[11:28:29.095] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:29.821] INFO: Expecting 41600 events.
[11:28:32.995] INFO: 41600 events read in total (2647ms).
[11:28:32.996] INFO: Test took 3883ms.
[11:28:33.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:33.753] INFO: Expecting 41600 events.
[11:28:36.666] INFO: 41600 events read in total (2386ms).
[11:28:36.667] INFO: Test took 3617ms.
[11:28:36.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:37.058] INFO: enter test to run
[11:28:46.852] INFO: test: HighRate no parameter change
[11:28:46.852] INFO: running: highrate
[11:28:46.853] INFO: ----------------------------------------------------------------------
[11:28:46.853] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:28:46.853] INFO: ----------------------------------------------------------------------
[11:28:47.466] INFO: Expecting 208000 events.
[11:28:58.984] INFO: 208000 events read in total (10991ms).
[11:28:58.987] INFO: Test took 12128ms.
[11:28:59.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:59.376] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 1
[11:28:59.376] INFO: number of red-efficiency pixels: 69 42 85 138 143 131 136 103 67 103 103 106 80 77 22 26
[11:28:59.376] INFO: number of X-ray hits detected: 63252 43895 66845 102178 118398 112890 112174 75617 63152 89973 88340 78520 80039 47807 22146 24228
[11:28:59.376] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:28:59.377] INFO: number of Vcal hits detected: 207925 207958 207913 207861 207849 207868 207862 207895 207931 207895 207895 207842 207920 207920 207977 207925
[11:28:59.377] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[11:28:59.377] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[11:28:59.377] INFO: X-ray hit rate [MHz/cm2]: 18.5 12.9 19.6 29.9 34.7 33.1 32.9 22.2 18.5 26.4 25.9 23.0 23.5 14.0 6.5 7.1
[11:28:59.377] INFO: PixTestHighRate::doXPixelAlive() done
[11:28:59.430] INFO: PixTest:: pg_setup set to default.
[11:28:59.442] INFO: enter test to run
[11:29:25.373] INFO: test: HighRate no parameter change
[11:29:25.373] INFO: running: highrate
[11:29:25.374] INFO: ----------------------------------------------------------------------
[11:29:25.374] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:29:25.374] INFO: ----------------------------------------------------------------------
[11:29:25.989] INFO: Expecting 208000 events.
[11:29:39.467] INFO: 208000 events read in total (12952ms).
[11:29:39.472] INFO: Test took 14087ms.
[11:29:39.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:40.054] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 1
[11:29:40.054] INFO: number of red-efficiency pixels: 181 155 314 447 501 503 525 301 172 321 348 290 211 193 60 51
[11:29:40.054] INFO: number of X-ray hits detected: 133022 91807 139507 214801 246720 237202 234677 158515 132617 189482 186317 164807 167667 100915 47298 50697
[11:29:40.054] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:29:40.054] INFO: number of Vcal hits detected: 207803 207838 207654 207522 207454 207457 207433 207676 207818 207657 207631 207646 207786 207794 207938 207900
[11:29:40.054] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[11:29:40.055] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[11:29:40.055] INFO: X-ray hit rate [MHz/cm2]: 39.0 26.9 40.9 63.0 72.3 69.5 68.8 46.5 38.9 55.5 54.6 48.3 49.1 29.6 13.9 14.9
[11:29:40.055] INFO: PixTestHighRate::doXPixelAlive() done
[11:29:40.108] INFO: PixTest:: pg_setup set to default.
[11:29:40.121] INFO: enter test to run
[11:30:07.892] INFO: test: HighRate no parameter change
[11:30:07.892] INFO: running: highrate
[11:30:07.893] INFO: ----------------------------------------------------------------------
[11:30:07.893] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:30:07.893] INFO: ----------------------------------------------------------------------
[11:30:08.513] INFO: Expecting 208000 events.
[11:30:23.755] INFO: 208000 events read in total (14715ms).
[11:30:23.762] INFO: Test took 15859ms.
[11:30:24.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:30:24.533] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 1
[11:30:24.533] INFO: number of red-efficiency pixels: 373 272 661 1145 1181 1067 1262 696 345 762 758 676 503 408 99 99
[11:30:24.533] INFO: number of X-ray hits detected: 203092 140572 212968 327881 378959 363130 360274 242062 203604 290275 284708 251576 257292 154248 71928 78054
[11:30:24.533] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:30:24.533] INFO: number of Vcal hits detected: 207555 207703 207141 206588 206503 206682 206346 207109 207633 207104 207115 207156 207462 207530 207899 207848
[11:30:24.533] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.4 99.3 99.4 99.3 99.6 99.8 99.6 99.6 99.7 99.8 99.8 100.0 100.0
[11:30:24.534] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.3 99.3 99.4 99.2 99.6 99.8 99.6 99.6 99.6 99.7 99.8 100.0 99.9
[11:30:24.534] INFO: X-ray hit rate [MHz/cm2]: 59.5 41.2 62.4 96.1 111.1 106.4 105.6 71.0 59.7 85.1 83.4 73.7 75.4 45.2 21.1 22.9
[11:30:24.534] INFO: PixTestHighRate::doXPixelAlive() done
[11:30:24.589] INFO: PixTest:: pg_setup set to default.
[11:30:24.606] INFO: enter test to run
[11:30:30.620] INFO: test: exit no parameter change
[11:30:31.011] QUIET: Connection to board 33 closed.
[11:30:31.025] INFO: pXar: this is the end, my friend