[12:43:27.321] INFO: *** Welcome to pxar ***
[12:43:27.321] INFO: *** Today: 2016/09/30
[12:43:28.122] INFO: *** Version: v1.9.0-818-g96727
[12:43:28.122] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//dacParameters35_C15.dat
[12:43:28.144] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:43:28.144] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//defaultMaskFile.dat
[12:43:28.144] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C15.dat
[12:43:28.233] INFO: clk: 4
[12:43:28.233] INFO: ctr: 4
[12:43:28.233] INFO: sda: 19
[12:43:28.233] INFO: tin: 9
[12:43:28.233] INFO: level: 15
[12:43:28.233] INFO: triggerdelay: 0
[12:43:28.233] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:43:28.233] INFO: Log level: INFO
[12:43:28.250] QUIET: Connection to board DTB_WREKRL opened.
[12:43:28.271] 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:
------------------------------------------------------
[12:43:28.273] INFO: RPC call hashes of host and DTB match: 398089610
[12:43:29.805] INFO: DUT info:
[12:43:29.805] INFO: The DUT currently contains the following objects:
[12:43:29.805] INFO: 2 TBM Cores tbm08c (2 ON)
[12:43:29.805] INFO: TBM Core alpha (0): 7 registers set
[12:43:29.805] INFO: TBM Core beta (1): 7 registers set
[12:43:29.805] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:43:29.805] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.805] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.805] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.805] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.805] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.805] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.806] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.806] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.806] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.806] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.806] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.806] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.806] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.806] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.806] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:29.806] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:30.217] INFO: enter 'restricted' command line mode
[12:43:30.217] INFO: enter test to run
[12:43:51.143] INFO: test: PixelAlive no parameter change
[12:43:51.143] INFO: running: pixelalive
[12:43:51.152] INFO: ----------------------------------------------------------------------
[12:43:51.152] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:43:51.152] INFO: ----------------------------------------------------------------------
[12:43:51.478] INFO: Expecting 41600 events.
[12:43:55.795] INFO: 41600 events read in total (3599ms).
[12:43:55.962] INFO: Test took 4808ms.
[12:43:55.971] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:56.286] INFO: PixTestAlive::aliveTest() done
[12:43:56.286] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2 0
[12:43:56.313] INFO: enter test to run
[12:44:11.951] INFO: test: timing no parameter change
[12:44:11.951] INFO: running: timing
[12:44:11.954] INFO: ######################################################################
[12:44:11.954] INFO: PixTestTiming::doTest()
[12:44:11.954] INFO: ######################################################################
[12:44:11.954] INFO: ----------------------------------------------------------------------
[12:44:11.954] INFO: PixTestTiming::TBMPhaseScan()
[12:44:11.954] INFO: ----------------------------------------------------------------------
[12:54:11.336] INFO: TBM Phase Settings: 248
[12:54:11.336] INFO: 400MHz Phase: 6
[12:54:11.336] INFO: 160MHz Phase: 7
[12:54:11.336] INFO: Functional Phase Area: 3
[12:54:11.339] INFO: Test took 599385 ms.
[12:54:11.339] INFO: PixTestTiming::TBMPhaseScan() done.
[12:54:11.339] INFO: ----------------------------------------------------------------------
[12:54:11.339] INFO: PixTestTiming::ROCDelayScan()
[12:54:11.339] INFO: ----------------------------------------------------------------------
[12:57:14.745] INFO: ROC Delay Settings: 228
[12:57:14.745] INFO: ROC Header-Trailer/Token Delay: 11
[12:57:14.745] INFO: ROC Port 0 Delay: 4
[12:57:14.745] INFO: ROC Port 1 Delay: 4
[12:57:14.745] INFO: Functional ROC Area: 5
[12:57:14.748] INFO: Test took 183409 ms.
[12:57:14.748] INFO: PixTestTiming::ROCDelayScan() done.
[12:57:14.749] INFO: ----------------------------------------------------------------------
[12:57:14.749] INFO: PixTestTiming::TimingTest()
[12:57:14.749] INFO: ----------------------------------------------------------------------
[12:57:30.943] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:45.979] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:01.089] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:16.161] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:31.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:46.738] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:01.914] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:17.180] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:32.345] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:47.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:47.891] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:47.908] INFO: ----------------------------------------------------------------------
[12:59:47.908] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:59:47.908] INFO: ----------------------------------------------------------------------
[12:59:47.908] INFO: ----------------------------------------------------------------------
[12:59:47.908] INFO: Read back bit status: 1
[12:59:47.908] INFO: ----------------------------------------------------------------------
[12:59:47.908] INFO: ----------------------------------------------------------------------
[12:59:47.908] INFO: Timings are good!
[12:59:47.908] INFO: ----------------------------------------------------------------------
[12:59:47.908] INFO: Test took 153160 ms.
[12:59:47.909] INFO: PixTestTiming::TimingTest() done.
[12:59:47.909] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:59:47.909] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:59:47.909] INFO: PixTestTiming::doTest took 935958 ms.
[12:59:47.909] INFO: PixTestTiming::doTest() done
[12:59:47.909] INFO: Write out TBMPhaseScan_0_V0
[12:59:47.909] INFO: Write out TBMPhaseScan_1_V0
[12:59:47.909] INFO: Write out CombinedTBMPhaseScan_V0
[12:59:47.910] INFO: Write out ROCDelayScan3_V0
[12:59:47.911] INFO: enter test to run
[13:00:19.256] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:00:19.256] INFO: running: highrate
[13:00:19.256] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:00:19.460] INFO: ----------------------------------------------------------------------
[13:00:19.460] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:00:19.460] INFO: ----------------------------------------------------------------------
[13:00:19.460] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:00:19.460] INFO: edge/corner pixel THR is adjusted
[13:00:19.460] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:00:20.417] INFO: Collecting data for 5 seconds...
[13:00:25.437] INFO: Done with hot pixel readout
[13:00:38.288] INFO: PixTest:: pg_setup set to default.



























