[14:01:42.724] INFO: *** Welcome to pxar ***
[14:01:42.724] INFO: *** Today: 2016/10/25
[14:01:43.098] INFO: *** Version: v1.9.0-818-g96727
[14:01:43.098] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//dacParameters35_C15.dat
[14:01:43.129] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:01:43.129] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//defaultMaskFile.dat
[14:01:43.135] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C15.dat
[14:01:43.230] INFO: clk: 4
[14:01:43.230] INFO: ctr: 4
[14:01:43.230] INFO: sda: 19
[14:01:43.230] INFO: tin: 9
[14:01:43.230] INFO: level: 15
[14:01:43.230] INFO: triggerdelay: 0
[14:01:43.230] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:01:43.230] INFO: Log level: INFO
[14:01:43.246] QUIET: Connection to board DTB_WREHUL opened.
[14:01:43.249] 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:01:43.251] INFO: RPC call hashes of host and DTB match: 398089610
[14:01:44.793] INFO: DUT info:
[14:01:44.793] INFO: The DUT currently contains the following objects:
[14:01:44.793] INFO: 2 TBM Cores tbm08c (2 ON)
[14:01:44.793] INFO: TBM Core alpha (0): 7 registers set
[14:01:44.793] INFO: TBM Core beta (1): 7 registers set
[14:01:44.793] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:01:44.793] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:44.794] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:01:45.198] INFO: enter 'restricted' command line mode
[14:01:45.198] INFO: enter test to run
[14:01:55.837] INFO: test: PixelAlive no parameter change
[14:01:55.837] INFO: running: pixelalive
[14:01:55.846] INFO: ----------------------------------------------------------------------
[14:01:55.846] 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:01:55.846] INFO: ----------------------------------------------------------------------
[14:01:56.171] INFO: Expecting 41600 events.
[14:02:00.534] INFO: 41600 events read in total (3645ms).
[14:02:00.700] INFO: Test took 4852ms.
[14:02:00.715] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:00.981] INFO: PixTestAlive::aliveTest() done
[14:02:00.981] INFO: number of dead pixels (per ROC): 0 2 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[14:02:01.013] INFO: enter test to run
[14:02:52.804] INFO: test: timing no parameter change
[14:02:52.804] INFO: running: timing
[14:02:52.807] INFO: ######################################################################
[14:02:52.808] INFO: PixTestTiming::doTest()
[14:02:52.808] INFO: ######################################################################
[14:02:52.808] INFO: ----------------------------------------------------------------------
[14:02:52.808] INFO: PixTestTiming::TBMPhaseScan()
[14:02:52.808] INFO: ----------------------------------------------------------------------
[14:09:11.937] INFO: TBM Phase Settings: 236
[14:09:11.937] INFO: 400MHz Phase: 3
[14:09:11.937] INFO: 160MHz Phase: 7
[14:09:11.937] INFO: Functional Phase Area: 4
[14:09:11.941] INFO: Test took 379133 ms.
[14:09:11.941] INFO: PixTestTiming::TBMPhaseScan() done.
[14:09:11.941] INFO: ----------------------------------------------------------------------
[14:09:11.941] INFO: PixTestTiming::ROCDelayScan()
[14:09:11.941] INFO: ----------------------------------------------------------------------
[14:11:24.154] INFO: ROC Delay Settings: 228
[14:11:24.155] INFO: ROC Header-Trailer/Token Delay: 11
[14:11:24.155] INFO: ROC Port 0 Delay: 4
[14:11:24.155] INFO: ROC Port 1 Delay: 4
[14:11:24.155] INFO: Functional ROC Area: 5
[14:11:24.158] INFO: Test took 132217 ms.
[14:11:24.158] INFO: PixTestTiming::ROCDelayScan() done.
[14:11:24.158] INFO: ----------------------------------------------------------------------
[14:11:24.158] INFO: PixTestTiming::TimingTest()
[14:11:24.158] INFO: ----------------------------------------------------------------------
[14:11:40.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:55.315] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:10.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:25.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:40.267] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:55.267] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:10.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:25.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:40.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:55.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:55.650] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:55.668] INFO: ----------------------------------------------------------------------
[14:13:55.668] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:13:55.668] INFO: ----------------------------------------------------------------------
[14:13:55.668] INFO: ----------------------------------------------------------------------
[14:13:55.668] INFO: Read back bit status: 1
[14:13:55.668] INFO: ----------------------------------------------------------------------
[14:13:55.668] INFO: ----------------------------------------------------------------------
[14:13:55.668] INFO: Timings are good!
[14:13:55.668] INFO: ----------------------------------------------------------------------
[14:13:55.668] INFO: Test took 151510 ms.
[14:13:55.668] INFO: PixTestTiming::TimingTest() done.
[14:13:55.677] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:13:55.678] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:13:55.678] INFO: PixTestTiming::doTest took 662874 ms.
[14:13:55.678] INFO: PixTestTiming::doTest() done
[14:13:55.678] INFO: Write out TBMPhaseScan_0_V0
[14:13:55.678] INFO: Write out TBMPhaseScan_1_V0
[14:13:55.678] INFO: Write out CombinedTBMPhaseScan_V0
[14:13:55.680] INFO: Write out ROCDelayScan3_V0
[14:13:55.681] INFO: enter test to run
[14:14:29.632] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:14:29.632] INFO: running: highrate
[14:14:29.632] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:14:29.945] INFO: ----------------------------------------------------------------------
[14:14:29.945] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:14:29.945] INFO: ----------------------------------------------------------------------
[14:14:29.945] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:14:29.945] INFO: edge/corner pixel THR is adjusted
[14:14:29.945] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:14:30.917] INFO: Collecting data for 5 seconds...
[14:14:35.934] INFO: Done with hot pixel readout
[14:14:48.556] INFO: PixTest:: pg_setup set to default.












