[14:19:49.801] INFO: *** Welcome to pxar ***
[14:19:49.801] INFO: *** Today: 2016/10/26
[14:19:50.765] INFO: *** Version: v1.9.0-818-g96727
[14:19:50.789] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//dacParameters35_C15.dat
[14:19:50.864] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:19:50.864] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//defaultMaskFile.dat
[14:19:50.873] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C15.dat
[14:19:51.034] INFO: clk: 4
[14:19:51.034] INFO: ctr: 4
[14:19:51.034] INFO: sda: 19
[14:19:51.034] INFO: tin: 9
[14:19:51.034] INFO: level: 15
[14:19:51.034] INFO: triggerdelay: 0
[14:19:51.035] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:19:51.035] INFO: Log level: INFO
[14:19:51.074] QUIET: Connection to board DTB_WREHUL opened.
[14:19:51.077] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 30
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREHUL
MAC address: 40D85511801E
Hostname: pixelDTB030
Comment:
------------------------------------------------------
[14:19:51.080] INFO: RPC call hashes of host and DTB match: 398089610
[14:19:52.605] INFO: DUT info:
[14:19:52.605] INFO: The DUT currently contains the following objects:
[14:19:52.605] INFO: 2 TBM Cores tbm08c (2 ON)
[14:19:52.605] INFO: TBM Core alpha (0): 7 registers set
[14:19:52.605] INFO: TBM Core beta (1): 7 registers set
[14:19:52.605] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:19:52.605] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.605] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.605] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.605] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.605] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.605] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.605] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.605] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.606] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.606] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.606] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.606] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.606] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.606] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.606] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:52.606] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:19:53.058] INFO: enter 'restricted' command line mode
[14:19:53.058] INFO: enter test to run
[14:20:05.249] INFO: test: PixelAlive no parameter change
[14:20:05.249] INFO: running: pixelalive
[14:20:05.302] INFO: ----------------------------------------------------------------------
[14:20:05.303] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:20:05.303] INFO: ----------------------------------------------------------------------
[14:20:05.639] INFO: Expecting 41600 events.
[14:20:10.068] INFO: 41600 events read in total (3711ms).
[14:20:10.238] INFO: Test took 4933ms.
[14:20:10.251] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:10.814] INFO: PixTestAlive::aliveTest() done
[14:20:10.814] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 6 0
[14:20:10.959] INFO: enter test to run
[14:20:18.841] INFO: test: timing no parameter change
[14:20:18.841] INFO: running: timing
[14:20:18.844] INFO: ######################################################################
[14:20:18.844] INFO: PixTestTiming::doTest()
[14:20:18.844] INFO: ######################################################################
[14:20:18.845] INFO: ----------------------------------------------------------------------
[14:20:18.845] INFO: PixTestTiming::TBMPhaseScan()
[14:20:18.845] INFO: ----------------------------------------------------------------------
[14:24:35.886] INFO: TBM Phase Settings: 204
[14:24:35.886] INFO: 400MHz Phase: 3
[14:24:35.886] INFO: 160MHz Phase: 6
[14:24:35.886] INFO: Functional Phase Area: 4
[14:24:35.909] INFO: Test took 257065 ms.
[14:24:35.909] INFO: PixTestTiming::TBMPhaseScan() done.
[14:24:35.909] INFO: ----------------------------------------------------------------------
[14:24:35.909] INFO: PixTestTiming::ROCDelayScan()
[14:24:35.909] INFO: ----------------------------------------------------------------------
[14:26:33.228] INFO: ROC Delay Settings: 220
[14:26:33.228] INFO: ROC Header-Trailer/Token Delay: 11
[14:26:33.228] INFO: ROC Port 0 Delay: 4
[14:26:33.228] INFO: ROC Port 1 Delay: 3
[14:26:33.228] INFO: Functional ROC Area: 4
[14:26:33.231] INFO: Test took 117322 ms.
[14:26:33.232] INFO: PixTestTiming::ROCDelayScan() done.
[14:26:33.232] INFO: ----------------------------------------------------------------------
[14:26:33.232] INFO: PixTestTiming::TimingTest()
[14:26:33.232] INFO: ----------------------------------------------------------------------
[14:26:49.394] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:04.376] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:19.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:34.339] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:49.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:04.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:19.258] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:34.243] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:49.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:04.185] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:04.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:04.585] INFO: ----------------------------------------------------------------------
[14:29:04.585] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:29:04.585] INFO: ----------------------------------------------------------------------
[14:29:04.585] INFO: ----------------------------------------------------------------------
[14:29:04.585] INFO: Read back bit status: 1
[14:29:04.585] INFO: ----------------------------------------------------------------------
[14:29:04.585] INFO: ----------------------------------------------------------------------
[14:29:04.585] INFO: Timings are good!
[14:29:04.585] INFO: ----------------------------------------------------------------------
[14:29:04.585] INFO: Test took 151353 ms.
[14:29:04.585] INFO: PixTestTiming::TimingTest() done.
[14:29:04.585] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:29:04.586] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:29:04.586] INFO: PixTestTiming::doTest took 525745 ms.
[14:29:04.586] INFO: PixTestTiming::doTest() done
[14:29:04.586] INFO: Write out TBMPhaseScan_0_V0
[14:29:04.586] INFO: Write out TBMPhaseScan_1_V0
[14:29:04.586] INFO: Write out CombinedTBMPhaseScan_V0
[14:29:04.588] INFO: Write out ROCDelayScan3_V0
[14:29:04.589] INFO: enter test to run
[14:29:32.829] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:29:32.829] INFO: running: highrate
[14:29:32.840] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:29:33.092] INFO: ----------------------------------------------------------------------
[14:29:33.092] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:29:33.092] INFO: ----------------------------------------------------------------------
[14:29:33.092] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:29:33.092] INFO: edge/corner pixel THR is adjusted
[14:29:33.092] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:29:34.051] INFO: Collecting data for 5 seconds...
[14:29:39.067] INFO: Done with hot pixel readout
[14:29:50.659] INFO: PixTest:: pg_setup set to default.
[14:29:50.660] INFO: 17 hot pixels found in step 0
[14:29:51.653] INFO: Collecting data for 5 seconds...
[14:29:56.672] INFO: Done with hot pixel readout
[14:30:08.333] INFO: PixTest:: pg_setup set to default.
[14:30:08.333] INFO: 14 hot pixels found in step 1
[14:30:09.327] INFO: Collecting data for 5 seconds...
[14:30:14.346] INFO: Done with hot pixel readout
[14:30:25.699] INFO: PixTest:: pg_setup set to default.
[14:30:25.700] INFO: 12 hot pixels found in step 2
[14:30:26.687] INFO: Collecting data for 5 seconds...
[14:30:31.705] INFO: Done with hot pixel readout
[14:30:43.013] INFO: PixTest:: pg_setup set to default.
[14:30:43.014] INFO: 10 hot pixels found in step 3
[14:30:44.007] INFO: Collecting data for 5 seconds...
[14:30:49.025] INFO: Done with hot pixel readout
[14:31:00.490] INFO: PixTest:: pg_setup set to default.