[13:00:38.290] INFO: 408 hot pixels found in step 0
[13:00:39.288] INFO: Collecting data for 5 seconds...
[13:00:44.305] INFO: Done with hot pixel readout
[13:00:56.976] INFO: PixTest:: pg_setup set to default.





























[13:00:56.979] INFO: 385 hot pixels found in step 1
[13:00:57.978] INFO: Collecting data for 5 seconds...
[13:01:02.995] INFO: Done with hot pixel readout
[13:01:15.709] INFO: PixTest:: pg_setup set to default.





































[13:01:15.711] INFO: 320 hot pixels found in step 2
[13:01:16.710] INFO: Collecting data for 5 seconds...
[13:01:21.728] INFO: Done with hot pixel readout
[13:01:34.310] INFO: PixTest:: pg_setup set to default.






































[13:01:34.312] INFO: 310 hot pixels found in step 3
[13:01:35.310] INFO: Collecting data for 5 seconds...
[13:01:40.328] INFO: Done with hot pixel readout
[13:01:53.016] INFO: PixTest:: pg_setup set to default.







































[13:01:53.018] INFO: 299 hot pixels found in step 4
[13:01:54.018] INFO: Collecting data for 5 seconds...
[13:01:59.036] INFO: Done with hot pixel readout
[13:02:11.638] INFO: PixTest:: pg_setup set to default.
























































[13:02:11.640] INFO: 291 hot pixels found in step 5
[13:02:12.639] INFO: Collecting data for 5 seconds...
[13:02:17.657] INFO: Done with hot pixel readout
[13:02:30.347] INFO: PixTest:: pg_setup set to default.





































































[13:02:30.349] INFO: 261 hot pixels found in step 6
[13:02:31.347] INFO: Collecting data for 5 seconds...
[13:02:36.364] INFO: Done with hot pixel readout
[13:02:49.013] INFO: PixTest:: pg_setup set to default.






















