[14:14:48.557] INFO: 227 hot pixels found in step 0
[14:14:49.558] INFO: Collecting data for 5 seconds...
[14:14:54.576] INFO: Done with hot pixel readout
[14:15:07.039] INFO: PixTest:: pg_setup set to default.







[14:15:07.040] INFO: 192 hot pixels found in step 1
[14:15:08.045] INFO: Collecting data for 5 seconds...
[14:15:13.063] INFO: Done with hot pixel readout
[14:15:25.571] INFO: PixTest:: pg_setup set to default.


















[14:15:25.573] INFO: 199 hot pixels found in step 2
[14:15:26.572] INFO: Collecting data for 5 seconds...
[14:15:31.591] INFO: Done with hot pixel readout
[14:15:43.910] INFO: PixTest:: pg_setup set to default.
















[14:15:43.912] INFO: 195 hot pixels found in step 3
[14:15:44.911] INFO: Collecting data for 5 seconds...
[14:15:49.930] INFO: Done with hot pixel readout
[14:16:02.316] INFO: PixTest:: pg_setup set to default.






















[14:16:02.317] INFO: 160 hot pixels found in step 4
[14:16:03.316] INFO: Collecting data for 5 seconds...
[14:16:08.335] INFO: Done with hot pixel readout
[14:16:20.682] INFO: PixTest:: pg_setup set to default.


















[14:16:20.684] INFO: 170 hot pixels found in step 5
[14:16:21.683] INFO: Collecting data for 5 seconds...
[14:16:26.701] INFO: Done with hot pixel readout
[14:16:39.008] INFO: PixTest:: pg_setup set to default.



























[14:16:39.010] INFO: 144 hot pixels found in step 6
[14:16:40.008] INFO: Collecting data for 5 seconds...
[14:16:45.026] INFO: Done with hot pixel readout
[14:16:57.292] INFO: PixTest:: pg_setup set to default.


























