[15:07:22.827] INFO: *** Welcome to pxar ***
[15:07:22.828] INFO: *** Today: 2016/09/14
[15:07:24.412] INFO: *** Version: v1.9.0-818-g96727
[15:07:24.439] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//dacParameters35_C15.dat
[15:07:24.723] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:07:24.738] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//defaultMaskFile.dat
[15:07:24.759] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C15.dat
[15:07:25.447] INFO: clk: 4
[15:07:25.447] INFO: ctr: 4
[15:07:25.447] INFO: sda: 19
[15:07:25.447] INFO: tin: 9
[15:07:25.447] INFO: level: 15
[15:07:25.447] INFO: triggerdelay: 0
[15:07:25.447] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:07:25.447] INFO: Log level: INFO
[15:07:25.581] QUIET: Connection to board DTB_WREKRL opened.
[15:07:25.585] 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:
------------------------------------------------------
[15:07:25.587] INFO: RPC call hashes of host and DTB match: 398089610
[15:07:27.128] INFO: DUT info:
[15:07:27.146] INFO: The DUT currently contains the following objects:
[15:07:27.146] INFO: 2 TBM Cores tbm08c (2 ON)
[15:07:27.146] INFO: TBM Core alpha (0): 7 registers set
[15:07:27.146] INFO: TBM Core beta (1): 7 registers set
[15:07:27.146] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:07:27.146] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.146] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.146] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.146] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.147] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:27.675] INFO: enter 'restricted' command line mode
[15:07:27.675] INFO: enter test to run
[15:07:34.169] INFO: test: PixelAlive no parameter change
[15:07:34.169] INFO: running: pixelalive
[15:07:34.344] INFO: ----------------------------------------------------------------------
[15:07:34.344] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:07:34.344] INFO: ----------------------------------------------------------------------
[15:07:34.667] INFO: Expecting 41600 events.
[15:07:38.955] INFO: 41600 events read in total (3570ms).
[15:07:39.124] INFO: Test took 4777ms.
[15:07:39.135] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:39.507] INFO: PixTestAlive::aliveTest() done
[15:07:39.507] INFO: number of dead pixels (per ROC): 0 2 0 0 0 3 0 0 0 0 0 0 0 0 0 0
[15:07:39.638] INFO: enter test to run
[15:08:39.121] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:08:39.121] INFO: running: highrate
[15:08:39.121] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:08:39.431] INFO: ----------------------------------------------------------------------
[15:08:39.431] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:08:39.431] INFO: ----------------------------------------------------------------------
[15:08:39.431] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:08:39.431] INFO: edge/corner pixel THR is adjusted
[15:08:39.431] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:08:40.390] INFO: Collecting data for 5 seconds...
[15:08:45.410] INFO: Done with hot pixel readout
[15:08:57.441] INFO: PixTest:: pg_setup set to default.
[15:08:57.442] INFO: 1 hot pixels found in step 0
[15:08:58.458] INFO: Collecting data for 5 seconds...
[15:09:03.479] INFO: Done with hot pixel readout
[15:09:15.511] INFO: PixTest:: pg_setup set to default.
[15:09:15.512] INFO: 1 hot pixels found in step 1
[15:09:16.509] INFO: Collecting data for 5 seconds...
[15:09:21.529] INFO: Done with hot pixel readout
[15:09:33.646] INFO: PixTest:: pg_setup set to default.
[15:09:33.647] INFO: 3 hot pixels found in step 2
[15:09:34.641] INFO: Collecting data for 5 seconds...
[15:09:39.660] INFO: Done with hot pixel readout
[15:09:51.475] INFO: PixTest:: pg_setup set to default.
[15:09:51.476] INFO: 0 hot pixels found in step 3
[15:09:51.513] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:09:51.629] INFO: PixTest::trimHotPixels() done
[15:09:51.652] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C0.dat
[15:09:51.663] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C1.dat
[15:09:51.687] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C2.dat
[15:09:51.693] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C3.dat
[15:09:51.698] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C4.dat
[15:09:51.704] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C5.dat
[15:09:51.709] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C6.dat
[15:09:51.715] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C7.dat
[15:09:51.720] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C8.dat
[15:09:51.726] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C9.dat
[15:09:51.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C10.dat
[15:09:51.736] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C11.dat
[15:09:51.742] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C12.dat
[15:09:51.747] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C13.dat
[15:09:51.752] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C14.dat
[15:09:51.758] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C15.dat
[15:09:51.763] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//defaultMaskFile.dat
[15:09:51.780] INFO: enter test to run
[15:11:25.648] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:11:25.648] INFO: running: highrate
[15:11:25.653] INFO: ----------------------------------------------------------------------
[15:11:25.653] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:11:25.653] INFO: ----------------------------------------------------------------------
[15:11:25.653] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:11:25.653] INFO: edge/corner pixel THR is adjusted
[15:11:25.653] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:11:26.610] INFO: Collecting data for 1 seconds...
[15:11:27.614] INFO: Done with hot pixel readout
[15:11:31.715] INFO: PixTest:: pg_setup set to default.
[15:11:31.715] INFO: 0 hot pixels found in step 0
[15:11:31.721] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:11:31.786] INFO: PixTest::trimHotPixels() done
[15:11:31.786] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C0.dat
[15:11:31.795] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C1.dat
[15:11:31.804] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C2.dat
[15:11:31.813] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C3.dat
[15:11:31.820] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C4.dat
[15:11:31.826] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C5.dat
[15:11:31.832] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C6.dat
[15:11:31.837] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C7.dat
[15:11:31.842] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C8.dat
[15:11:31.848] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C9.dat
[15:11:31.853] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C10.dat
[15:11:31.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C11.dat
[15:11:31.864] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C12.dat
[15:11:31.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C13.dat
[15:11:31.875] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C14.dat
[15:11:31.880] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//trimParameters35_C15.dat
[15:11:31.885] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-33_FPIXTest-17C-FNAL-160912-1213-150V_2016-09-12_12h14m_1473700447/000_FPIXTest_p17//defaultMaskFile.dat
[15:11:31.895] INFO: enter test to run
[15:11:50.847] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:11:50.847] INFO: running: xray
[15:11:50.871] INFO: ----------------------------------------------------------------------
[15:11:50.871] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:11:50.871] INFO: ----------------------------------------------------------------------
[15:11:51.849] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:12:02.959] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:12:30.052] INFO: Resuming triggers.
[15:12:41.165] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:13:09.305] INFO: Resuming triggers.
[15:13:20.420] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:13:48.604] INFO: Resuming triggers.
[15:13:59.720] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:14:29.019] INFO: Resuming triggers.
[15:14:40.135] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:15:09.617] INFO: Resuming triggers.
[15:15:20.735] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:15:50.048] INFO: Resuming triggers.
[15:16:01.166] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[15:16:30.596] INFO: Resuming triggers.
[15:16:41.713] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[15:17:10.854] INFO: Resuming triggers.
[15:17:21.973] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:17:50.352] INFO: Resuming triggers.
[15:17:50.653] INFO: data taking finished, elapsed time: 100 seconds.
[15:17:51.889] INFO: PixTest:: pg_setup set to default.
[15:17:51.892] INFO: PixTestXray::doPhRun() done
[15:17:52.118] INFO: enter test to run
[15:18:38.237] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:18:38.237] INFO: running: xray
[15:18:38.238] INFO: ----------------------------------------------------------------------
[15:18:38.238] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:18:38.238] INFO: ----------------------------------------------------------------------
[15:18:39.206] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:18:45.511] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:19:16.120] INFO: Resuming triggers.
[15:19:22.425] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[15:19:52.321] INFO: Resuming triggers.
[15:19:58.627] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[15:20:29.114] INFO: Resuming triggers.
[15:20:35.421] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[15:21:05.970] INFO: Resuming triggers.
[15:21:12.274] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[15:21:42.381] INFO: Resuming triggers.
[15:21:48.690] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[15:22:18.949] INFO: Resuming triggers.
[15:22:25.253] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[15:22:55.280] INFO: Resuming triggers.
[15:23:01.590] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[15:23:33.239] INFO: Resuming triggers.
[15:23:39.544] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:24:10.932] INFO: Resuming triggers.
[15:24:17.238] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[15:24:48.153] INFO: Resuming triggers.
[15:24:54.465] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[15:25:24.868] INFO: Resuming triggers.
[15:25:31.173] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[15:26:02.209] INFO: Resuming triggers.
[15:26:08.517] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[15:26:39.537] INFO: Resuming triggers.
[15:26:45.850] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[15:27:15.978] INFO: Resuming triggers.
[15:27:22.285] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[15:27:52.396] INFO: Resuming triggers.
[15:27:58.150] INFO: data taking finished, elapsed time: 100 seconds.
[15:28:25.788] INFO: PixTest:: pg_setup set to default.
[15:28:25.792] INFO: PixTestXray::doPhRun() done
[15:28:25.964] INFO: enter test to run
[15:28:54.169] INFO: test: HighRate no parameter change
[15:28:54.169] INFO: running: highrate
[15:28:54.188] INFO: ----------------------------------------------------------------------
[15:28:54.188] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:28:54.188] INFO: ----------------------------------------------------------------------
[15:28:54.342] INFO: Expecting 768 events.
[15:28:55.477] INFO: 768 events read in total (419ms).
[15:28:55.477] INFO: Test took 1269ms.
[15:28:56.280] INFO: Expecting 41600 events.
[15:28:59.388] INFO: 41600 events read in total (2581ms).
[15:28:59.389] INFO: Test took 3844ms.
[15:28:59.425] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:00.148] INFO: Expecting 41600 events.
[15:29:03.370] INFO: 41600 events read in total (2695ms).
[15:29:03.371] INFO: Test took 3928ms.
[15:29:03.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:04.127] INFO: Expecting 41600 events.
[15:29:07.368] INFO: 41600 events read in total (2714ms).
[15:29:07.369] INFO: Test took 3941ms.
[15:29:07.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:08.124] INFO: Expecting 41600 events.
[15:29:11.363] INFO: 41600 events read in total (2712ms).
[15:29:11.364] INFO: Test took 3939ms.
[15:29:11.401] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:12.117] INFO: Expecting 41600 events.
[15:29:15.349] INFO: 41600 events read in total (2705ms).
[15:29:15.350] INFO: Test took 3929ms.
[15:29:15.387] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:16.104] INFO: Expecting 41600 events.
[15:29:19.355] INFO: 41600 events read in total (2724ms).
[15:29:19.356] INFO: Test took 3951ms.
[15:29:19.392] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:20.110] INFO: Expecting 41600 events.
[15:29:23.377] INFO: 41600 events read in total (2740ms).
[15:29:23.378] INFO: Test took 3966ms.
[15:29:23.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:24.134] INFO: Expecting 41600 events.
[15:29:27.365] INFO: 41600 events read in total (2704ms).
[15:29:27.367] INFO: Test took 3935ms.
[15:29:27.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:28.124] INFO: Expecting 41600 events.
[15:29:31.371] INFO: 41600 events read in total (2721ms).
[15:29:31.372] INFO: Test took 3949ms.
[15:29:31.409] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:32.128] INFO: Expecting 41600 events.
[15:29:35.381] INFO: 41600 events read in total (2726ms).
[15:29:35.382] INFO: Test took 3955ms.
[15:29:35.419] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:36.139] INFO: Expecting 41600 events.
[15:29:39.387] INFO: 41600 events read in total (2721ms).
[15:29:39.388] INFO: Test took 3949ms.
[15:29:39.424] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:40.143] INFO: Expecting 41600 events.
[15:29:43.412] INFO: 41600 events read in total (2742ms).
[15:29:43.413] INFO: Test took 3969ms.
[15:29:43.451] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:44.168] INFO: Expecting 41600 events.
[15:29:47.248] INFO: 41600 events read in total (2553ms).
[15:29:47.249] INFO: Test took 3780ms.
[15:29:47.286] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:48.007] INFO: Expecting 41600 events.
[15:29:51.157] INFO: 41600 events read in total (2623ms).
[15:29:51.158] INFO: Test took 3853ms.
[15:29:51.196] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:51.914] INFO: Expecting 41600 events.
[15:29:55.158] INFO: 41600 events read in total (2717ms).
[15:29:55.159] INFO: Test took 3945ms.
[15:29:55.196] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:55.916] INFO: Expecting 41600 events.
[15:29:59.041] INFO: 41600 events read in total (2598ms).
[15:29:59.042] INFO: Test took 3828ms.
[15:29:59.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:59.796] INFO: Expecting 41600 events.
[15:30:03.053] INFO: 41600 events read in total (2730ms).
[15:30:03.054] INFO: Test took 3958ms.
[15:30:03.091] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:03.801] INFO: Expecting 41600 events.
[15:30:07.046] INFO: 41600 events read in total (2718ms).
[15:30:07.047] INFO: Test took 3938ms.
[15:30:07.083] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:07.803] INFO: Expecting 41600 events.
[15:30:11.038] INFO: 41600 events read in total (2708ms).
[15:30:11.039] INFO: Test took 3937ms.
[15:30:11.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:11.793] INFO: Expecting 41600 events.
[15:30:14.853] INFO: 41600 events read in total (2533ms).
[15:30:14.854] INFO: Test took 3760ms.
[15:30:14.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:15.251] INFO: enter test to run
[15:31:29.088] INFO: test: HighRate no parameter change
[15:31:29.088] INFO: running: highrate
[15:31:29.089] INFO: ----------------------------------------------------------------------
[15:31:29.089] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:31:29.089] INFO: ----------------------------------------------------------------------
[15:31:29.729] INFO: Expecting 208000 events.
[15:31:41.810] INFO: 208000 events read in total (11554ms).
[15:31:41.813] INFO: Test took 12694ms.
[15:31:41.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:42.223] INFO: number of dead pixels (per ROC): 0 1 0 0 0 3 0 0 0 0 0 0 0 0 0 0
[15:31:42.239] INFO: number of red-efficiency pixels: 67 61 113 123 178 158 176 93 109 126 144 122 132 71 18 26
[15:31:42.239] INFO: number of X-ray hits detected: 66886 45262 70974 111351 113715 117382 118667 86505 89172 113768 115820 96066 97283 58738 25098 28146
[15:31:42.239] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:31:42.239] INFO: number of Vcal hits detected: 207930 207890 207885 207874 207814 207692 207822 207905 207889 207869 207855 207873 207866 207928 207982 207974
[15:31:42.239] 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 99.9 99.9 100.0 100.0 100.0
[15:31:42.239] INFO: Vcal hit overall efficiency (%): 100.0 99.9 99.9 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
[15:31:42.239] INFO: X-ray hit rate [MHz/cm2]: 19.6 13.3 20.8 32.6 33.3 34.4 34.8 25.4 26.1 33.3 33.9 28.2 28.5 17.2 7.4 8.2
[15:31:42.239] INFO: PixTestHighRate::doXPixelAlive() done
[15:31:42.288] INFO: PixTest:: pg_setup set to default.
[15:31:42.303] INFO: enter test to run
[15:32:32.823] INFO: test: HighRate no parameter change
[15:32:32.823] INFO: running: highrate
[15:32:32.824] INFO: ----------------------------------------------------------------------
[15:32:32.824] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:32:32.824] INFO: ----------------------------------------------------------------------
[15:32:33.439] INFO: Expecting 208000 events.
[15:32:47.347] INFO: 208000 events read in total (13381ms).
[15:32:47.352] INFO: Test took 14519ms.
[15:32:47.665] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:47.971] INFO: number of dead pixels (per ROC): 0 1 0 0 0 3 0 0 0 0 0 0 0 0 0 0
[15:32:47.971] INFO: number of red-efficiency pixels: 207 149 335 372 562 603 607 281 341 403 463 324 379 234 73 49
[15:32:47.971] INFO: number of X-ray hits detected: 135083 92711 144196 225516 231215 240526 240376 176926 182209 232842 235695 196571 198290 117757 50658 58118
[15:32:47.971] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:32:47.971] INFO: number of Vcal hits detected: 207781 207794 207634 207592 207382 207192 207318 207702 207630 207567 207510 207657 207588 207751 207926 207949
[15:32:47.972] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.7 99.9 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[15:32:47.972] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.6 99.7 99.9 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:32:47.972] INFO: X-ray hit rate [MHz/cm2]: 39.6 27.2 42.3 66.1 67.8 70.5 70.5 51.9 53.4 68.2 69.1 57.6 58.1 34.5 14.8 17.0
[15:32:47.972] INFO: PixTestHighRate::doXPixelAlive() done
[15:32:48.026] INFO: PixTest:: pg_setup set to default.
[15:32:48.041] INFO: enter test to run
[15:33:03.567] INFO: test: HighRate no parameter change
[15:33:03.567] INFO: running: highrate
[15:33:03.568] INFO: ----------------------------------------------------------------------
[15:33:03.568] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:33:03.568] INFO: ----------------------------------------------------------------------
[15:33:04.187] INFO: Expecting 208000 events.
[15:33:20.555] INFO: 208000 events read in total (15842ms).
[15:33:20.563] INFO: Test took 16986ms.
[15:33:21.059] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:21.425] INFO: number of dead pixels (per ROC): 0 1 0 0 0 3 0 0 0 0 0 0 0 0 0 0
[15:33:21.425] INFO: number of red-efficiency pixels: 465 307 777 960 1286 1352 1505 651 786 1041 1027 744 952 579 116 110
[15:33:21.425] INFO: number of X-ray hits detected: 206395 141150 220376 345245 351951 367281 367535 269096 280271 354105 360194 299302 302919 181360 78184 88375
[15:33:21.425] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:33:21.425] INFO: number of Vcal hits detected: 207466 207606 206901 206826 206274 205999 205969 207207 207056 206738 206732 207112 206802 207289 207883 207887
[15:33:21.425] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.5 99.5 99.3 99.2 99.1 99.7 99.6 99.4 99.4 99.6 99.5 99.7 99.9 99.9
[15:33:21.425] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.4 99.2 99.0 99.0 99.6 99.5 99.4 99.4 99.6 99.4 99.7 99.9 99.9
[15:33:21.425] INFO: X-ray hit rate [MHz/cm2]: 60.5 41.4 64.6 101.2 103.2 107.7 107.7 78.9 82.1 103.8 105.6 87.7 88.8 53.2 22.9 25.9
[15:33:21.425] INFO: PixTestHighRate::doXPixelAlive() done
[15:33:21.472] INFO: PixTest:: pg_setup set to default.
[15:33:21.487] INFO: enter test to run
[15:33:24.815] INFO: test: exit no parameter change
[15:33:25.837] QUIET: Connection to board 33 closed.
[15:33:26.166] INFO: pXar: this is the end, my friend