[12:51:43.009] INFO: *** Welcome to pxar ***
[12:51:43.009] INFO: *** Today: 2016/06/09
[12:51:43.037] INFO: *** Version: v1.9.0-814-g7497
[12:51:43.037] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//dacParameters35_C15.dat
[12:51:43.070] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:51:43.070] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//defaultMaskFile.dat
[12:51:43.080] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C15.dat
[12:51:43.152] INFO: clk: 4
[12:51:43.152] INFO: ctr: 4
[12:51:43.152] INFO: sda: 19
[12:51:43.152] INFO: tin: 9
[12:51:43.152] INFO: level: 15
[12:51:43.152] INFO: triggerdelay: 0
[12:51:43.152] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:51:43.152] INFO: Log level: INFO
[12:51:43.171] QUIET: Connection to board DTB_WREKRL opened.
[12:51:43.175] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[12:51:43.177] INFO: RPC call hashes of host and DTB match: 398089610
[12:51:44.709] INFO: DUT info:
[12:51:44.709] INFO: The DUT currently contains the following objects:
[12:51:44.709] INFO: 2 TBM Cores tbm08c (2 ON)
[12:51:44.709] INFO: TBM Core alpha (0): 7 registers set
[12:51:44.709] INFO: TBM Core beta (1): 7 registers set
[12:51:44.709] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:51:44.709] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.709] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.709] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.709] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.709] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.709] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.709] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.709] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.709] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.710] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.710] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.710] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.710] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.710] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.710] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:44.710] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:45.113] INFO: enter 'restricted' command line mode
[12:51:45.113] INFO: enter test to run
[12:52:00.742] INFO: test: PixelAlive no parameter change
[12:52:00.743] INFO: running: pixelalive
[12:52:00.752] INFO: ----------------------------------------------------------------------
[12:52:00.752] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:52:00.752] INFO: ----------------------------------------------------------------------
[12:52:01.067] INFO: Expecting 41600 events.
[12:52:05.412] INFO: 41600 events read in total (3627ms).
[12:52:05.581] INFO: Test took 4827ms.
[12:52:05.590] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:05.854] INFO: PixTestAlive::aliveTest() done
[12:52:05.854] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:52:05.885] INFO: enter test to run
[12:52:46.742] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:52:46.742] INFO: running: highrate
[12:52:46.743] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:52:46.963] INFO: ----------------------------------------------------------------------
[12:52:46.963] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:52:46.963] INFO: ----------------------------------------------------------------------
[12:52:46.963] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:52:46.964] INFO: edge/corner pixel THR is adjusted
[12:52:46.964] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:52:47.923] INFO: Collecting data for 5 seconds...
[12:52:52.941] INFO: Done with hot pixel readout
[12:53:04.329] INFO: PixTest:: pg_setup set to default.
[12:53:04.329] INFO: 0 hot pixels found in step 0
[12:53:04.342] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:53:04.360] INFO: PixTest::trimHotPixels() done
[12:53:04.399] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C0.dat
[12:53:04.404] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C1.dat
[12:53:04.409] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C2.dat
[12:53:04.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C3.dat
[12:53:04.421] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C4.dat
[12:53:04.426] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C5.dat
[12:53:04.431] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C6.dat
[12:53:04.436] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C7.dat
[12:53:04.441] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C8.dat
[12:53:04.447] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C9.dat
[12:53:04.453] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C10.dat
[12:53:04.458] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C11.dat
[12:53:04.463] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C12.dat
[12:53:04.468] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C13.dat
[12:53:04.474] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C14.dat
[12:53:04.479] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C15.dat
[12:53:04.485] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//defaultMaskFile.dat
[12:53:04.494] INFO: enter test to run
[12:53:31.046] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:53:31.046] INFO: running: highrate
[12:53:31.050] INFO: ----------------------------------------------------------------------
[12:53:31.050] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:53:31.050] INFO: ----------------------------------------------------------------------
[12:53:31.050] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:53:31.050] INFO: edge/corner pixel THR is adjusted
[12:53:31.050] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:53:32.008] INFO: Collecting data for 1 seconds...
[12:53:33.012] INFO: Done with hot pixel readout
[12:53:36.866] INFO: PixTest:: pg_setup set to default.
[12:53:36.867] INFO: 0 hot pixels found in step 0
[12:53:36.874] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:53:36.974] INFO: PixTest::trimHotPixels() done
[12:53:36.974] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C0.dat
[12:53:36.982] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C1.dat
[12:53:36.987] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C2.dat
[12:53:36.993] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C3.dat
[12:53:36.998] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C4.dat
[12:53:37.003] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C5.dat
[12:53:37.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C6.dat
[12:53:37.014] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C7.dat
[12:53:37.019] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C8.dat
[12:53:37.025] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C9.dat
[12:53:37.030] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C10.dat
[12:53:37.035] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C11.dat
[12:53:37.041] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C12.dat
[12:53:37.046] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C13.dat
[12:53:37.051] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C14.dat
[12:53:37.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C15.dat
[12:53:37.062] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//defaultMaskFile.dat
[12:53:37.071] INFO: enter test to run
[12:54:13.670] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:54:13.670] INFO: running: xray
[12:54:13.671] INFO: ----------------------------------------------------------------------
[12:54:13.671] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:54:13.671] INFO: ----------------------------------------------------------------------
[12:54:14.634] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:54:26.534] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:54:55.738] INFO: Resuming triggers.
[12:55:07.637] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:55:37.451] INFO: Resuming triggers.
[12:55:49.351] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:56:18.992] INFO: Resuming triggers.
[12:56:30.893] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:57:00.281] INFO: Resuming triggers.
[12:57:12.180] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.


