[13:02:49.015] INFO: 243 hot pixels found in step 7
[13:02:50.015] INFO: Collecting data for 5 seconds...
[13:02:55.033] INFO: Done with hot pixel readout
[13:03:07.655] INFO: PixTest:: pg_setup set to default.




















































[13:03:07.657] INFO: 217 hot pixels found in step 8
[13:03:08.656] INFO: Collecting data for 5 seconds...
[13:03:13.673] INFO: Done with hot pixel readout
[13:03:26.313] INFO: PixTest:: pg_setup set to default.

























































[13:03:26.315] INFO: 212 hot pixels found in step 9
[13:03:27.314] INFO: Collecting data for 5 seconds...
[13:03:32.331] INFO: Done with hot pixel readout
[13:03:44.993] INFO: PixTest:: pg_setup set to default.




























































[13:03:44.995] INFO: 207 hot pixels found in step 10
[13:03:45.994] INFO: Collecting data for 5 seconds...
[13:03:51.011] INFO: Done with hot pixel readout
[13:04:03.533] INFO: PixTest:: pg_setup set to default.































































[13:04:03.535] INFO: 194 hot pixels found in step 11
[13:04:04.533] INFO: Collecting data for 5 seconds...
[13:04:09.552] INFO: Done with hot pixel readout
[13:04:22.226] INFO: PixTest:: pg_setup set to default.






























































[13:04:22.228] INFO: 177 hot pixels found in step 12
[13:04:23.226] INFO: Collecting data for 5 seconds...
[13:04:28.242] INFO: Done with hot pixel readout
[13:04:40.895] INFO: PixTest:: pg_setup set to default.


































































[13:04:40.897] INFO: 177 hot pixels found in step 13
[13:04:41.895] INFO: Collecting data for 5 seconds...
[13:04:46.913] INFO: Done with hot pixel readout
[13:04:59.589] INFO: PixTest:: pg_setup set to default.































