[14:16:57.293] INFO: 154 hot pixels found in step 7
[14:16:58.291] INFO: Collecting data for 5 seconds...
[14:17:03.309] INFO: Done with hot pixel readout
[14:17:15.426] INFO: PixTest:: pg_setup set to default.





























[14:17:15.427] INFO: 149 hot pixels found in step 8
[14:17:16.426] INFO: Collecting data for 5 seconds...
[14:17:21.443] INFO: Done with hot pixel readout
[14:17:33.732] INFO: PixTest:: pg_setup set to default.























[14:17:33.734] INFO: 128 hot pixels found in step 9
[14:17:34.733] INFO: Collecting data for 5 seconds...
[14:17:39.751] INFO: Done with hot pixel readout
[14:17:51.671] INFO: PixTest:: pg_setup set to default.



































[14:17:51.672] INFO: 114 hot pixels found in step 10
[14:17:52.672] INFO: Collecting data for 5 seconds...
[14:17:57.690] INFO: Done with hot pixel readout
[14:18:10.367] INFO: PixTest:: pg_setup set to default.


























[14:18:10.369] INFO: 109 hot pixels found in step 11
[14:18:11.366] INFO: Collecting data for 5 seconds...
[14:18:16.385] INFO: Done with hot pixel readout
[14:18:29.060] INFO: PixTest:: pg_setup set to default.





























[14:18:29.061] INFO: 123 hot pixels found in step 12
[14:18:30.060] INFO: Collecting data for 5 seconds...
[14:18:35.079] INFO: Done with hot pixel readout
[14:18:47.758] INFO: PixTest:: pg_setup set to default.































[14:18:47.760] INFO: 108 hot pixels found in step 13
[14:18:48.758] INFO: Collecting data for 5 seconds...
[14:18:53.777] INFO: Done with hot pixel readout
[14:19:06.116] INFO: PixTest:: pg_setup set to default.