[12:57:41.881] INFO: Resuming triggers.
[12:57:53.780] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[12:58:23.227] INFO: Resuming triggers.
[12:58:35.122] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:59:04.318] INFO: Resuming triggers.
[12:59:16.212] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:59:45.484] INFO: Resuming triggers.
[12:59:50.656] INFO: data taking finished, elapsed time: 100 seconds.
[13:00:03.545] INFO: PixTest:: pg_setup set to default.
[13:00:03.549] INFO: PixTestXray::doPhRun() done
[13:00:03.682] INFO: enter test to run
[13:00:20.139] INFO: test: timing no parameter change
[13:00:20.139] INFO: running: timing
[13:00:20.156] INFO: ######################################################################
[13:00:20.164] INFO: PixTestTiming::doTest()
[13:00:20.164] INFO: ######################################################################
[13:00:20.164] INFO: ----------------------------------------------------------------------
[13:00:20.164] INFO: PixTestTiming::TBMPhaseScan()
[13:00:20.164] INFO: ----------------------------------------------------------------------
[13:06:31.290] INFO: TBM Phase Settings: 236
[13:06:31.290] INFO: 400MHz Phase: 3
[13:06:31.290] INFO: 160MHz Phase: 7
[13:06:31.290] INFO: Functional Phase Area: 5
[13:06:31.324] INFO: Test took 371160 ms.
[13:06:31.324] INFO: PixTestTiming::TBMPhaseScan() done.
[13:06:31.325] INFO: ----------------------------------------------------------------------
[13:06:31.325] INFO: PixTestTiming::ROCDelayScan()
[13:06:31.325] INFO: ----------------------------------------------------------------------
[13:08:32.116] INFO: ROC Delay Settings: 227
[13:08:32.116] INFO: ROC Header-Trailer/Token Delay: 11
[13:08:32.116] INFO: ROC Port 0 Delay: 3
[13:08:32.116] INFO: ROC Port 1 Delay: 4
[13:08:32.116] INFO: Functional ROC Area: 4
[13:08:32.119] INFO: Test took 120795 ms.
[13:08:32.119] INFO: PixTestTiming::ROCDelayScan() done.
[13:08:32.119] INFO: ----------------------------------------------------------------------
[13:08:32.119] INFO: PixTestTiming::TimingTest()
[13:08:32.119] INFO: ----------------------------------------------------------------------
[13:08:48.603] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:03.902] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:19.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:34.367] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:49.610] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:04.804] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:20.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:35.175] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:50.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:05.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:05.473] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:05.486] INFO: ----------------------------------------------------------------------
[13:11:05.486] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[13:11:05.486] INFO: ----------------------------------------------------------------------
[13:11:05.486] INFO: ----------------------------------------------------------------------
[13:11:05.486] INFO: Read back bit status: 1
[13:11:05.486] INFO: ----------------------------------------------------------------------
[13:11:05.486] INFO: ----------------------------------------------------------------------
[13:11:05.486] INFO: Timings are good!
[13:11:05.486] INFO: ----------------------------------------------------------------------
[13:11:05.486] INFO: Test took 153367 ms.
[13:11:05.486] INFO: PixTestTiming::TimingTest() done.
[13:11:05.495] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//tbmParameters_C0a.dat
[13:11:05.495] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-22_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:11:05.496] INFO: PixTestTiming::doTest took 645343 ms.
[13:11:05.496] INFO: PixTestTiming::doTest() done
[13:11:05.496] INFO: Write out TBMPhaseScan_0_V0
[13:11:05.496] INFO: Write out TBMPhaseScan_1_V0
[13:11:05.496] INFO: Write out CombinedTBMPhaseScan_V0
[13:11:05.532] INFO: Write out ROCDelayScan3_V0
[13:11:05.532] INFO: enter test to run
[13:12:13.278] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:12:13.278] INFO: running: xray
[13:12:13.279] INFO: ----------------------------------------------------------------------
[13:12:13.279] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:12:13.279] INFO: ----------------------------------------------------------------------
[13:12:14.244] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:12:26.147] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:12:55.418] INFO: Resuming triggers.
[13:13:07.325] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:13:36.392] INFO: Resuming triggers.
[13:13:48.298] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:14:17.654] INFO: Resuming triggers.
[13:14:29.560] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:14:58.826] INFO: Resuming triggers.
[13:15:10.733] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[13:15:39.830] INFO: Resuming triggers.
[13:15:51.738] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:16:21.105] INFO: Resuming triggers.
[13:16:33.012] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[13:17:02.302] INFO: Resuming triggers.
[13:17:14.211] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[13:17:43.392] INFO: Resuming triggers.
[13:17:48.467] INFO: data taking finished, elapsed time: 100 seconds.
[13:18:01.207] INFO: PixTest:: pg_setup set to default.
[13:18:01.210] INFO: PixTestXray::doPhRun() done
[13:18:01.343] INFO: enter test to run
[13:18:40.851] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:18:40.851] INFO: running: xray
[13:18:40.852] INFO: ----------------------------------------------------------------------
[13:18:40.852] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:18:40.852] INFO: ----------------------------------------------------------------------
[13:18:41.817] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:18:48.940] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[13:19:19.786] INFO: Resuming triggers.
[13:19:26.905] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[13:19:57.538] INFO: Resuming triggers.
[13:20:04.655] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[13:20:35.831] INFO: Resuming triggers.
[13:20:42.948] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[13:21:14.078] INFO: Resuming triggers.
[13:21:21.193] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:21:50.375] INFO: Resuming triggers.
[13:21:57.494] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[13:22:27.591] INFO: Resuming triggers.
[13:22:34.704] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[13:23:04.784] INFO: Resuming triggers.
[13:23:11.896] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:23:41.948] INFO: Resuming triggers.
[13:23:49.065] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[13:24:19.095] INFO: Resuming triggers.
[13:24:26.207] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:24:56.272] INFO: Resuming triggers.
[13:25:03.385] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[13:25:33.229] INFO: Resuming triggers.
[13:25:40.346] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[13:26:10.451] INFO: Resuming triggers.
[13:26:17.567] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:26:47.575] INFO: Resuming triggers.
[13:26:54.692] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[13:27:24.731] INFO: Resuming triggers.
[13:27:25.447] INFO: data taking finished, elapsed time: 100 seconds.
[13:27:28.844] INFO: PixTest:: pg_setup set to default.
[13:27:28.847] INFO: PixTestXray::doPhRun() done
[13:27:28.995] INFO: enter test to run
[13:28:36.911] INFO: test: HighRate no parameter change
[13:28:36.911] INFO: running: highrate
[13:28:36.912] INFO: ----------------------------------------------------------------------
[13:28:36.912] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:28:36.912] INFO: ----------------------------------------------------------------------
[13:28:37.053] INFO: Expecting 768 events.
[13:28:38.187] INFO: 768 events read in total (418ms).
[13:28:38.187] INFO: Test took 1268ms.
[13:28:38.991] INFO: Expecting 41600 events.
[13:28:42.060] INFO: 41600 events read in total (2542ms).
[13:28:42.061] INFO: Test took 3866ms.
[13:28:42.091] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:42.823] INFO: Expecting 41600 events.
[13:28:46.002] INFO: 41600 events read in total (2652ms).
[13:28:46.003] INFO: Test took 3894ms.
[13:28:46.033] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:46.766] INFO: Expecting 41600 events.
[13:28:49.948] INFO: 41600 events read in total (2655ms).
[13:28:49.949] INFO: Test took 3897ms.
[13:28:49.979] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:50.711] INFO: Expecting 41600 events.
[13:28:53.921] INFO: 41600 events read in total (2683ms).
[13:28:53.922] INFO: Test took 3925ms.
[13:28:53.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:54.682] INFO: Expecting 41600 events.
[13:28:57.891] INFO: 41600 events read in total (2682ms).
[13:28:57.891] INFO: Test took 3923ms.
[13:28:57.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:58.650] INFO: Expecting 41600 events.
[13:29:01.842] INFO: 41600 events read in total (2665ms).
[13:29:01.843] INFO: Test took 3904ms.
[13:29:01.873] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:02.606] INFO: Expecting 41600 events.
[13:29:05.810] INFO: 41600 events read in total (2677ms).
[13:29:05.811] INFO: Test took 3921ms.
[13:29:05.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:06.568] INFO: Expecting 41600 events.
[13:29:09.781] INFO: 41600 events read in total (2686ms).
[13:29:09.782] INFO: Test took 3924ms.
[13:29:09.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:10.540] INFO: Expecting 41600 events.
[13:29:13.745] INFO: 41600 events read in total (2678ms).
[13:29:13.746] INFO: Test took 3916ms.
[13:29:13.777] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:14.508] INFO: Expecting 41600 events.
[13:29:17.704] INFO: 41600 events read in total (2669ms).
[13:29:17.705] INFO: Test took 3910ms.
[13:29:17.735] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:18.466] INFO: Expecting 41600 events.
[13:29:21.676] INFO: 41600 events read in total (2683ms).
[13:29:21.677] INFO: Test took 3925ms.
[13:29:21.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:22.437] INFO: Expecting 41600 events.
[13:29:25.638] INFO: 41600 events read in total (2674ms).
[13:29:25.639] INFO: Test took 3914ms.
[13:29:25.669] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:26.402] INFO: Expecting 41600 events.
[13:29:29.595] INFO: 41600 events read in total (2666ms).
[13:29:29.595] INFO: Test took 3910ms.
[13:29:29.627] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:30.355] INFO: Expecting 41600 events.
[13:29:33.560] INFO: 41600 events read in total (2678ms).
[13:29:33.561] INFO: Test took 3916ms.
[13:29:33.591] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:34.324] INFO: Expecting 41600 events.
[13:29:37.530] INFO: 41600 events read in total (2680ms).
[13:29:37.531] INFO: Test took 3922ms.
[13:29:37.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:38.294] INFO: Expecting 41600 events.
[13:29:41.477] INFO: 41600 events read in total (2656ms).
[13:29:41.478] INFO: Test took 3899ms.
[13:29:41.508] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:42.240] INFO: Expecting 41600 events.
[13:29:45.449] INFO: 41600 events read in total (2682ms).
[13:29:45.449] INFO: Test took 3923ms.
[13:29:45.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:46.211] INFO: Expecting 41600 events.
[13:29:49.412] INFO: 41600 events read in total (2674ms).
[13:29:49.412] INFO: Test took 3915ms.
[13:29:49.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:50.175] INFO: Expecting 41600 events.
[13:29:53.378] INFO: 41600 events read in total (2676ms).
[13:29:53.379] INFO: Test took 3918ms.
[13:29:53.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:54.138] INFO: Expecting 41600 events.
[13:29:57.179] INFO: 41600 events read in total (2514ms).
[13:29:57.180] INFO: Test took 3752ms.
[13:29:57.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:57.581] INFO: enter test to run
[13:30:02.430] INFO: test: HighRate no parameter change
[13:30:02.430] INFO: running: highrate
[13:30:02.431] INFO: ----------------------------------------------------------------------
[13:30:02.431] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:30:02.431] INFO: ----------------------------------------------------------------------
[13:30:03.046] INFO: Expecting 208000 events.
[13:30:14.744] INFO: 208000 events read in total (11171ms).
[13:30:14.746] INFO: Test took 12309ms.
[13:30:14.875] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:15.125] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:30:15.125] INFO: number of red-efficiency pixels: 50 42 86 107 112 137 118 89 75 103 92 80 73 45 10 20
[13:30:15.125] INFO: number of X-ray hits detected: 57863 38189 61002 93440 98393 101644 102972 74455 64729 85125 81973 70365 69763 43187 19917 23259
[13:30:15.125] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:30:15.125] INFO: number of Vcal hits detected: 207950 207958 207913 207893 207886 207857 207880 207909 207924 207896 207907 207918 207927 207955 207990 207980
[13:30:15.125] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[13:30:15.125] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[13:30:15.125] INFO: X-ray hit rate [MHz/cm2]: 17.0 11.2 17.9 27.4 28.8 29.8 30.2 21.8 19.0 25.0 24.0 20.6 20.4 12.7 5.8 6.8
[13:30:15.125] INFO: PixTestHighRate::doXPixelAlive() done
[13:30:15.171] INFO: PixTest:: pg_setup set to default.
[13:30:15.188] INFO: enter test to run
[13:30:37.517] INFO: test: HighRate no parameter change
[13:30:37.517] INFO: running: highrate
[13:30:37.518] INFO: ----------------------------------------------------------------------
[13:30:37.518] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:30:37.518] INFO: ----------------------------------------------------------------------
[13:30:38.137] INFO: Expecting 208000 events.
[13:30:51.498] INFO: 208000 events read in total (12834ms).
[13:30:51.503] INFO: Test took 13975ms.
[13:30:51.768] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:52.064] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:30:52.064] INFO: number of red-efficiency pixels: 172 97 260 292 376 439 354 227 201 275 288 233 200 98 46 59
[13:30:52.064] INFO: number of X-ray hits detected: 123202 81370 130149 199830 210530 217085 219286 159144 138917 182428 175815 149894 148149 92043 42838 49348
[13:30:52.064] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:30:52.065] INFO: number of Vcal hits detected: 207822 207898 207719 207694 207596 207516 207615 207755 207793 207714 207697 207754 207796 207899 207954 207941
[13:30:52.065] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:30:52.065] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:30:52.065] INFO: X-ray hit rate [MHz/cm2]: 36.1 23.9 38.1 58.6 61.7 63.6 64.3 46.6 40.7 53.5 51.5 43.9 43.4 27.0 12.6 14.5
[13:30:52.065] INFO: PixTestHighRate::doXPixelAlive() done
[13:30:52.111] INFO: PixTest:: pg_setup set to default.
[13:30:52.127] INFO: enter test to run
[13:31:15.117] INFO: test: HighRate no parameter change
[13:31:15.117] INFO: running: highrate
[13:31:15.118] INFO: ----------------------------------------------------------------------
[13:31:15.119] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:31:15.119] INFO: ----------------------------------------------------------------------
[13:31:15.739] INFO: Expecting 208000 events.
[13:31:30.609] INFO: 208000 events read in total (14343ms).
[13:31:30.616] INFO: Test took 15486ms.
[13:31:31.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:31.374] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:31:31.374] INFO: number of red-efficiency pixels: 323 213 622 661 846 1102 851 529 451 598 707 552 413 258 81 99
[13:31:31.374] INFO: number of X-ray hits detected: 188143 124927 197585 302842 319544 329405 334299 242915 211334 277882 266774 229853 227232 140101 65347 75765
[13:31:31.374] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:31:31.374] INFO: number of Vcal hits detected: 207647 207777 207211 207243 207018 206625 206971 207396 207507 207325 207174 207382 207545 207718 207917 207900
[13:31:31.374] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.7 99.6 99.4 99.6 99.7 99.8 99.7 99.6 99.7 99.8 99.9 100.0 100.0
[13:31:31.374] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.6 99.5 99.3 99.5 99.7 99.8 99.7 99.6 99.7 99.8 99.9 100.0 100.0
[13:31:31.374] INFO: X-ray hit rate [MHz/cm2]: 55.1 36.6 57.9 88.8 93.7 96.6 98.0 71.2 61.9 81.4 78.2 67.4 66.6 41.1 19.2 22.2
[13:31:31.374] INFO: PixTestHighRate::doXPixelAlive() done
[13:31:31.422] INFO: PixTest:: pg_setup set to default.
[13:31:31.440] INFO: enter test to run
[13:31:35.709] INFO: test: exit no parameter change
[13:31:36.068] QUIET: Connection to board 33 closed.
[13:31:36.069] INFO: pXar: this is the end, my friend