[14:31:00.491] INFO: 12 hot pixels found in step 4
[14:31:01.479] INFO: Collecting data for 5 seconds...
[14:31:06.497] INFO: Done with hot pixel readout
[14:31:17.983] INFO: PixTest:: pg_setup set to default.

[14:31:17.984] INFO: 7 hot pixels found in step 5
[14:31:18.976] INFO: Collecting data for 5 seconds...
[14:31:23.994] INFO: Done with hot pixel readout
[14:31:35.669] INFO: PixTest:: pg_setup set to default.

[14:31:35.669] INFO: 9 hot pixels found in step 6
[14:31:36.662] INFO: Collecting data for 5 seconds...
[14:31:41.680] INFO: Done with hot pixel readout
[14:31:53.301] INFO: PixTest:: pg_setup set to default.



[14:31:53.302] INFO: 7 hot pixels found in step 7
[14:31:54.293] INFO: Collecting data for 5 seconds...
[14:31:59.313] INFO: Done with hot pixel readout
[14:32:10.881] INFO: PixTest:: pg_setup set to default.



[14:32:10.882] INFO: 9 hot pixels found in step 8
[14:32:11.875] INFO: Collecting data for 5 seconds...
[14:32:16.894] INFO: Done with hot pixel readout
[14:32:28.357] INFO: PixTest:: pg_setup set to default.




