[13:53:40.672] INFO: *** Welcome to pxar ***
[13:53:40.672] INFO: *** Today: 2016/09/13
[13:53:41.501] INFO: *** Version: v1.9.0-818-g96727
[13:53:41.501] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//dacParameters35_C15.dat
[13:53:41.527] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:53:41.527] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[13:53:41.530] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[13:53:41.645] INFO: clk: 4
[13:53:41.645] INFO: ctr: 4
[13:53:41.645] INFO: sda: 19
[13:53:41.645] INFO: tin: 9
[13:53:41.645] INFO: level: 15
[13:53:41.645] INFO: triggerdelay: 0
[13:53:41.649] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:53:41.649] INFO: Log level: INFO
[13:53:41.667] QUIET: Connection to board DTB_WREKRL opened.
[13:53:41.670] 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:
------------------------------------------------------
[13:53:41.673] INFO: RPC call hashes of host and DTB match: 398089610
[13:53:43.219] INFO: DUT info:
[13:53:43.219] INFO: The DUT currently contains the following objects:
[13:53:43.219] INFO: 2 TBM Cores tbm08c (2 ON)
[13:53:43.237] INFO: TBM Core alpha (0): 7 registers set
[13:53:43.237] INFO: TBM Core beta (1): 7 registers set
[13:53:43.237] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:53:43.237] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.237] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:53:43.673] INFO: enter 'restricted' command line mode
[13:53:43.673] INFO: enter test to run
[13:53:51.731] INFO: test: PixelAlive no parameter change
[13:53:51.731] INFO: running: pixelalive
[13:53:51.761] INFO: ----------------------------------------------------------------------
[13:53:51.761] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:53:51.761] INFO: ----------------------------------------------------------------------
[13:53:52.085] INFO: Expecting 41600 events.
[13:53:56.400] INFO: 41600 events read in total (3597ms).
[13:53:56.565] INFO: Test took 4800ms.
[13:53:56.574] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:56.891] INFO: PixTestAlive::aliveTest() done
[13:53:56.891] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:53:56.984] INFO: enter test to run
[13:54:12.740] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:54:12.740] INFO: running: highrate
[13:54:12.755] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:54:13.008] INFO: ----------------------------------------------------------------------
[13:54:13.009] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:54:13.009] INFO: ----------------------------------------------------------------------
[13:54:13.009] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:54:13.009] INFO: edge/corner pixel THR is adjusted
[13:54:13.009] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:54:13.993] INFO: Collecting data for 5 seconds...
[13:54:19.010] INFO: Done with hot pixel readout
[13:54:30.627] INFO: PixTest:: pg_setup set to default.
[13:54:30.628] INFO: 15 hot pixels found in step 0
[13:54:31.646] INFO: Collecting data for 5 seconds...
[13:54:36.663] INFO: Done with hot pixel readout
[13:54:48.141] INFO: PixTest:: pg_setup set to default.
[13:54:48.142] INFO: 20 hot pixels found in step 1
[13:54:49.133] INFO: Collecting data for 5 seconds...
[13:54:54.149] INFO: Done with hot pixel readout
[13:55:05.550] INFO: PixTest:: pg_setup set to default.
[13:55:05.551] INFO: 18 hot pixels found in step 2
[13:55:06.543] INFO: Collecting data for 5 seconds...
[13:55:11.559] INFO: Done with hot pixel readout
[13:55:22.890] INFO: PixTest:: pg_setup set to default.
[13:55:22.891] INFO: 14 hot pixels found in step 3
[13:55:23.881] INFO: Collecting data for 5 seconds...
[13:55:28.898] INFO: Done with hot pixel readout
[13:55:40.100] INFO: PixTest:: pg_setup set to default.
[13:55:40.100] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:55:40.100] INFO: 17 hot pixels found in step 4
[13:55:41.091] INFO: Collecting data for 5 seconds...
[13:55:46.107] INFO: Done with hot pixel readout
[13:55:57.385] INFO: PixTest:: pg_setup set to default.
[13:55:57.385] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:55:57.385] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:55:57.386] INFO: 17 hot pixels found in step 5
[13:55:58.376] INFO: Collecting data for 5 seconds...
[13:56:03.393] INFO: Done with hot pixel readout
[13:56:14.690] INFO: PixTest:: pg_setup set to default.
[13:56:14.690] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:56:14.690] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:56:14.691] INFO: 15 hot pixels found in step 6
[13:56:15.681] INFO: Collecting data for 5 seconds...
[13:56:20.698] INFO: Done with hot pixel readout
[13:56:32.030] INFO: PixTest:: pg_setup set to default.
[13:56:32.030] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:56:32.030] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:56:32.030] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:56:32.031] INFO: 16 hot pixels found in step 7
[13:56:33.022] INFO: Collecting data for 5 seconds...
[13:56:38.039] INFO: Done with hot pixel readout
[13:56:49.452] INFO: PixTest:: pg_setup set to default.
[13:56:49.453] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:56:49.453] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:56:49.453] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:56:49.453] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:56:49.454] INFO: 12 hot pixels found in step 8
[13:56:50.446] INFO: Collecting data for 5 seconds...
[13:56:55.462] INFO: Done with hot pixel readout
[13:57:06.772] INFO: PixTest:: pg_setup set to default.
[13:57:06.772] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:06.772] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:06.773] INFO: 10 hot pixels found in step 9
[13:57:07.763] INFO: Collecting data for 5 seconds...
[13:57:12.779] INFO: Done with hot pixel readout
[13:57:24.062] INFO: PixTest:: pg_setup set to default.
[13:57:24.062] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:24.062] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:24.063] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:24.063] INFO: 12 hot pixels found in step 10
[13:57:25.054] INFO: Collecting data for 5 seconds...
[13:57:30.071] INFO: Done with hot pixel readout
[13:57:41.339] INFO: PixTest:: pg_setup set to default.
[13:57:41.339] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:41.339] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:41.339] INFO: 7 hot pixels found in step 11
[13:57:42.330] INFO: Collecting data for 5 seconds...
[13:57:47.346] INFO: Done with hot pixel readout
[13:57:58.430] INFO: PixTest:: pg_setup set to default.
[13:57:58.430] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:58.430] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:58.431] INFO: 8 hot pixels found in step 12
[13:57:59.421] INFO: Collecting data for 5 seconds...
[13:58:04.437] INFO: Done with hot pixel readout
[13:58:15.157] INFO: PixTest:: pg_setup set to default.
[13:58:15.157] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:58:15.157] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:58:15.158] INFO: 7 hot pixels found in step 13
[13:58:16.151] INFO: Collecting data for 5 seconds...
[13:58:21.166] INFO: Done with hot pixel readout
[13:58:32.201] INFO: PixTest:: pg_setup set to default.
[13:58:32.202] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:58:32.202] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:58:32.202] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:58:32.202] INFO: 4 hot pixels found in step 14
[13:58:32.237] INFO: 4 hot pixels could not be trimmed and have been masked.
[13:58:32.241] INFO: PixTest::trimHotPixels() done
[13:58:32.318] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat
[13:58:32.324] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C1.dat
[13:58:32.329] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C2.dat
[13:58:32.335] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C3.dat
[13:58:32.340] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C4.dat
[13:58:32.346] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C5.dat
[13:58:32.351] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C6.dat
[13:58:32.357] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C7.dat
[13:58:32.362] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C8.dat
[13:58:32.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C9.dat
[13:58:32.373] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C10.dat
[13:58:32.378] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C11.dat
[13:58:32.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C12.dat
[13:58:32.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C13.dat
[13:58:32.395] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C14.dat
[13:58:32.400] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[13:58:32.468] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[13:58:32.480] INFO: enter test to run
[13:59:55.792] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:59:55.792] INFO: running: highrate
[13:59:55.796] INFO: ----------------------------------------------------------------------
[13:59:55.796] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:59:55.796] INFO: ----------------------------------------------------------------------
[13:59:55.796] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:59:55.796] INFO: edge/corner pixel THR is adjusted
[13:59:55.796] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:59:56.758] INFO: Collecting data for 1 seconds...
[13:59:57.762] INFO: Done with hot pixel readout
[14:00:01.518] INFO: PixTest:: pg_setup set to default.
[14:00:01.519] INFO: 0 hot pixels found in step 0
[14:00:01.524] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:00:01.612] INFO: PixTest::trimHotPixels() done
[14:00:01.612] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat
[14:00:01.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C1.dat
[14:00:01.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C2.dat
[14:00:01.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C3.dat
[14:00:01.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C4.dat
[14:00:01.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C5.dat
[14:00:01.650] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C6.dat
[14:00:01.655] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C7.dat
[14:00:01.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C8.dat
[14:00:01.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C9.dat
[14:00:01.671] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C10.dat
[14:00:01.676] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C11.dat
[14:00:01.681] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C12.dat
[14:00:01.686] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C13.dat
[14:00:01.692] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C14.dat
[14:00:01.697] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[14:00:01.702] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-34_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[14:00:01.741] INFO: enter test to run
[14:00:33.528] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:00:33.528] INFO: running: xray
[14:00:33.550] INFO: ----------------------------------------------------------------------
[14:00:33.550] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:00:33.550] INFO: ----------------------------------------------------------------------
[14:00:34.513] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:00:45.002] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:01:13.993] INFO: Resuming triggers.
[14:01:25.480] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:01:52.504] INFO: Resuming triggers.
[14:02:03.992] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:02:31.829] INFO: Resuming triggers.
[14:02:43.315] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:03:11.086] INFO: Resuming triggers.
[14:03:22.574] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:03:49.751] INFO: Resuming triggers.
[14:04:01.239] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:04:28.455] INFO: Resuming triggers.
[14:04:39.945] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:05:07.142] INFO: Resuming triggers.
[14:05:18.634] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:05:46.009] INFO: Resuming triggers.
[14:05:54.426] INFO: data taking finished, elapsed time: 100 seconds.
[14:06:14.790] INFO: PixTest:: pg_setup set to default.
[14:06:14.793] INFO: PixTestXray::doPhRun() done
[14:06:15.013] INFO: enter test to run
[14:06:45.742] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:06:45.742] INFO: running: xray
[14:06:45.743] INFO: ----------------------------------------------------------------------
[14:06:45.743] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:06:45.743] INFO: ----------------------------------------------------------------------
[14:06:46.708] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:06:53.517] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:07:22.828] INFO: Resuming triggers.
[14:07:29.637] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:07:59.542] INFO: Resuming triggers.
[14:08:06.353] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:08:36.365] INFO: Resuming triggers.
[14:08:43.176] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:09:13.237] INFO: Resuming triggers.
[14:09:20.052] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:09:49.577] INFO: Resuming triggers.
[14:09:56.389] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[14:10:25.749] INFO: Resuming triggers.
[14:10:32.562] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:11:01.984] INFO: Resuming triggers.
[14:11:08.803] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:11:38.318] INFO: Resuming triggers.
[14:11:45.131] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:12:14.678] INFO: Resuming triggers.
[14:12:21.488] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:12:51.073] INFO: Resuming triggers.
[14:12:57.885] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:13:27.603] INFO: Resuming triggers.
[14:13:34.412] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:14:03.977] INFO: Resuming triggers.
[14:14:10.787] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:14:40.553] INFO: Resuming triggers.
[14:14:47.363] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:15:16.965] INFO: Resuming triggers.
[14:15:21.935] INFO: data taking finished, elapsed time: 100 seconds.
[14:15:43.848] INFO: PixTest:: pg_setup set to default.
[14:15:43.852] INFO: PixTestXray::doPhRun() done
[14:15:44.051] INFO: enter test to run
[14:16:31.818] INFO: test: HighRate no parameter change
[14:16:31.818] INFO: running: highrate
[14:16:31.844] INFO: ----------------------------------------------------------------------
[14:16:31.844] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:16:31.844] INFO: ----------------------------------------------------------------------
[14:16:32.016] INFO: Expecting 768 events.
[14:16:33.163] INFO: 768 events read in total (432ms).
[14:16:33.164] INFO: Test took 1283ms.
[14:16:33.966] INFO: Expecting 41600 events.
[14:16:37.008] INFO: 41600 events read in total (2515ms).
[14:16:37.009] INFO: Test took 3767ms.
[14:16:37.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:37.769] INFO: Expecting 41600 events.
[14:16:40.932] INFO: 41600 events read in total (2636ms).
[14:16:40.933] INFO: Test took 3868ms.
[14:16:40.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:41.689] INFO: Expecting 41600 events.
[14:16:44.862] INFO: 41600 events read in total (2647ms).
[14:16:44.863] INFO: Test took 3876ms.
[14:16:44.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:45.612] INFO: Expecting 41600 events.
[14:16:48.771] INFO: 41600 events read in total (2632ms).
[14:16:48.772] INFO: Test took 3857ms.
[14:16:48.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:49.531] INFO: Expecting 41600 events.
[14:16:52.702] INFO: 41600 events read in total (2645ms).
[14:16:52.703] INFO: Test took 3876ms.
[14:16:52.737] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:53.457] INFO: Expecting 41600 events.
[14:16:56.630] INFO: 41600 events read in total (2647ms).
[14:16:56.631] INFO: Test took 3876ms.
[14:16:56.665] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:57.391] INFO: Expecting 41600 events.
[14:17:00.525] INFO: 41600 events read in total (2607ms).
[14:17:00.526] INFO: Test took 3844ms.
[14:17:00.560] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:01.278] INFO: Expecting 41600 events.
[14:17:04.492] INFO: 41600 events read in total (2687ms).
[14:17:04.493] INFO: Test took 3914ms.
[14:17:04.529] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:05.244] INFO: Expecting 41600 events.
[14:17:08.400] INFO: 41600 events read in total (2630ms).
[14:17:08.401] INFO: Test took 3852ms.
[14:17:08.436] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:09.155] INFO: Expecting 41600 events.
[14:17:12.313] INFO: 41600 events read in total (2631ms).
[14:17:12.315] INFO: Test took 3862ms.
[14:17:12.357] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:13.058] INFO: Expecting 41600 events.
[14:17:16.180] INFO: 41600 events read in total (2595ms).
[14:17:16.181] INFO: Test took 3798ms.
[14:17:16.216] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:16.939] INFO: Expecting 41600 events.
[14:17:20.037] INFO: 41600 events read in total (2571ms).
[14:17:20.038] INFO: Test took 3805ms.
[14:17:20.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:20.794] INFO: Expecting 41600 events.
[14:17:23.867] INFO: 41600 events read in total (2546ms).
[14:17:23.868] INFO: Test took 3777ms.
[14:17:23.908] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:24.622] INFO: Expecting 41600 events.
[14:17:27.734] INFO: 41600 events read in total (2585ms).
[14:17:27.735] INFO: Test took 3807ms.
[14:17:27.771] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:28.487] INFO: Expecting 41600 events.
[14:17:31.608] INFO: 41600 events read in total (2594ms).
[14:17:31.609] INFO: Test took 3820ms.
[14:17:31.645] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:32.364] INFO: Expecting 41600 events.
[14:17:35.493] INFO: 41600 events read in total (2602ms).
[14:17:35.494] INFO: Test took 3827ms.
[14:17:35.528] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:36.247] INFO: Expecting 41600 events.
[14:17:39.421] INFO: 41600 events read in total (2647ms).
[14:17:39.422] INFO: Test took 3876ms.
[14:17:39.456] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:40.183] INFO: Expecting 41600 events.
[14:17:43.347] INFO: 41600 events read in total (2637ms).
[14:17:43.348] INFO: Test took 3874ms.
[14:17:43.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:44.109] INFO: Expecting 41600 events.
[14:17:47.242] INFO: 41600 events read in total (2606ms).
[14:17:47.243] INFO: Test took 3841ms.
[14:17:47.278] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:47.995] INFO: Expecting 41600 events.
[14:17:50.001] INFO: 41600 events read in total (2479ms).
[14:17:50.002] INFO: Test took 3706ms.
[14:17:51.036] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:51.397] INFO: enter test to run
[14:18:49.433] INFO: test: HighRate no parameter change
[14:18:49.433] INFO: running: highrate
[14:18:49.434] INFO: ----------------------------------------------------------------------
[14:18:49.434] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:18:49.434] INFO: ----------------------------------------------------------------------
[14:18:50.099] INFO: Expecting 208000 events.
[14:19:01.529] INFO: 208000 events read in total (10903ms).
[14:19:01.532] INFO: Test took 12042ms.
[14:19:01.681] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:01.934] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:19:01.934] INFO: number of red-efficiency pixels: 85 57 81 144 128 163 169 91 71 116 98 103 122 66 26 20
[14:19:01.934] INFO: number of X-ray hits detected: 67156 45154 71400 107463 112974 113086 111438 72074 66882 95378 95309 84480 88273 56681 22931 26436
[14:19:01.934] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:19:01.934] INFO: number of Vcal hits detected: 207914 207942 207918 207856 207869 207833 207824 207906 207928 207881 207899 207896 207877 207934 207972 207980
[14:19:01.934] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0
[14:19:01.934] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0
[14:19:01.934] INFO: X-ray hit rate [MHz/cm2]: 19.7 13.2 20.9 31.5 33.1 33.1 32.7 21.1 19.6 28.0 27.9 24.8 25.9 16.6 6.7 7.7
[14:19:01.934] INFO: PixTestHighRate::doXPixelAlive() done
[14:19:01.983] INFO: PixTest:: pg_setup set to default.
[14:19:01.995] INFO: enter test to run
[14:20:32.281] INFO: test: HighRate no parameter change
[14:20:32.281] INFO: running: highrate
[14:20:32.282] INFO: ----------------------------------------------------------------------
[14:20:32.282] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:20:32.282] INFO: ----------------------------------------------------------------------
[14:20:32.904] INFO: Expecting 208000 events.
[14:20:45.960] INFO: 208000 events read in total (12529ms).
[14:20:45.965] INFO: Test took 13675ms.
[14:20:46.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:46.560] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:20:46.560] INFO: number of red-efficiency pixels: 267 126 229 468 386 534 533 254 236 370 309 252 328 231 58 54
[14:20:46.560] INFO: number of X-ray hits detected: 135519 90377 143630 215637 225795 226398 221972 144936 134363 193546 192663 170701 176815 113238 46435 53509
[14:20:46.560] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:20:46.561] INFO: number of Vcal hits detected: 207722 207867 207746 207499 207574 207396 207406 207731 207754 207601 207674 207731 207650 207751 207941 207946
[14:20:46.561] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.9 99.9 99.8 99.9 99.9 99.8 99.9 100.0 100.0
[14:20:46.561] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[14:20:46.561] INFO: X-ray hit rate [MHz/cm2]: 39.7 26.5 42.1 63.2 66.2 66.4 65.1 42.5 39.4 56.7 56.5 50.0 51.8 33.2 13.6 15.7
[14:20:46.561] INFO: PixTestHighRate::doXPixelAlive() done
[14:20:46.610] INFO: PixTest:: pg_setup set to default.
[14:20:46.627] INFO: enter test to run
[14:21:12.800] INFO: test: HighRate no parameter change
[14:21:12.800] INFO: running: highrate
[14:21:12.800] INFO: ----------------------------------------------------------------------
[14:21:12.801] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:21:12.801] INFO: ----------------------------------------------------------------------
[14:21:13.424] INFO: Expecting 208000 events.
[14:21:28.567] INFO: 208000 events read in total (14617ms).
[14:21:28.576] INFO: Test took 15767ms.
[14:21:29.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:29.401] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:21:29.401] INFO: number of red-efficiency pixels: 552 275 523 1078 945 1293 1251 565 501 773 662 578 751 520 102 91
[14:21:29.401] INFO: number of X-ray hits detected: 205093 137299 218274 327074 339881 342413 336539 219000 205102 292272 289761 257095 268457 171614 69761 81567
[14:21:29.401] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:21:29.401] INFO: number of Vcal hits detected: 207320 207691 207380 206645 206843 206308 206351 207325 207420 207098 207256 207350 207158 207387 207895 207907
[14:21:29.401] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.4 99.5 99.3 99.3 99.7 99.8 99.6 99.7 99.7 99.6 99.7 100.0 100.0
[14:21:29.401] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.3 99.4 99.2 99.2 99.7 99.7 99.6 99.6 99.7 99.6 99.7 99.9 100.0
[14:21:29.401] INFO: X-ray hit rate [MHz/cm2]: 60.1 40.2 64.0 95.9 99.6 100.4 98.6 64.2 60.1 85.7 84.9 75.4 78.7 50.3 20.4 23.9
[14:21:29.401] INFO: PixTestHighRate::doXPixelAlive() done
[14:21:29.450] INFO: PixTest:: pg_setup set to default.
[14:21:29.466] INFO: enter test to run
[14:21:41.560] INFO: test: exit no parameter change
[14:21:42.270] QUIET: Connection to board 33 closed.
[14:21:42.529] INFO: pXar: this is the end, my friend