[13:04:59.591] INFO: 189 hot pixels found in step 14
[13:04:59.634] INFO: 189 hot pixels could not be trimmed and have been masked.
[13:04:59.638] INFO: PixTest::trimHotPixels() done
[13:04:59.659] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C0.dat
[13:04:59.671] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C1.dat
[13:04:59.680] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C2.dat
[13:04:59.686] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C3.dat
[13:04:59.691] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C4.dat
[13:04:59.696] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C5.dat
[13:04:59.701] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C6.dat
[13:04:59.707] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C7.dat
[13:04:59.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C8.dat
[13:04:59.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C9.dat
[13:04:59.723] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C10.dat
[13:04:59.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C11.dat
[13:04:59.733] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C12.dat
[13:04:59.738] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C13.dat
[13:04:59.744] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C14.dat
[13:04:59.749] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//trimParameters35_C15.dat
[13:04:59.754] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-5-17_FPIXTest-17C-FNAL-160923-1305-150V_2016-09-23_13h05m_1474653933/000_FPIXTest_p17//defaultMaskFile.dat
[13:04:59.767] INFO: enter test to run
[13:05:52.262] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:05:52.262] INFO: running: xray
[13:05:52.263] INFO: ----------------------------------------------------------------------
[13:05:52.263] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:05:52.263] INFO: ----------------------------------------------------------------------
[13:05:53.227] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:06:03.692] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:06:33.239] INFO: Resuming triggers.
[13:06:43.700] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:07:13.429] INFO: Resuming triggers.
[13:07:23.888] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[13:07:53.523] INFO: Resuming triggers.
[13:08:03.986] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[13:08:34.267] INFO: Resuming triggers.
[13:08:44.732] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[13:09:14.406] INFO: Resuming triggers.
[13:09:24.869] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[13:09:55.144] INFO: Resuming triggers.
[13:10:05.611] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[13:10:34.114] INFO: Resuming triggers.
[13:10:44.583] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[13:11:14.450] INFO: Resuming triggers.
[13:11:24.916] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:11:55.384] INFO: Resuming triggers.
[13:12:01.576] INFO: data taking finished, elapsed time: 100 seconds.
[13:12:20.130] INFO: PixTest:: pg_setup set to default.
[13:12:20.133] INFO: PixTestXray::doPhRun() done
[13:12:20.343] INFO: enter test to run
[13:13:04.523] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:13:04.523] INFO: running: xray
[13:13:04.525] INFO: ----------------------------------------------------------------------
[13:13:04.525] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:13:04.525] INFO: ----------------------------------------------------------------------
[13:13:05.497] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:13:11.693] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:13:41.806] INFO: Resuming triggers.
[13:13:47.999] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:14:18.172] INFO: Resuming triggers.
[13:14:24.365] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[13:14:54.505] INFO: Resuming triggers.
[13:15:00.698] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[13:15:30.960] INFO: Resuming triggers.
[13:15:37.157] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[13:16:07.357] INFO: Resuming triggers.
[13:16:13.552] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[13:16:43.605] INFO: Resuming triggers.
[13:16:49.796] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[13:17:19.912] INFO: Resuming triggers.
[13:17:26.103] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[13:17:56.162] INFO: Resuming triggers.
[13:18:02.356] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:18:32.389] INFO: Resuming triggers.
[13:18:38.581] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:19:08.791] INFO: Resuming triggers.
[13:19:14.985] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:19:45.113] INFO: Resuming triggers.
[13:19:51.305] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:20:21.424] INFO: Resuming triggers.
[13:20:27.617] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:20:57.654] INFO: Resuming triggers.
[13:21:03.846] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:21:34.807] INFO: Resuming triggers.
[13:21:40.005] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:22:11.678] INFO: Resuming triggers.
[13:22:17.872] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[13:22:49.319] INFO: Resuming triggers.
[13:22:50.570] INFO: data taking finished, elapsed time: 100 seconds.
[13:22:57.071] INFO: PixTest:: pg_setup set to default.
[13:22:57.074] INFO: PixTestXray::doPhRun() done
[13:22:57.228] INFO: enter test to run
[13:23:20.999] INFO: test: HighRate no parameter change
[13:23:20.999] INFO: running: highrate
[13:23:21.014] INFO: ----------------------------------------------------------------------
[13:23:21.014] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:23:21.014] INFO: ----------------------------------------------------------------------
[13:23:21.168] INFO: Expecting 768 events.
[13:23:22.302] INFO: 768 events read in total (419ms).
[13:23:22.302] INFO: Test took 1268ms.
[13:23:23.105] INFO: Expecting 41600 events.
[13:23:26.164] INFO: 41600 events read in total (2532ms).
[13:23:26.165] INFO: Test took 3857ms.
[13:23:26.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:26.917] INFO: Expecting 41600 events.
[13:23:30.320] INFO: 41600 events read in total (2876ms).
[13:23:30.321] INFO: Test took 4094ms.
[13:23:30.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:31.072] INFO: Expecting 41600 events.
[13:23:34.306] INFO: 41600 events read in total (2707ms).
[13:23:34.307] INFO: Test took 3924ms.
[13:23:34.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:35.055] INFO: Expecting 41600 events.
[13:23:38.427] INFO: 41600 events read in total (2845ms).
[13:23:38.428] INFO: Test took 4059ms.
[13:23:38.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:39.170] INFO: Expecting 41600 events.
[13:23:42.535] INFO: 41600 events read in total (2838ms).
[13:23:42.536] INFO: Test took 4044ms.
[13:23:42.579] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:43.287] INFO: Expecting 41600 events.
[13:23:46.638] INFO: 41600 events read in total (2824ms).
[13:23:46.639] INFO: Test took 4038ms.
[13:23:46.682] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:47.387] INFO: Expecting 41600 events.
[13:23:50.765] INFO: 41600 events read in total (2851ms).
[13:23:50.766] INFO: Test took 4063ms.
[13:23:50.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:51.513] INFO: Expecting 41600 events.
[13:23:54.672] INFO: 41600 events read in total (2632ms).
[13:23:54.673] INFO: Test took 3843ms.
[13:23:54.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:55.424] INFO: Expecting 41600 events.
[13:23:58.784] INFO: 41600 events read in total (2833ms).
[13:23:58.785] INFO: Test took 4048ms.
[13:23:58.827] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:59.534] INFO: Expecting 41600 events.
[13:24:02.950] INFO: 41600 events read in total (2889ms).
[13:24:02.951] INFO: Test took 4103ms.
[13:24:02.994] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:03.702] INFO: Expecting 41600 events.
[13:24:07.088] INFO: 41600 events read in total (2859ms).
[13:24:07.089] INFO: Test took 4075ms.
[13:24:07.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:07.837] INFO: Expecting 41600 events.
[13:24:11.291] INFO: 41600 events read in total (2927ms).
[13:24:11.292] INFO: Test took 4139ms.
[13:24:11.335] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:12.042] INFO: Expecting 41600 events.
[13:24:15.393] INFO: 41600 events read in total (2824ms).
[13:24:15.394] INFO: Test took 4037ms.
[13:24:15.437] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:16.134] INFO: Expecting 41600 events.
[13:24:19.495] INFO: 41600 events read in total (2834ms).
[13:24:19.496] INFO: Test took 4038ms.
[13:24:19.538] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:20.245] INFO: Expecting 41600 events.
[13:24:23.588] INFO: 41600 events read in total (2816ms).
[13:24:23.589] INFO: Test took 4030ms.
[13:24:23.632] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:24.332] INFO: Expecting 41600 events.
[13:24:27.741] INFO: 41600 events read in total (2882ms).
[13:24:27.742] INFO: Test took 4089ms.
[13:24:27.785] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:28.491] INFO: Expecting 41600 events.
[13:24:31.882] INFO: 41600 events read in total (2864ms).
[13:24:31.883] INFO: Test took 4077ms.
[13:24:31.927] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:32.634] INFO: Expecting 41600 events.
[13:24:36.053] INFO: 41600 events read in total (2892ms).
[13:24:36.055] INFO: Test took 4108ms.
[13:24:36.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:36.800] INFO: Expecting 41600 events.
[13:24:40.198] INFO: 41600 events read in total (2872ms).
[13:24:40.200] INFO: Test took 4081ms.
[13:24:40.242] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:40.944] INFO: Expecting 41600 events.
[13:24:43.924] INFO: 41600 events read in total (2453ms).
[13:24:43.925] INFO: Test took 3662ms.
[13:24:43.967] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:44.315] INFO: enter test to run
[13:25:09.982] INFO: test: HighRate no parameter change
[13:25:09.982] INFO: running: highrate
[13:25:09.983] INFO: ----------------------------------------------------------------------
[13:25:09.983] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:25:09.983] INFO: ----------------------------------------------------------------------
[13:25:10.609] INFO: Expecting 208000 events.
[13:25:23.273] INFO: 208000 events read in total (12137ms).
[13:25:23.278] INFO: Test took 13286ms.
[13:25:23.463] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:25:23.730] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 66 0 0 0 0 0 0 0 2 0
[13:25:23.730] INFO: number of red-efficiency pixels: 87 72 119 141 174 211 350 101 129 171 186 132 155 101 29 34
[13:25:23.730] INFO: number of X-ray hits detected: 78923 51747 83534 126253 133229 141332 171701 100934 97445 132157 133137 110423 116606 73194 25134 28998
[13:25:23.730] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:25:23.730] INFO: number of Vcal hits detected: 207893 207925 207876 207851 207822 207777 202864 207897 207866 207784 207807 207866 207838 207896 207873 207966
[13:25:23.730] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.1 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:25:23.730] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 97.5 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0
[13:25:23.730] INFO: X-ray hit rate [MHz/cm2]: 23.1 15.2 24.5 37.0 39.1 41.4 50.3 29.6 28.6 38.7 39.0 32.4 34.2 21.5 7.4 8.5
[13:25:23.730] INFO: PixTestHighRate::doXPixelAlive() done
[13:25:23.776] INFO: PixTest:: pg_setup set to default.
[13:25:23.790] INFO: enter test to run
[13:25:38.830] INFO: test: HighRate no parameter change
[13:25:38.830] INFO: running: highrate
[13:25:38.831] INFO: ----------------------------------------------------------------------
[13:25:38.831] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:25:38.831] INFO: ----------------------------------------------------------------------
[13:25:39.449] INFO: Expecting 208000 events.
[13:25:53.676] INFO: 208000 events read in total (13700ms).
[13:25:53.682] INFO: Test took 14841ms.
[13:25:54.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:25:54.359] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 49 0 0 0 0 0 0 0 2 0
[13:25:54.359] INFO: number of red-efficiency pixels: 229 159 388 413 498 686 671 349 273 484 467 362 366 297 57 66
[13:25:54.359] INFO: number of X-ray hits detected: 146911 95726 157228 233519 249186 263671 293691 188355 184184 246534 246498 204879 216804 135902 47123 53800
[13:25:54.359] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:25:54.359] INFO: number of Vcal hits detected: 207741 207829 207561 207557 207459 207216 202177 207625 207701 207403 207479 207618 207603 207676 207842 207932
[13:25:54.359] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 98.3 99.8 99.9 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[13:25:54.359] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.6 97.2 99.8 99.9 99.7 99.7 99.8 99.8 99.8 99.9 100.0
[13:25:54.359] INFO: X-ray hit rate [MHz/cm2]: 43.1 28.1 46.1 68.4 73.0 77.3 86.1 55.2 54.0 72.3 72.3 60.1 63.5 39.8 13.8 15.8
[13:25:54.359] INFO: PixTestHighRate::doXPixelAlive() done
[13:25:54.408] INFO: PixTest:: pg_setup set to default.
[13:25:54.425] INFO: enter test to run
[13:26:09.286] INFO: test: HighRate no parameter change
[13:26:09.286] INFO: running: highrate
[13:26:09.287] INFO: ----------------------------------------------------------------------
[13:26:09.287] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:26:09.287] INFO: ----------------------------------------------------------------------
[13:26:09.905] INFO: Expecting 208000 events.
[13:26:26.271] INFO: 208000 events read in total (15839ms).
[13:26:26.280] INFO: Test took 16984ms.
[13:26:26.789] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:26:27.160] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 43 0 0 0 0 0 0 0 2 0
[13:26:27.160] INFO: number of red-efficiency pixels: 476 378 865 913 1164 1549 1377 725 641 1134 1062 804 873 686 102 104
[13:26:27.160] INFO: number of X-ray hits detected: 219771 143933 234116 350099 371044 392474 423357 281915 276206 370572 369180 307342 324910 203836 70661 81362
[13:26:27.160] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:26:27.160] INFO: number of Vcal hits detected: 207431 207573 206710 206882 206513 205701 200930 207112 207239 206471 206636 207026 206988 207062 207794 207893
[13:26:27.160] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.5 99.5 99.4 99.0 97.6 99.6 99.7 99.3 99.4 99.6 99.6 99.6 100.0 100.0
[13:26:27.160] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.4 99.5 99.3 98.9 96.6 99.6 99.6 99.3 99.3 99.5 99.5 99.5 99.9 99.9
[13:26:27.160] INFO: X-ray hit rate [MHz/cm2]: 64.4 42.2 68.6 102.6 108.8 115.0 124.1 82.6 81.0 108.6 108.2 90.1 95.2 59.7 20.7 23.8
[13:26:27.160] INFO: PixTestHighRate::doXPixelAlive() done
[13:26:27.210] INFO: PixTest:: pg_setup set to default.
[13:26:27.231] INFO: enter test to run
[13:26:29.502] INFO: test: exit no parameter change
[13:26:29.909] QUIET: Connection to board 33 closed.
[13:26:29.918] INFO: pXar: this is the end, my friend