[10:18:12.210] INFO: *** Welcome to pxar ***
[10:18:12.210] INFO: *** Today: 2016/10/20
[10:18:13.030] INFO: *** Version: v1.9.0-818-g96727
[10:18:13.030] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//dacParameters35_C15.dat
[10:18:13.053] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:18:13.053] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//defaultMaskFile.dat
[10:18:13.059] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C15.dat
[10:18:13.158] INFO: clk: 4
[10:18:13.158] INFO: ctr: 4
[10:18:13.158] INFO: sda: 19
[10:18:13.158] INFO: tin: 9
[10:18:13.158] INFO: level: 15
[10:18:13.158] INFO: triggerdelay: 0
[10:18:13.158] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[10:18:13.158] INFO: Log level: INFO
[10:18:13.174] QUIET: Connection to board DTB_WREKRL opened.
[10:18:13.177] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[10:18:13.180] INFO: RPC call hashes of host and DTB match: 398089610
[10:18:14.718] INFO: DUT info:
[10:18:14.718] INFO: The DUT currently contains the following objects:
[10:18:14.718] INFO: 2 TBM Cores tbm08c (2 ON)
[10:18:14.718] INFO: TBM Core alpha (0): 7 registers set
[10:18:14.718] INFO: TBM Core beta (1): 7 registers set
[10:18:14.718] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:18:14.718] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.718] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.718] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.718] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.718] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:14.719] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:15.123] INFO: enter 'restricted' command line mode
[10:18:15.123] INFO: enter test to run
[10:18:22.220] INFO: test: yPixelAlive no parameter change
[10:18:22.220] INFO: running: ypixelalive
[10:18:22.234] INFO: command ->ypixelalive<- not known, ignored
[10:18:22.234] INFO: enter test to run
[10:18:29.892] INFO: test: timing no parameter change
[10:18:29.892] INFO: running: timing
[10:18:29.903] INFO: ######################################################################
[10:18:29.903] INFO: PixTestTiming::doTest()
[10:18:29.903] INFO: ######################################################################
[10:18:29.903] INFO: ----------------------------------------------------------------------
[10:18:29.904] INFO: PixTestTiming::TBMPhaseScan()
[10:18:29.904] INFO: ----------------------------------------------------------------------
[10:24:43.108] INFO: TBM Phase Settings: 208
[10:24:43.108] INFO: 400MHz Phase: 4
[10:24:43.108] INFO: 160MHz Phase: 6
[10:24:43.108] INFO: Functional Phase Area: 4
[10:24:43.112] INFO: Test took 373209 ms.
[10:24:43.112] INFO: PixTestTiming::TBMPhaseScan() done.
[10:24:43.112] INFO: ----------------------------------------------------------------------
[10:24:43.112] INFO: PixTestTiming::ROCDelayScan()
[10:24:43.112] INFO: ----------------------------------------------------------------------
[10:26:38.625] INFO: ROC Delay Settings: 219
[10:26:38.625] INFO: ROC Header-Trailer/Token Delay: 11
[10:26:38.625] INFO: ROC Port 0 Delay: 3
[10:26:38.625] INFO: ROC Port 1 Delay: 3
[10:26:38.625] INFO: Functional ROC Area: 4
[10:26:38.629] INFO: Test took 115517 ms.
[10:26:38.629] INFO: PixTestTiming::ROCDelayScan() done.
[10:26:38.629] INFO: ----------------------------------------------------------------------
[10:26:38.629] INFO: PixTestTiming::TimingTest()
[10:26:38.629] INFO: ----------------------------------------------------------------------
[10:26:54.962] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:10.112] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:24.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:39.919] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:54.934] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:10.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:25.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:40.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:55.456] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:10.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:11.010] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:11.027] INFO: ----------------------------------------------------------------------
[10:29:11.027] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[10:29:11.027] INFO: ----------------------------------------------------------------------
[10:29:11.027] INFO: ----------------------------------------------------------------------
[10:29:11.027] INFO: Read back bit status: 1
[10:29:11.027] INFO: ----------------------------------------------------------------------
[10:29:11.027] INFO: ----------------------------------------------------------------------
[10:29:11.027] INFO: Timings are good!
[10:29:11.027] INFO: ----------------------------------------------------------------------
[10:29:11.027] INFO: Test took 152398 ms.
[10:29:11.027] INFO: PixTestTiming::TimingTest() done.
[10:29:11.070] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//tbmParameters_C0a.dat
[10:29:11.070] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:29:11.070] INFO: PixTestTiming::doTest took 641172 ms.
[10:29:11.070] INFO: PixTestTiming::doTest() done
[10:29:11.071] INFO: Write out TBMPhaseScan_0_V0
[10:29:11.618] INFO: Write out TBMPhaseScan_1_V0
[10:29:11.618] INFO: Write out CombinedTBMPhaseScan_V0
[10:29:11.649] INFO: Write out ROCDelayScan3_V0
[10:29:11.666] INFO: enter test to run
[10:29:49.159] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:29:49.159] INFO: running: highrate
[10:29:49.191] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:29:49.458] INFO: ----------------------------------------------------------------------
[10:29:49.458] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:29:49.458] INFO: ----------------------------------------------------------------------
[10:29:49.458] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:29:49.458] INFO: edge/corner pixel THR is adjusted
[10:29:49.458] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:29:50.445] INFO: Collecting data for 5 seconds...
[10:29:55.462] INFO: Done with hot pixel readout
[10:30:07.017] INFO: PixTest:: pg_setup set to default.
[10:30:07.017] INFO: 12 hot pixels found in step 0
[10:30:08.010] INFO: Collecting data for 5 seconds...
[10:30:13.027] INFO: Done with hot pixel readout
[10:30:24.754] INFO: PixTest:: pg_setup set to default.
[10:30:24.755] INFO: 13 hot pixels found in step 1
[10:30:25.747] INFO: Collecting data for 5 seconds...
[10:30:30.764] INFO: Done with hot pixel readout
[10:30:42.381] INFO: PixTest:: pg_setup set to default.
[10:30:42.382] INFO: 11 hot pixels found in step 2
[10:30:43.375] INFO: Collecting data for 5 seconds...
[10:30:48.392] INFO: Done with hot pixel readout
[10:31:00.024] INFO: PixTest:: pg_setup set to default.
[10:31:00.025] INFO: 8 hot pixels found in step 3
[10:31:01.016] INFO: Collecting data for 5 seconds...
[10:31:06.033] INFO: Done with hot pixel readout
[10:31:17.785] INFO: PixTest:: pg_setup set to default.
[10:31:17.786] INFO: 5 hot pixels found in step 4
[10:31:18.778] INFO: Collecting data for 5 seconds...
[10:31:23.795] INFO: Done with hot pixel readout
[10:31:35.453] INFO: PixTest:: pg_setup set to default.
[10:31:35.454] INFO: 2 hot pixels found in step 5
[10:31:36.446] INFO: Collecting data for 5 seconds...
[10:31:41.463] INFO: Done with hot pixel readout
[10:31:53.147] INFO: PixTest:: pg_setup set to default.
[10:31:53.148] INFO: 2 hot pixels found in step 6
[10:31:54.140] INFO: Collecting data for 5 seconds...
[10:31:59.158] INFO: Done with hot pixel readout
[10:32:10.957] INFO: PixTest:: pg_setup set to default.
[10:32:10.958] INFO: 7 hot pixels found in step 7
[10:32:11.950] INFO: Collecting data for 5 seconds...
[10:32:16.969] INFO: Done with hot pixel readout
[10:32:28.836] INFO: PixTest:: pg_setup set to default.
[10:32:28.837] INFO: 2 hot pixels found in step 8
[10:32:29.829] INFO: Collecting data for 5 seconds...
[10:32:34.848] INFO: Done with hot pixel readout
[10:32:46.509] INFO: PixTest:: pg_setup set to default.
[10:32:46.510] INFO: 1 hot pixels found in step 9
[10:32:47.501] INFO: Collecting data for 5 seconds...
[10:32:52.519] INFO: Done with hot pixel readout
[10:33:03.850] INFO: PixTest:: pg_setup set to default.