[14:32:28.358] INFO: 8 hot pixels found in step 9
[14:32:29.350] INFO: Collecting data for 5 seconds...
[14:32:34.371] INFO: Done with hot pixel readout
[14:32:45.962] INFO: PixTest:: pg_setup set to default.




[14:32:45.963] INFO: 6 hot pixels found in step 10
[14:32:46.955] INFO: Collecting data for 5 seconds...
[14:32:51.975] INFO: Done with hot pixel readout
[14:33:03.551] INFO: PixTest:: pg_setup set to default.




[14:33:03.552] INFO: 7 hot pixels found in step 11
[14:33:04.544] INFO: Collecting data for 5 seconds...
[14:33:09.564] INFO: Done with hot pixel readout
[14:33:21.561] INFO: PixTest:: pg_setup set to default.





[14:33:21.562] INFO: 9 hot pixels found in step 12
[14:33:22.555] INFO: Collecting data for 5 seconds...
[14:33:27.575] INFO: Done with hot pixel readout
[14:33:39.270] INFO: PixTest:: pg_setup set to default.





[14:33:39.271] INFO: 8 hot pixels found in step 13
[14:33:40.263] INFO: Collecting data for 5 seconds...
[14:33:45.281] INFO: Done with hot pixel readout
[14:33:57.165] INFO: PixTest:: pg_setup set to default.