[14:19:06.118] INFO: 98 hot pixels found in step 14
[14:19:06.161] INFO: 98 hot pixels could not be trimmed and have been masked.
[14:19:06.165] INFO: PixTest::trimHotPixels() done
[14:19:06.165] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C0.dat
[14:19:06.174] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C1.dat
[14:19:06.183] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C2.dat
[14:19:06.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C3.dat
[14:19:06.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C4.dat
[14:19:06.209] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C5.dat
[14:19:06.218] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C6.dat
[14:19:06.226] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C7.dat
[14:19:06.235] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C8.dat
[14:19:06.244] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C9.dat
[14:19:06.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C10.dat
[14:19:06.261] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C11.dat
[14:19:06.270] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C12.dat
[14:19:06.278] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C13.dat
[14:19:06.285] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C14.dat
[14:19:06.291] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//trimParameters35_C15.dat
[14:19:06.297] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-5-20_FPIXTest-17C-FNAL-161024-1025-150V_2016-10-24_10h25m_1477322714/000_FPIXTest_p17//defaultMaskFile.dat
[14:19:06.311] INFO: enter test to run
[14:19:24.165] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:19:24.165] INFO: running: xray
[14:19:24.167] INFO: ----------------------------------------------------------------------
[14:19:24.167] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:19:24.167] INFO: ----------------------------------------------------------------------
[14:19:25.129] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:19:35.858] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[14:20:05.589] INFO: Resuming triggers.
[14:20:16.320] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:20:46.355] INFO: Resuming triggers.
[14:20:57.085] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:21:26.948] INFO: Resuming triggers.
[14:21:37.681] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[14:22:07.212] INFO: Resuming triggers.
[14:22:17.940] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[14:22:47.787] INFO: Resuming triggers.
[14:22:58.516] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[14:23:27.692] INFO: Resuming triggers.
[14:23:38.425] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:24:07.744] INFO: Resuming triggers.
[14:24:18.471] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:24:47.252] INFO: Resuming triggers.
[14:24:57.981] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:25:27.333] INFO: Resuming triggers.
[14:25:31.099] INFO: data taking finished, elapsed time: 100 seconds.
[14:25:41.741] INFO: PixTest:: pg_setup set to default.
[14:25:41.745] INFO: PixTestXray::doPhRun() done
[14:25:41.980] INFO: enter test to run
[14:26:02.659] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:26:02.659] INFO: running: xray
[14:26:02.660] INFO: ----------------------------------------------------------------------
[14:26:02.660] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:26:02.660] INFO: ----------------------------------------------------------------------
[14:26:03.623] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:26:10.067] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:26:40.436] INFO: Resuming triggers.
[14:26:46.878] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:27:16.966] INFO: Resuming triggers.
[14:27:23.408] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:27:53.516] INFO: Resuming triggers.
[14:27:59.957] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[14:28:30.860] INFO: Resuming triggers.
[14:28:37.301] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:29:08.241] INFO: Resuming triggers.
[14:29:14.682] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[14:29:45.606] INFO: Resuming triggers.
[14:29:52.048] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:30:22.963] INFO: Resuming triggers.
[14:30:29.409] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[14:30:59.443] INFO: Resuming triggers.
[14:31:05.887] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:31:36.341] INFO: Resuming triggers.
[14:31:42.784] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[14:32:13.330] INFO: Resuming triggers.
[14:32:19.775] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:32:50.970] INFO: Resuming triggers.
[14:32:57.417] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:33:28.606] INFO: Resuming triggers.
[14:33:35.050] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:34:06.612] INFO: Resuming triggers.
[14:34:13.062] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:34:44.311] INFO: Resuming triggers.
[14:34:50.755] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:35:22.474] INFO: Resuming triggers.
[14:35:26.171] INFO: data taking finished, elapsed time: 100 seconds.
[14:35:44.415] INFO: PixTest:: pg_setup set to default.
[14:35:44.418] INFO: PixTestXray::doPhRun() done
[14:35:44.576] INFO: enter test to run
[14:36:28.695] INFO: test: HighRate no parameter change
[14:36:28.695] INFO: running: highrate
[14:36:28.710] INFO: ----------------------------------------------------------------------
[14:36:28.710] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:36:28.710] INFO: ----------------------------------------------------------------------
[14:36:28.865] INFO: Expecting 768 events.
[14:36:29.998] INFO: 768 events read in total (418ms).
[14:36:29.999] INFO: Test took 1269ms.
[14:36:30.802] INFO: Expecting 41600 events.
[14:36:33.877] INFO: 41600 events read in total (2548ms).
[14:36:33.878] INFO: Test took 3873ms.
[14:36:33.915] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:34.639] INFO: Expecting 41600 events.
[14:36:37.891] INFO: 41600 events read in total (2725ms).
[14:36:37.893] INFO: Test took 3959ms.
[14:36:37.934] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:38.632] INFO: Expecting 41600 events.
[14:36:41.850] INFO: 41600 events read in total (2691ms).
[14:36:41.851] INFO: Test took 3898ms.
[14:36:41.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:42.608] INFO: Expecting 41600 events.
[14:36:45.870] INFO: 41600 events read in total (2735ms).
[14:36:45.871] INFO: Test took 3963ms.
[14:36:45.909] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:46.628] INFO: Expecting 41600 events.
[14:36:49.862] INFO: 41600 events read in total (2707ms).
[14:36:49.863] INFO: Test took 3933ms.
[14:36:49.901] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:50.616] INFO: Expecting 41600 events.
[14:36:53.890] INFO: 41600 events read in total (2747ms).
[14:36:53.891] INFO: Test took 3969ms.
[14:36:53.928] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:54.639] INFO: Expecting 41600 events.
[14:36:57.914] INFO: 41600 events read in total (2748ms).
[14:36:57.915] INFO: Test took 3966ms.
[14:36:57.953] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:58.669] INFO: Expecting 41600 events.
[14:37:01.959] INFO: 41600 events read in total (2763ms).
[14:37:01.960] INFO: Test took 3987ms.
[14:37:01.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:02.714] INFO: Expecting 41600 events.
[14:37:05.004] INFO: 41600 events read in total (2763ms).
[14:37:05.005] INFO: Test took 3989ms.
[14:37:06.043] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:06.761] INFO: Expecting 41600 events.
[14:37:10.033] INFO: 41600 events read in total (2746ms).
[14:37:10.034] INFO: Test took 3971ms.
[14:37:10.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:10.786] INFO: Expecting 41600 events.
[14:37:14.067] INFO: 41600 events read in total (2755ms).
[14:37:14.068] INFO: Test took 3976ms.
[14:37:14.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:14.824] INFO: Expecting 41600 events.
[14:37:18.054] INFO: 41600 events read in total (2703ms).
[14:37:18.055] INFO: Test took 3929ms.
[14:37:18.092] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:18.812] INFO: Expecting 41600 events.
[14:37:22.083] INFO: 41600 events read in total (2744ms).
[14:37:22.084] INFO: Test took 3972ms.
[14:37:22.122] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:22.840] INFO: Expecting 41600 events.
[14:37:26.105] INFO: 41600 events read in total (2738ms).
[14:37:26.106] INFO: Test took 3966ms.
[14:37:26.144] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:26.863] INFO: Expecting 41600 events.
[14:37:30.111] INFO: 41600 events read in total (2721ms).
[14:37:30.113] INFO: Test took 3949ms.
[14:37:30.150] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:30.867] INFO: Expecting 41600 events.
[14:37:34.155] INFO: 41600 events read in total (2761ms).
[14:37:34.156] INFO: Test took 3986ms.
[14:37:34.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:34.910] INFO: Expecting 41600 events.
[14:37:38.198] INFO: 41600 events read in total (2761ms).
[14:37:38.199] INFO: Test took 3984ms.
[14:37:38.237] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:38.953] INFO: Expecting 41600 events.
[14:37:42.222] INFO: 41600 events read in total (2742ms).
[14:37:42.223] INFO: Test took 3966ms.
[14:37:42.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:42.980] INFO: Expecting 41600 events.
[14:37:46.264] INFO: 41600 events read in total (2757ms).
[14:37:46.265] INFO: Test took 3985ms.
[14:37:46.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:47.021] INFO: Expecting 41600 events.
[14:37:50.209] INFO: 41600 events read in total (2661ms).
[14:37:50.211] INFO: Test took 3889ms.
[14:37:50.248] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:50.605] INFO: enter test to run
[14:38:21.982] INFO: test: HighRate no parameter change
[14:38:21.982] INFO: running: highrate
[14:38:21.983] INFO: ----------------------------------------------------------------------
[14:38:21.983] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:38:21.983] INFO: ----------------------------------------------------------------------
[14:38:22.594] INFO: Expecting 208000 events.
[14:38:34.684] INFO: 208000 events read in total (11563ms).
[14:38:34.687] INFO: Test took 12694ms.
[14:38:34.850] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:35.109] INFO: number of dead pixels (per ROC): 0 2 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[14:38:35.109] INFO: number of red-efficiency pixels: 78 40 78 169 149 155 160 88 119 147 120 113 162 98 27 26
[14:38:35.109] INFO: number of X-ray hits detected: 68456 41875 72404 112734 115292 122547 125594 82585 86976 129750 128183 102105 109891 67228 26323 28472
[14:38:35.109] 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:38:35.109] INFO: number of Vcal hits detected: 207921 207862 207921 207775 207847 207843 207837 207909 207879 207850 207876 207882 207834 207898 207973 207974
[14:38:35.109] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[14:38:35.109] INFO: Vcal hit overall efficiency (%): 100.0 99.9 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:38:35.109] INFO: X-ray hit rate [MHz/cm2]: 20.1 12.3 21.2 33.0 33.8 35.9 36.8 24.2 25.5 38.0 37.6 29.9 32.2 19.7 7.7 8.3
[14:38:35.109] INFO: PixTestHighRate::doXPixelAlive() done
[14:38:35.159] INFO: PixTest:: pg_setup set to default.
[14:38:35.175] INFO: enter test to run
[14:39:23.261] INFO: test: HighRate no parameter change
[14:39:23.262] INFO: running: highrate
[14:39:23.263] INFO: ----------------------------------------------------------------------
[14:39:23.263] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:39:23.263] INFO: ----------------------------------------------------------------------
[14:39:23.877] INFO: Expecting 208000 events.
[14:39:37.815] INFO: 208000 events read in total (13411ms).
[14:39:37.821] INFO: Test took 14549ms.
[14:39:38.149] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:38.461] INFO: number of dead pixels (per ROC): 0 2 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[14:39:38.461] INFO: number of red-efficiency pixels: 188 106 286 461 546 551 618 237 326 450 512 333 490 305 63 73
[14:39:38.461] INFO: number of X-ray hits detected: 138690 84855 148136 228767 233648 250428 255020 167848 177391 262815 259356 207124 223337 135733 53810 57818
[14:39:38.461] 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:39:38.461] INFO: number of Vcal hits detected: 207801 207793 207689 207447 207396 207380 207307 207748 207651 207510 207432 207640 207462 207662 207935 207924
[14:39:38.461] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.7 99.7 99.7 99.9 99.8 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[14:39:38.461] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.7 99.9 99.8 99.8 99.7 99.8 99.7 99.8 100.0 100.0
[14:39:38.461] INFO: X-ray hit rate [MHz/cm2]: 40.7 24.9 43.4 67.1 68.5 73.4 74.7 49.2 52.0 77.0 76.0 60.7 65.5 39.8 15.8 16.9
[14:39:38.461] INFO: PixTestHighRate::doXPixelAlive() done
[14:39:38.510] INFO: PixTest:: pg_setup set to default.
[14:39:38.525] INFO: enter test to run
[14:39:51.533] INFO: test: HighRate no parameter change
[14:39:51.533] INFO: running: highrate
[14:39:51.535] INFO: ----------------------------------------------------------------------
[14:39:51.535] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:39:51.535] INFO: ----------------------------------------------------------------------
[14:39:52.152] INFO: Expecting 208000 events.
[14:40:08.095] INFO: 208000 events read in total (15416ms).
[14:40:08.103] INFO: Test took 16558ms.
[14:40:08.575] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:08.932] INFO: number of dead pixels (per ROC): 0 2 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[14:40:08.932] INFO: number of red-efficiency pixels: 383 189 529 1127 1104 1224 1351 518 657 1043 1006 649 1048 627 92 94
[14:40:08.932] INFO: number of X-ray hits detected: 201521 124491 214236 334249 340313 363011 370536 245900 258505 382239 377647 301753 325523 197704 78440 84592
[14:40:08.932] 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:40:08.932] INFO: number of Vcal hits detected: 207566 207703 207319 206545 206638 206437 206201 207385 207177 206722 206770 207237 206707 207195 207907 207902
[14:40:08.932] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.4 99.3 99.2 99.7 99.6 99.4 99.5 99.7 99.4 99.7 100.0 100.0
[14:40:08.932] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.3 99.3 99.2 99.1 99.7 99.6 99.4 99.4 99.6 99.4 99.6 100.0 100.0
[14:40:08.932] INFO: X-ray hit rate [MHz/cm2]: 59.1 36.5 62.8 98.0 99.7 106.4 108.6 72.1 75.8 112.0 110.7 88.4 95.4 57.9 23.0 24.8
[14:40:08.932] INFO: PixTestHighRate::doXPixelAlive() done
[14:40:08.978] INFO: PixTest:: pg_setup set to default.
[14:40:08.994] INFO: enter test to run
[14:40:13.277] INFO: test: exit no parameter change
[14:40:13.732] QUIET: Connection to board 30 closed.
[14:40:13.820] INFO: pXar: this is the end, my friend