[10:33:03.851] INFO: 4 hot pixels found in step 10
[10:33:04.842] INFO: Collecting data for 5 seconds...
[10:33:09.861] INFO: Done with hot pixel readout
[10:33:21.018] INFO: PixTest:: pg_setup set to default.
[10:33:21.019] INFO: 2 hot pixels found in step 11
[10:33:22.011] INFO: Collecting data for 5 seconds...
[10:33:27.030] INFO: Done with hot pixel readout
[10:33:38.417] INFO: PixTest:: pg_setup set to default.
[10:33:38.418] INFO: 0 hot pixels found in step 12
[10:33:38.461] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:33:38.464] INFO: PixTest::trimHotPixels() done
[10:33:38.464] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C0.dat
[10:33:38.484] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C1.dat
[10:33:38.490] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C2.dat
[10:33:38.510] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C3.dat
[10:33:38.515] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C4.dat
[10:33:38.521] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C5.dat
[10:33:38.526] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C6.dat
[10:33:38.532] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C7.dat
[10:33:38.537] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C8.dat
[10:33:38.543] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C9.dat
[10:33:38.548] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C10.dat
[10:33:38.554] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C11.dat
[10:33:38.559] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C12.dat
[10:33:38.564] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C13.dat
[10:33:38.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C14.dat
[10:33:38.575] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//trimParameters35_C15.dat
[10:33:38.581] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-8-39_FPIXTest-17C-FNAL-161019-1258-150V_2016-10-19_12h58m_1476899905/000_FPIXTest_p17//defaultMaskFile.dat
[10:33:38.595] INFO: enter test to run
[10:34:28.501] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:34:28.502] INFO: running: xray
[10:34:28.503] INFO: ----------------------------------------------------------------------
[10:34:28.503] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:34:28.503] INFO: ----------------------------------------------------------------------
[10:34:29.480] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:34:41.209] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:35:11.437] INFO: Resuming triggers.
[10:35:23.171] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:35:53.082] INFO: Resuming triggers.
[10:36:04.813] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[10:36:34.901] INFO: Resuming triggers.
[10:36:46.637] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:37:16.736] INFO: Resuming triggers.
[10:37:28.470] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[10:37:59.473] INFO: Resuming triggers.
[10:38:11.206] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[10:38:41.893] INFO: Resuming triggers.
[10:38:53.628] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:39:24.365] INFO: Resuming triggers.
[10:39:36.100] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[10:40:06.972] INFO: Resuming triggers.
[10:40:13.489] INFO: data taking finished, elapsed time: 100 seconds.
[10:40:30.928] INFO: PixTest:: pg_setup set to default.
[10:40:30.931] INFO: PixTestXray::doPhRun() done
[10:40:31.285] INFO: enter test to run
[10:41:22.219] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:41:22.219] INFO: running: xray
[10:41:22.220] INFO: ----------------------------------------------------------------------
[10:41:22.220] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:41:22.220] INFO: ----------------------------------------------------------------------
[10:41:23.183] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:41:30.141] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:42:00.857] INFO: Resuming triggers.
[10:42:07.816] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:42:38.448] INFO: Resuming triggers.
[10:42:45.409] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[10:43:15.921] INFO: Resuming triggers.
[10:43:22.881] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[10:43:53.494] INFO: Resuming triggers.
[10:44:00.453] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:44:31.143] INFO: Resuming triggers.
[10:44:38.103] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[10:45:08.907] INFO: Resuming triggers.
[10:45:15.865] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[10:45:46.495] INFO: Resuming triggers.
[10:45:53.453] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[10:46:24.193] INFO: Resuming triggers.
[10:46:31.157] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[10:47:01.707] INFO: Resuming triggers.
[10:47:08.671] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:47:39.002] INFO: Resuming triggers.
[10:47:46.960] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[10:48:18.074] INFO: Resuming triggers.
[10:48:25.037] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[10:48:56.177] INFO: Resuming triggers.
[10:49:03.139] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[10:49:34.441] INFO: Resuming triggers.
[10:49:41.404] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[10:50:12.463] INFO: Resuming triggers.
[10:50:15.368] INFO: data taking finished, elapsed time: 100 seconds.
[10:50:28.567] INFO: PixTest:: pg_setup set to default.
[10:50:28.570] INFO: PixTestXray::doPhRun() done
[10:50:28.722] INFO: enter test to run
[10:51:03.815] INFO: test: HighRate no parameter change
[10:51:03.815] INFO: running: highrate
[10:51:03.864] INFO: ----------------------------------------------------------------------
[10:51:03.864] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:51:03.864] INFO: ----------------------------------------------------------------------
[10:51:04.021] INFO: Expecting 768 events.
[10:51:05.156] INFO: 768 events read in total (419ms).
[10:51:05.156] INFO: Test took 1271ms.
[10:51:05.959] INFO: Expecting 41600 events.
[10:51:09.115] INFO: 41600 events read in total (2629ms).
[10:51:09.116] INFO: Test took 3895ms.
[10:51:09.152] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:09.868] INFO: Expecting 41600 events.
[10:51:13.153] INFO: 41600 events read in total (2759ms).
[10:51:13.154] INFO: Test took 3970ms.
[10:51:13.190] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:13.907] INFO: Expecting 41600 events.
[10:51:17.105] INFO: 41600 events read in total (2671ms).
[10:51:17.106] INFO: Test took 3897ms.
[10:51:17.144] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:17.862] INFO: Expecting 41600 events.
[10:51:21.106] INFO: 41600 events read in total (2717ms).
[10:51:21.108] INFO: Test took 3946ms.
[10:51:21.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:21.857] INFO: Expecting 41600 events.
[10:51:25.165] INFO: 41600 events read in total (2781ms).
[10:51:25.166] INFO: Test took 4000ms.
[10:51:25.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:25.925] INFO: Expecting 41600 events.
[10:51:29.197] INFO: 41600 events read in total (2745ms).
[10:51:29.198] INFO: Test took 3976ms.
[10:51:29.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:29.950] INFO: Expecting 41600 events.
[10:51:33.217] INFO: 41600 events read in total (2740ms).
[10:51:33.218] INFO: Test took 3964ms.
[10:51:33.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:33.970] INFO: Expecting 41600 events.
[10:51:37.258] INFO: 41600 events read in total (2761ms).
[10:51:37.259] INFO: Test took 3985ms.
[10:51:37.296] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:38.006] INFO: Expecting 41600 events.
[10:51:41.364] INFO: 41600 events read in total (2831ms).
[10:51:41.365] INFO: Test took 4049ms.
[10:51:41.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:42.114] INFO: Expecting 41600 events.
[10:51:45.390] INFO: 41600 events read in total (2750ms).
[10:51:45.391] INFO: Test took 3964ms.
[10:51:45.429] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:46.149] INFO: Expecting 41600 events.
[10:51:49.431] INFO: 41600 events read in total (2755ms).
[10:51:49.432] INFO: Test took 3985ms.
[10:51:49.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:50.187] INFO: Expecting 41600 events.
[10:51:53.429] INFO: 41600 events read in total (2716ms).
[10:51:53.430] INFO: Test took 3941ms.
[10:51:53.467] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:54.185] INFO: Expecting 41600 events.
[10:51:57.411] INFO: 41600 events read in total (2700ms).
[10:51:57.412] INFO: Test took 3926ms.
[10:51:57.449] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:58.167] INFO: Expecting 41600 events.
[10:52:01.454] INFO: 41600 events read in total (2760ms).
[10:52:01.455] INFO: Test took 3987ms.
[10:52:01.491] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:02.210] INFO: Expecting 41600 events.
[10:52:05.547] INFO: 41600 events read in total (2810ms).
[10:52:05.548] INFO: Test took 4036ms.
[10:52:05.585] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:06.303] INFO: Expecting 41600 events.
[10:52:09.609] INFO: 41600 events read in total (2780ms).
[10:52:09.610] INFO: Test took 4006ms.
[10:52:09.651] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:10.369] INFO: Expecting 41600 events.
[10:52:13.675] INFO: 41600 events read in total (2780ms).
[10:52:13.676] INFO: Test took 4007ms.
[10:52:13.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:14.429] INFO: Expecting 41600 events.
[10:52:17.760] INFO: 41600 events read in total (2804ms).
[10:52:17.761] INFO: Test took 4028ms.
[10:52:17.798] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:18.514] INFO: Expecting 41600 events.
[10:52:21.793] INFO: 41600 events read in total (2752ms).
[10:52:21.794] INFO: Test took 3977ms.
[10:52:21.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:22.550] INFO: Expecting 41600 events.
[10:52:25.729] INFO: 41600 events read in total (2652ms).
[10:52:25.730] INFO: Test took 3880ms.
[10:52:25.771] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:26.103] INFO: enter test to run
[10:53:23.774] INFO: test: HighRate no parameter change
[10:53:23.774] INFO: running: highrate
[10:53:23.775] INFO: ----------------------------------------------------------------------
[10:53:23.775] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:53:23.775] INFO: ----------------------------------------------------------------------
[10:53:24.409] INFO: Expecting 208000 events.
[10:53:36.771] INFO: 208000 events read in total (11835ms).
[10:53:36.774] INFO: Test took 12972ms.
[10:53:36.949] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:37.219] INFO: number of dead pixels (per ROC): 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:53:37.219] INFO: number of red-efficiency pixels: 73 69 91 162 180 180 160 128 95 132 108 97 88 66 28 22
[10:53:37.219] INFO: number of X-ray hits detected: 71214 46031 69718 107281 117526 123059 128145 93892 83699 110493 106194 87935 91718 55305 22030 24983
[10:53:37.219] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:53:37.219] INFO: number of Vcal hits detected: 207924 207831 207907 207833 207813 207814 207836 207870 207904 207865 207888 207901 207912 207932 207972 207978
[10:53:37.220] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[10:53:37.220] INFO: Vcal hit overall efficiency (%): 100.0 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[10:53:37.220] INFO: X-ray hit rate [MHz/cm2]: 20.9 13.5 20.4 31.4 34.4 36.1 37.6 27.5 24.5 32.4 31.1 25.8 26.9 16.2 6.5 7.3
[10:53:37.220] INFO: PixTestHighRate::doXPixelAlive() done
[10:53:37.265] INFO: PixTest:: pg_setup set to default.
[10:53:37.278] INFO: enter test to run
[10:54:27.325] INFO: test: HighRate no parameter change
[10:54:27.326] INFO: running: highrate
[10:54:27.327] INFO: ----------------------------------------------------------------------
[10:54:27.327] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:54:27.327] INFO: ----------------------------------------------------------------------
[10:54:27.951] INFO: Expecting 208000 events.
[10:54:41.667] INFO: 208000 events read in total (13190ms).
[10:54:41.672] INFO: Test took 14336ms.
[10:54:41.965] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:42.264] INFO: number of dead pixels (per ROC): 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:54:42.264] INFO: number of red-efficiency pixels: 202 159 256 401 472 512 429 349 197 322 291 263 228 162 45 63
[10:54:42.264] INFO: number of X-ray hits detected: 133025 87059 130239 201011 220025 230285 239180 175081 155511 205893 198838 164266 169981 103031 41979 46869
[10:54:42.264] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:54:42.264] INFO: number of Vcal hits detected: 207789 207739 207723 207581 207488 207437 207521 207610 207801 207656 207701 207728 207763 207832 207955 207936
[10:54:42.264] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[10:54:42.264] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[10:54:42.265] INFO: X-ray hit rate [MHz/cm2]: 39.0 25.5 38.2 58.9 64.5 67.5 70.1 51.3 45.6 60.3 58.3 48.1 49.8 30.2 12.3 13.7
[10:54:42.265] INFO: PixTestHighRate::doXPixelAlive() done
[10:54:42.310] INFO: PixTest:: pg_setup set to default.
[10:54:42.328] INFO: enter test to run
[10:55:28.421] INFO: test: HighRate no parameter change
[10:55:28.421] INFO: running: highrate
[10:55:28.423] INFO: ----------------------------------------------------------------------
[10:55:28.423] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:55:28.423] INFO: ----------------------------------------------------------------------
[10:55:29.036] INFO: Expecting 208000 events.
[10:55:44.605] INFO: 208000 events read in total (15042ms).
[10:55:44.612] INFO: Test took 16180ms.
[10:55:45.023] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:55:45.364] INFO: number of dead pixels (per ROC): 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:55:45.364] INFO: number of red-efficiency pixels: 373 276 532 831 1077 1177 963 743 426 684 593 546 481 315 73 90
[10:55:45.364] INFO: number of X-ray hits detected: 196114 128185 190824 295126 323724 338693 350634 258836 230132 302740 292701 242485 251970 151450 61714 69434
[10:55:45.364] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:55:45.364] INFO: number of Vcal hits detected: 207562 207602 207319 207022 206675 206493 206824 207070 207524 207219 207330 207371 207480 207641 207926 207908
[10:55:45.364] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.4 99.3 99.5 99.6 99.8 99.7 99.7 99.7 99.8 99.8 100.0 100.0
[10:55:45.364] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.7 99.5 99.4 99.3 99.4 99.6 99.8 99.6 99.7 99.7 99.8 99.8 100.0 100.0
[10:55:45.364] INFO: X-ray hit rate [MHz/cm2]: 57.5 37.6 55.9 86.5 94.9 99.3 102.8 75.9 67.5 88.7 85.8 71.1 73.9 44.4 18.1 20.4
[10:55:45.364] INFO: PixTestHighRate::doXPixelAlive() done
[10:55:45.410] INFO: PixTest:: pg_setup set to default.
[10:55:45.426] INFO: enter test to run
[10:56:04.485] INFO: test: exit no parameter change
[10:56:05.188] QUIET: Connection to board 33 closed.
[10:56:05.375] INFO: pXar: this is the end, my friend