[14:33:57.166] INFO: 7 hot pixels found in step 14
[14:33:57.203] INFO: 7 hot pixels could not be trimmed and have been masked.
[14:33:57.206] INFO: PixTest::trimHotPixels() done
[14:33:57.206] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C0.dat
[14:33:57.212] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C1.dat
[14:33:57.218] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C2.dat
[14:33:57.223] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C3.dat
[14:33:57.229] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C4.dat
[14:33:57.234] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C5.dat
[14:33:57.240] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C6.dat
[14:33:57.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C7.dat
[14:33:57.251] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C8.dat
[14:33:57.256] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C9.dat
[14:33:57.262] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C10.dat
[14:33:57.267] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C11.dat
[14:33:57.273] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C12.dat
[14:33:57.278] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C13.dat
[14:33:57.284] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C14.dat
[14:33:57.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//trimParameters35_C15.dat
[14:33:57.295] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-5-36_FPIXTest-17C-FNAL-161024-1542-150V_2016-10-24_15h42m_1477341723/000_FPIXTest_p17//defaultMaskFile.dat
[14:33:57.305] INFO: enter test to run
[14:34:06.588] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:34:06.588] INFO: running: xray
[14:34:06.589] INFO: ----------------------------------------------------------------------
[14:34:06.589] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:34:06.589] INFO: ----------------------------------------------------------------------
[14:34:07.572] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:34:19.210] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:34:49.058] INFO: Resuming triggers.
[14:35:00.693] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:35:30.101] INFO: Resuming triggers.
[14:35:41.737] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:36:11.073] INFO: Resuming triggers.
[14:36:22.711] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:36:51.825] INFO: Resuming triggers.
[14:37:03.460] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:37:32.816] INFO: Resuming triggers.
[14:37:44.452] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:38:13.841] INFO: Resuming triggers.
[14:38:25.476] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:38:54.947] INFO: Resuming triggers.
[14:39:06.582] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:39:36.145] INFO: Resuming triggers.
[14:39:43.403] INFO: data taking finished, elapsed time: 100 seconds.
[14:40:01.938] INFO: PixTest:: pg_setup set to default.
[14:40:01.941] INFO: PixTestXray::doPhRun() done
[14:40:02.141] INFO: enter test to run
[14:40:40.609] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:40:40.609] INFO: running: xray
[14:40:40.610] INFO: ----------------------------------------------------------------------
[14:40:40.610] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:40:40.610] INFO: ----------------------------------------------------------------------
[14:40:41.574] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:40:48.589] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:41:18.828] INFO: Resuming triggers.
[14:41:25.845] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:41:55.863] INFO: Resuming triggers.
[14:42:02.879] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:42:33.100] INFO: Resuming triggers.
[14:42:40.118] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:43:10.764] INFO: Resuming triggers.
[14:43:17.787] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:43:48.707] INFO: Resuming triggers.
[14:43:55.728] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[14:44:26.306] INFO: Resuming triggers.
[14:44:33.326] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[14:45:04.326] INFO: Resuming triggers.
[14:45:11.342] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:45:42.456] INFO: Resuming triggers.
[14:45:49.474] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[14:46:20.166] INFO: Resuming triggers.
[14:46:27.189] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:46:58.633] INFO: Resuming triggers.
[14:47:05.649] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[14:47:37.457] INFO: Resuming triggers.
[14:47:44.474] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:48:15.877] INFO: Resuming triggers.
[14:48:22.897] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[14:48:53.005] INFO: Resuming triggers.
[14:49:01.017] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[14:49:32.276] INFO: Resuming triggers.
[14:49:34.379] INFO: data taking finished, elapsed time: 100 seconds.
[14:49:44.065] INFO: PixTest:: pg_setup set to default.
[14:49:44.069] INFO: PixTestXray::doPhRun() done
[14:49:44.231] INFO: enter test to run
[14:50:12.365] INFO: test: HighRate no parameter change
[14:50:12.365] INFO: running: highrate
[14:50:12.380] INFO: ----------------------------------------------------------------------
[14:50:12.380] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:50:12.380] INFO: ----------------------------------------------------------------------
[14:50:12.535] INFO: Expecting 768 events.
[14:50:13.669] INFO: 768 events read in total (419ms).
[14:50:13.669] INFO: Test took 1269ms.
[14:50:14.473] INFO: Expecting 41600 events.
[14:50:17.439] INFO: 41600 events read in total (2439ms).
[14:50:17.440] INFO: Test took 3764ms.
[14:50:17.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:18.204] INFO: Expecting 41600 events.
[14:50:21.333] INFO: 41600 events read in total (2602ms).
[14:50:21.334] INFO: Test took 3847ms.
[14:50:21.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:22.095] INFO: Expecting 41600 events.
[14:50:25.306] INFO: 41600 events read in total (2684ms).
[14:50:25.307] INFO: Test took 3923ms.
[14:50:25.339] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:26.067] INFO: Expecting 41600 events.
[14:50:29.290] INFO: 41600 events read in total (2697ms).
[14:50:29.291] INFO: Test took 3934ms.
[14:50:29.323] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:30.051] INFO: Expecting 41600 events.
[14:50:33.202] INFO: 41600 events read in total (2625ms).
[14:50:33.203] INFO: Test took 3862ms.
[14:50:33.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:33.962] INFO: Expecting 41600 events.
[14:50:37.177] INFO: 41600 events read in total (2688ms).
[14:50:37.178] INFO: Test took 3925ms.
[14:50:37.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:37.940] INFO: Expecting 41600 events.
[14:50:41.153] INFO: 41600 events read in total (2686ms).
[14:50:41.154] INFO: Test took 3926ms.
[14:50:41.187] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:41.915] INFO: Expecting 41600 events.
[14:50:45.133] INFO: 41600 events read in total (2691ms).
[14:50:45.134] INFO: Test took 3929ms.
[14:50:45.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:45.894] INFO: Expecting 41600 events.
[14:50:49.126] INFO: 41600 events read in total (2705ms).
[14:50:49.127] INFO: Test took 3944ms.
[14:50:49.159] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:49.885] INFO: Expecting 41600 events.
[14:50:53.120] INFO: 41600 events read in total (2708ms).
[14:50:53.121] INFO: Test took 3943ms.
[14:50:53.154] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:53.877] INFO: Expecting 41600 events.
[14:50:57.109] INFO: 41600 events read in total (2705ms).
[14:50:57.110] INFO: Test took 3938ms.
[14:50:57.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:57.871] INFO: Expecting 41600 events.
[14:51:01.091] INFO: 41600 events read in total (2693ms).
[14:51:01.092] INFO: Test took 3908ms.
[14:51:01.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:01.851] INFO: Expecting 41600 events.
[14:51:05.077] INFO: 41600 events read in total (2699ms).
[14:51:05.078] INFO: Test took 3936ms.
[14:51:05.111] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:05.839] INFO: Expecting 41600 events.
[14:51:09.060] INFO: 41600 events read in total (2694ms).
[14:51:09.061] INFO: Test took 3931ms.
[14:51:09.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:09.823] INFO: Expecting 41600 events.
[14:51:13.037] INFO: 41600 events read in total (2687ms).
[14:51:13.038] INFO: Test took 3926ms.
[14:51:13.070] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:13.790] INFO: Expecting 41600 events.
[14:51:17.015] INFO: 41600 events read in total (2698ms).
[14:51:17.016] INFO: Test took 3927ms.
[14:51:17.049] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:17.777] INFO: Expecting 41600 events.
[14:51:20.998] INFO: 41600 events read in total (2694ms).
[14:51:20.999] INFO: Test took 3932ms.
[14:51:21.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:21.757] INFO: Expecting 41600 events.
[14:51:24.979] INFO: 41600 events read in total (2695ms).
[14:51:24.980] INFO: Test took 3931ms.
[14:51:25.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:25.734] INFO: Expecting 41600 events.
[14:51:28.953] INFO: 41600 events read in total (2692ms).
[14:51:28.954] INFO: Test took 3923ms.
[14:51:28.986] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:29.711] INFO: Expecting 41600 events.
[14:51:32.820] INFO: 41600 events read in total (2582ms).
[14:51:32.821] INFO: Test took 3818ms.
[14:51:32.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:33.219] INFO: enter test to run
[14:52:32.035] INFO: test: HighRate no parameter change
[14:52:32.036] INFO: running: highrate
[14:52:32.037] INFO: ----------------------------------------------------------------------
[14:52:32.037] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:52:32.037] INFO: ----------------------------------------------------------------------
[14:52:32.644] INFO: Expecting 208000 events.
[14:52:44.392] INFO: 208000 events read in total (11221ms).
[14:52:44.395] INFO: Test took 12351ms.
[14:52:44.531] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:44.781] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0
[14:52:44.781] INFO: number of red-efficiency pixels: 85 50 85 117 104 121 133 83 63 139 95 100 96 54 34 28
[14:52:44.781] INFO: number of X-ray hits detected: 64222 38442 61135 89204 95743 101220 99949 72018 74223 100596 102703 85186 86813 52543 20754 22512
[14:52:44.781] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:52:44.781] INFO: number of Vcal hits detected: 207911 207950 207915 207882 207894 207878 207866 207916 207936 207858 207905 207898 207902 207945 207769 207972
[14:52:44.781] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 100.0 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[14:52:44.781] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 99.9 100.0
[14:52:44.781] INFO: X-ray hit rate [MHz/cm2]: 18.8 11.3 17.9 26.1 28.1 29.7 29.3 21.1 21.8 29.5 30.1 25.0 25.4 15.4 6.1 6.6
[14:52:44.781] INFO: PixTestHighRate::doXPixelAlive() done
[14:52:44.830] INFO: PixTest:: pg_setup set to default.
[14:52:44.847] INFO: enter test to run
[14:53:08.316] INFO: test: HighRate no parameter change
[14:53:08.316] INFO: running: highrate
[14:53:08.317] INFO: ----------------------------------------------------------------------
[14:53:08.317] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:53:08.317] INFO: ----------------------------------------------------------------------
[14:53:08.934] INFO: Expecting 208000 events.
[14:53:22.228] INFO: 208000 events read in total (12767ms).
[14:53:22.233] INFO: Test took 13906ms.
[14:53:22.507] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:22.799] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0
[14:53:22.799] INFO: number of red-efficiency pixels: 242 110 179 312 294 453 410 276 198 427 345 264 293 174 56 55
[14:53:22.799] INFO: number of X-ray hits detected: 131421 79474 125970 183758 197486 208452 205677 147406 153792 207813 211506 176313 178184 108556 42958 47483
[14:53:22.799] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:53:22.799] INFO: number of Vcal hits detected: 207745 207881 207815 207679 207689 207514 207558 207703 207794 207541 207622 207723 207695 207817 207745 207942
[14:53:22.799] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.9 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:53:22.799] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.9 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 99.9 100.0
[14:53:22.799] INFO: X-ray hit rate [MHz/cm2]: 38.5 23.3 36.9 53.9 57.9 61.1 60.3 43.2 45.1 60.9 62.0 51.7 52.2 31.8 12.6 13.9
[14:53:22.799] INFO: PixTestHighRate::doXPixelAlive() done
[14:53:22.851] INFO: PixTest:: pg_setup set to default.
[14:53:22.865] INFO: enter test to run
[14:53:47.891] INFO: test: HighRate no parameter change
[14:53:47.891] INFO: running: highrate
[14:53:47.893] INFO: ----------------------------------------------------------------------
[14:53:47.893] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:53:47.893] INFO: ----------------------------------------------------------------------
[14:53:48.513] INFO: Expecting 208000 events.
[14:54:03.603] INFO: 208000 events read in total (14563ms).
[14:54:03.610] INFO: Test took 15709ms.
[14:54:04.027] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:04.365] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0
[14:54:04.365] INFO: number of red-efficiency pixels: 531 229 391 639 658 994 904 525 424 1003 818 568 767 312 75 120
[14:54:04.365] INFO: number of X-ray hits detected: 198833 120036 188493 275744 295536 313257 308831 223794 230653 312041 318376 264041 268299 163262 64535 70806
[14:54:04.365] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:54:04.365] INFO: number of Vcal hits detected: 207373 207756 207557 207270 207261 206798 206900 207385 207533 206796 207050 207360 207109 207652 207727 207878
[14:54:04.365] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.8 99.7 99.7 99.5 99.5 99.7 99.8 99.5 99.6 99.7 99.6 99.8 100.0 99.9
[14:54:04.365] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.8 99.6 99.6 99.4 99.5 99.7 99.8 99.4 99.5 99.7 99.6 99.8 99.9 99.9
[14:54:04.365] INFO: X-ray hit rate [MHz/cm2]: 58.3 35.2 55.2 80.8 86.6 91.8 90.5 65.6 67.6 91.5 93.3 77.4 78.6 47.9 18.9 20.8
[14:54:04.365] INFO: PixTestHighRate::doXPixelAlive() done
[14:54:04.418] INFO: PixTest:: pg_setup set to default.
[14:54:04.434] INFO: enter test to run
[14:54:10.131] INFO: test: exit no parameter change
[14:54:10.596] QUIET: Connection to board 30 closed.
[14:54:10.608] INFO: pXar: this is the end, my friend