[14:04:42.930] INFO: *** Welcome to pxar ***
[14:04:42.930] INFO: *** Today: 2016/06/20
[14:04:42.946] INFO: *** Version: v1.9.0-814-g7497
[14:04:42.946] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//dacParameters35_C15.dat
[14:04:42.970] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:04:42.971] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//defaultMaskFile.dat
[14:04:42.971] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C15.dat
[14:04:43.082] INFO: clk: 4
[14:04:43.082] INFO: ctr: 4
[14:04:43.082] INFO: sda: 19
[14:04:43.082] INFO: tin: 9
[14:04:43.082] INFO: level: 15
[14:04:43.082] INFO: triggerdelay: 0
[14:04:43.082] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:04:43.082] INFO: Log level: INFO
[14:04:43.100] QUIET: Connection to board DTB_WREKRL opened.
[14:04:43.103] 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:
------------------------------------------------------
[14:04:43.106] INFO: RPC call hashes of host and DTB match: 398089610
[14:04:44.631] INFO: DUT info:
[14:04:44.631] INFO: The DUT currently contains the following objects:
[14:04:44.632] INFO: 2 TBM Cores tbm08c (2 ON)
[14:04:44.632] INFO: TBM Core alpha (0): 7 registers set
[14:04:44.632] INFO: TBM Core beta (1): 7 registers set
[14:04:44.632] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:04:44.632] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.632] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.632] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.632] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.632] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.632] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.632] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.632] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.632] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.632] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.632] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.633] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.633] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.633] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.633] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:44.633] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:04:45.046] INFO: enter 'restricted' command line mode
[14:04:45.046] INFO: enter test to run
[14:04:50.007] INFO: test: PixelAlive no parameter change
[14:04:50.007] INFO: running: pixelalive
[14:04:50.017] INFO: ----------------------------------------------------------------------
[14:04:50.017] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:04:50.017] INFO: ----------------------------------------------------------------------
[14:04:50.334] INFO: Expecting 41600 events.
[14:04:54.676] INFO: 41600 events read in total (3623ms).
[14:04:54.845] INFO: Test took 4826ms.
[14:04:54.855] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:55.117] INFO: PixTestAlive::aliveTest() done
[14:04:55.118] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 164 0 0 0 0 0 0 0
[14:04:55.149] INFO: enter test to run
[14:05:53.511] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:05:53.511] INFO: running: highrate
[14:05:53.512] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:05:53.733] INFO: ----------------------------------------------------------------------
[14:05:53.733] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:05:53.733] INFO: ----------------------------------------------------------------------
[14:05:53.733] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:05:53.733] INFO: edge/corner pixel THR is adjusted
[14:05:53.733] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:05:54.692] INFO: Collecting data for 5 seconds...
[14:05:59.707] INFO: Done with hot pixel readout
[14:06:10.945] INFO: PixTest:: pg_setup set to default.
[14:06:10.946] INFO: 12 hot pixels found in step 0
[14:06:11.931] INFO: Collecting data for 5 seconds...
[14:06:16.946] INFO: Done with hot pixel readout
[14:06:28.125] INFO: PixTest:: pg_setup set to default.
[14:06:28.125] INFO: 10 hot pixels found in step 1
[14:06:29.113] INFO: Collecting data for 5 seconds...
[14:06:34.128] INFO: Done with hot pixel readout
[14:06:45.369] INFO: PixTest:: pg_setup set to default.
[14:06:45.370] INFO: 12 hot pixels found in step 2
[14:06:46.357] INFO: Collecting data for 5 seconds...
[14:06:51.373] INFO: Done with hot pixel readout
[14:07:02.539] INFO: PixTest:: pg_setup set to default.
[14:07:02.539] INFO: 9 hot pixels found in step 3
[14:07:03.527] INFO: Collecting data for 5 seconds...
[14:07:08.543] INFO: Done with hot pixel readout
[14:07:19.831] INFO: PixTest:: pg_setup set to default.
[14:07:19.832] INFO: 8 hot pixels found in step 4
[14:07:20.818] INFO: Collecting data for 5 seconds...
[14:07:25.834] INFO: Done with hot pixel readout
[14:07:36.002] INFO: PixTest:: pg_setup set to default.
[14:07:37.002] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:37.003] INFO: 7 hot pixels found in step 5
[14:07:37.990] INFO: Collecting data for 5 seconds...
[14:07:43.005] INFO: Done with hot pixel readout
[14:07:54.165] INFO: PixTest:: pg_setup set to default.
[14:07:54.165] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:07:54.166] INFO: 7 hot pixels found in step 6
[14:07:55.153] INFO: Collecting data for 5 seconds...
[14:08:00.168] INFO: Done with hot pixel readout
[14:08:11.263] INFO: PixTest:: pg_setup set to default.
[14:08:11.263] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:11.264] INFO: 4 hot pixels found in step 7
[14:08:12.251] INFO: Collecting data for 5 seconds...
[14:08:17.267] INFO: Done with hot pixel readout
[14:08:28.473] INFO: PixTest:: pg_setup set to default.
[14:08:28.473] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:28.473] INFO: 3 hot pixels found in step 8
[14:08:29.460] INFO: Collecting data for 5 seconds...
[14:08:34.476] INFO: Done with hot pixel readout
[14:08:45.691] INFO: PixTest:: pg_setup set to default.
[14:08:45.692] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:08:45.692] INFO: 3 hot pixels found in step 9
[14:08:46.680] INFO: Collecting data for 5 seconds...
[14:08:51.697] INFO: Done with hot pixel readout
[14:09:02.944] INFO: PixTest:: pg_setup set to default.
[14:09:02.944] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:02.945] INFO: 2 hot pixels found in step 10
[14:09:03.933] INFO: Collecting data for 5 seconds...
[14:09:08.950] INFO: Done with hot pixel readout
[14:09:19.779] INFO: PixTest:: pg_setup set to default.
[14:09:19.779] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:19.780] INFO: 2 hot pixels found in step 11
[14:09:20.768] INFO: Collecting data for 5 seconds...
[14:09:25.784] INFO: Done with hot pixel readout
[14:09:36.680] INFO: PixTest:: pg_setup set to default.
[14:09:36.680] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:36.681] INFO: 2 hot pixels found in step 12
[14:09:37.669] INFO: Collecting data for 5 seconds...
[14:09:42.685] INFO: Done with hot pixel readout
[14:09:53.578] INFO: PixTest:: pg_setup set to default.
[14:09:53.578] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:09:53.579] INFO: 3 hot pixels found in step 13
[14:09:54.567] INFO: Collecting data for 5 seconds...
[14:09:59.584] INFO: Done with hot pixel readout
[14:10:10.638] INFO: PixTest:: pg_setup set to default.
[14:10:10.638] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:10:10.639] INFO: 2 hot pixels found in step 14
[14:10:10.677] INFO: 2 hot pixels could not be trimmed and have been masked.
[14:10:10.681] INFO: PixTest::trimHotPixels() done
[14:10:10.681] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C0.dat
[14:10:10.696] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C1.dat
[14:10:10.702] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C2.dat
[14:10:10.708] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C3.dat
[14:10:10.713] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C4.dat
[14:10:10.719] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C5.dat
[14:10:10.724] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C6.dat
[14:10:10.730] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C7.dat
[14:10:10.735] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C8.dat
[14:10:10.741] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C9.dat
[14:10:10.746] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C10.dat
[14:10:10.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C11.dat
[14:10:10.757] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C12.dat
[14:10:10.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C13.dat
[14:10:10.767] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C14.dat
[14:10:10.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C15.dat
[14:10:10.778] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//defaultMaskFile.dat
[14:10:10.787] INFO: enter test to run
[14:10:38.237] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:10:38.237] INFO: running: highrate
[14:10:38.242] INFO: ----------------------------------------------------------------------
[14:10:38.242] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:10:38.242] INFO: ----------------------------------------------------------------------
[14:10:38.242] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:10:38.242] INFO: edge/corner pixel THR is adjusted
[14:10:38.242] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:10:39.199] INFO: Collecting data for 1 seconds...
[14:10:40.203] INFO: Done with hot pixel readout
[14:10:43.771] INFO: PixTest:: pg_setup set to default.
[14:10:43.772] INFO: 0 hot pixels found in step 0
[14:10:43.779] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:10:43.878] INFO: PixTest::trimHotPixels() done
[14:10:43.879] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C0.dat
[14:10:43.890] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C1.dat
[14:10:43.900] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C2.dat
[14:10:43.905] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C3.dat
[14:10:43.911] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C4.dat
[14:10:43.916] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C5.dat
[14:10:43.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C6.dat
[14:10:43.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C7.dat
[14:10:43.932] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C8.dat
[14:10:43.937] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C9.dat
[14:10:43.942] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C10.dat
[14:10:43.948] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C11.dat
[14:10:43.953] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C12.dat
[14:10:43.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C13.dat
[14:10:43.964] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C14.dat
[14:10:43.969] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//trimParameters35_C15.dat
[14:10:43.974] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-47_FPIXTest-17C-FNAL-160614-0955_2016-06-14_09h56m_1465916162/000_FPIXTest_p17//defaultMaskFile.dat
[14:10:43.984] INFO: enter test to run
[14:11:10.645] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:11:10.645] INFO: running: xray
[14:11:10.646] INFO: ----------------------------------------------------------------------
[14:11:10.646] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:11:10.646] INFO: ----------------------------------------------------------------------
[14:11:11.609] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:11:23.635] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:11:53.610] INFO: Resuming triggers.
[14:12:05.636] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:12:35.460] INFO: Resuming triggers.
[14:12:47.488] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:13:16.523] INFO: Resuming triggers.
[14:13:28.550] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:13:57.628] INFO: Resuming triggers.
[14:14:09.658] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:14:38.496] INFO: Resuming triggers.
[14:14:50.523] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:15:19.575] INFO: Resuming triggers.
[14:15:31.605] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:16:00.665] INFO: Resuming triggers.
[14:16:12.696] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:16:41.727] INFO: Resuming triggers.
[14:16:45.832] INFO: data taking finished, elapsed time: 100 seconds.
[14:16:56.091] INFO: PixTest:: pg_setup set to default.
[14:16:56.094] INFO: PixTestXray::doPhRun() done
[14:16:56.227] INFO: enter test to run
[14:17:29.242] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:17:29.242] INFO: running: xray
[14:17:29.243] INFO: ----------------------------------------------------------------------
[14:17:29.244] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:17:29.244] INFO: ----------------------------------------------------------------------
[14:17:30.207] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:17:37.650] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:18:07.591] INFO: Resuming triggers.
[14:18:15.037] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:18:45.088] INFO: Resuming triggers.
[14:18:52.533] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:19:22.530] INFO: Resuming triggers.
[14:19:29.977] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[14:20:00.078] INFO: Resuming triggers.
[14:20:07.523] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[14:20:37.439] INFO: Resuming triggers.
[14:20:44.883] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:21:15.568] INFO: Resuming triggers.
[14:21:23.011] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[14:21:53.453] INFO: Resuming triggers.
[14:22:00.897] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:22:31.447] INFO: Resuming triggers.
[14:22:38.891] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:23:10.104] INFO: Resuming triggers.
[14:23:17.549] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:23:48.962] INFO: Resuming triggers.
[14:23:56.409] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:24:26.509] INFO: Resuming triggers.
[14:24:33.956] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:25:04.017] INFO: Resuming triggers.
[14:25:11.467] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:25:41.499] INFO: Resuming triggers.
[14:25:45.041] INFO: data taking finished, elapsed time: 100 seconds.
[14:25:59.602] INFO: PixTest:: pg_setup set to default.
[14:25:59.606] INFO: PixTestXray::doPhRun() done
[14:25:59.751] INFO: enter test to run
[14:26:47.718] INFO: test: HighRate no parameter change
[14:26:47.719] INFO: running: highrate
[14:26:47.720] INFO: ----------------------------------------------------------------------
[14:26:47.720] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:26:47.720] INFO: ----------------------------------------------------------------------
[14:26:47.860] INFO: Expecting 768 events.
[14:26:48.994] INFO: 768 events read in total (418ms).
[14:26:48.994] INFO: Test took 1268ms.
[14:26:49.797] INFO: Expecting 41600 events.
[14:26:52.856] INFO: 41600 events read in total (2532ms).
[14:26:52.857] INFO: Test took 3857ms.
[14:26:52.886] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:53.622] INFO: Expecting 41600 events.
[14:26:56.781] INFO: 41600 events read in total (2632ms).
[14:26:56.782] INFO: Test took 3879ms.
[14:26:56.812] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:57.546] INFO: Expecting 41600 events.
[14:27:00.728] INFO: 41600 events read in total (2655ms).
[14:27:00.729] INFO: Test took 3899ms.
[14:27:00.759] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:01.491] INFO: Expecting 41600 events.
[14:27:04.663] INFO: 41600 events read in total (2646ms).
[14:27:04.664] INFO: Test took 3889ms.
[14:27:04.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:05.424] INFO: Expecting 41600 events.
[14:27:08.622] INFO: 41600 events read in total (2671ms).
[14:27:08.623] INFO: Test took 3911ms.
[14:27:08.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:09.383] INFO: Expecting 41600 events.
[14:27:12.585] INFO: 41600 events read in total (2676ms).
[14:27:12.586] INFO: Test took 3917ms.
[14:27:12.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:13.348] INFO: Expecting 41600 events.
[14:27:16.535] INFO: 41600 events read in total (2660ms).
[14:27:16.535] INFO: Test took 3903ms.
[14:27:16.566] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:17.300] INFO: Expecting 41600 events.
[14:27:20.502] INFO: 41600 events read in total (2676ms).
[14:27:20.503] INFO: Test took 3921ms.
[14:27:20.533] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:21.262] INFO: Expecting 41600 events.
[14:27:24.455] INFO: 41600 events read in total (2666ms).
[14:27:24.456] INFO: Test took 3905ms.
[14:27:24.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:25.219] INFO: Expecting 41600 events.
[14:27:28.415] INFO: 41600 events read in total (2669ms).
[14:27:28.416] INFO: Test took 3914ms.
[14:27:28.447] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:29.180] INFO: Expecting 41600 events.
[14:27:32.363] INFO: 41600 events read in total (2656ms).
[14:27:32.364] INFO: Test took 3901ms.
[14:27:32.394] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:33.128] INFO: Expecting 41600 events.
[14:27:36.331] INFO: 41600 events read in total (2676ms).
[14:27:36.332] INFO: Test took 3920ms.
[14:27:36.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:37.093] INFO: Expecting 41600 events.
[14:27:40.294] INFO: 41600 events read in total (2674ms).
[14:27:40.295] INFO: Test took 3917ms.
[14:27:40.325] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:41.058] INFO: Expecting 41600 events.
[14:27:44.242] INFO: 41600 events read in total (2657ms).
[14:27:44.243] INFO: Test took 3901ms.
[14:27:44.273] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:44.001] INFO: Expecting 41600 events.
[14:27:48.201] INFO: 41600 events read in total (2673ms).
[14:27:48.202] INFO: Test took 3912ms.
[14:27:48.232] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:48.965] INFO: Expecting 41600 events.
[14:27:52.162] INFO: 41600 events read in total (2670ms).
[14:27:52.163] INFO: Test took 3914ms.
[14:27:52.193] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:52.926] INFO: Expecting 41600 events.
[14:27:56.118] INFO: 41600 events read in total (2665ms).
[14:27:56.119] INFO: Test took 3910ms.
[14:27:56.150] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:56.878] INFO: Expecting 41600 events.
[14:28:00.092] INFO: 41600 events read in total (2687ms).
[14:28:00.093] INFO: Test took 3926ms.
[14:28:00.123] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:00.854] INFO: Expecting 41600 events.
[14:28:04.038] INFO: 41600 events read in total (2657ms).
[14:28:04.039] INFO: Test took 3899ms.
[14:28:04.069] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:04.799] INFO: Expecting 41600 events.
[14:28:07.817] INFO: 41600 events read in total (2491ms).
[14:28:07.818] INFO: Test took 3732ms.
[14:28:07.847] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:08.219] INFO: enter test to run
[14:28:35.982] INFO: test: HighRate no parameter change
[14:28:35.982] INFO: running: highrate
[14:28:35.983] INFO: ----------------------------------------------------------------------
[14:28:35.983] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:28:35.983] INFO: ----------------------------------------------------------------------
[14:28:36.603] INFO: Expecting 208000 events.
[14:28:48.246] INFO: 208000 events read in total (11116ms).
[14:28:48.249] INFO: Test took 12257ms.
[14:28:48.376] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:48.623] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 135 0 0 0 0 0 0 0
[14:28:48.624] INFO: number of red-efficiency pixels: 65 24 62 98 127 136 136 99 251 120 106 84 76 53 28 29
[14:28:48.624] INFO: number of X-ray hits detected: 52775 34554 57417 87713 96481 98560 104291 79674 71959 85976 81588 65747 67230 41406 18437 20745
[14:28:48.624] 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:28:48.624] INFO: number of Vcal hits detected: 207935 207974 207938 207900 207871 207861 207808 207901 199761 207878 207893 207912 207923 207943 207971 207971
[14:28:48.624] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 99.2 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[14:28:48.624] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 96.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:28:48.624] INFO: X-ray hit rate [MHz/cm2]: 15.5 10.1 16.8 25.7 28.3 28.9 30.6 23.4 21.1 25.2 23.9 19.3 19.7 12.1 5.4 6.1
[14:28:48.624] INFO: PixTestHighRate::doXPixelAlive() done
[14:28:48.673] INFO: PixTest:: pg_setup set to default.
[14:28:48.688] INFO: enter test to run
[14:29:48.117] INFO: test: HighRate no parameter change
[14:29:48.117] INFO: running: highrate
[14:29:48.119] INFO: ----------------------------------------------------------------------
[14:29:48.119] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:29:48.119] INFO: ----------------------------------------------------------------------
[14:29:48.738] INFO: Expecting 208000 events.
[14:30:01.554] INFO: 208000 events read in total (12289ms).
[14:30:01.559] INFO: Test took 13430ms.
[14:30:01.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:02.098] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 88 0 0 0 0 0 0 0
[14:30:02.098] INFO: number of red-efficiency pixels: 157 84 162 343 402 399 354 311 399 335 247 195 201 123 43 40
[14:30:02.098] INFO: number of X-ray hits detected: 107891 70254 117150 179347 196667 200604 212866 161849 146677 176386 165581 134627 136852 85395 37521 42135
[14:30:02.098] 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:30:02.098] INFO: number of Vcal hits detected: 207827 207914 207831 207634 207577 207564 207574 207661 199670 207646 207741 207798 207793 207867 207957 207960
[14:30:02.098] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.8 98.0 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[14:30:02.098] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.8 96.0 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[14:30:02.098] INFO: X-ray hit rate [MHz/cm2]: 31.6 20.6 34.3 52.6 57.6 58.8 62.4 47.4 43.0 51.7 48.5 39.5 40.1 25.0 11.0 12.4
[14:30:02.098] INFO: PixTestHighRate::doXPixelAlive() done
[14:30:02.143] INFO: PixTest:: pg_setup set to default.
[14:30:02.162] INFO: enter test to run
[14:30:31.485] INFO: test: HighRate no parameter change
[14:30:31.485] INFO: running: highrate
[14:30:31.486] INFO: ----------------------------------------------------------------------
[14:30:31.486] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:30:31.486] INFO: ----------------------------------------------------------------------
[14:30:32.098] INFO: Expecting 208000 events.
[14:30:46.600] INFO: 208000 events read in total (13975ms).
[14:30:46.606] INFO: Test took 15111ms.
[14:30:46.971] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:47.296] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 71 0 0 0 0 0 0 0
[14:30:47.296] INFO: number of red-efficiency pixels: 342 169 391 754 881 926 777 722 638 783 512 457 440 213 71 64
[14:30:47.296] INFO: number of X-ray hits detected: 162474 105993 175760 269230 296169 302707 320953 244339 218455 265962 250673 202328 205995 129171 57099 63805
[14:30:47.296] 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:30:47.296] INFO: number of Vcal hits detected: 207605 207824 207542 207130 206958 206872 207045 207132 199413 207112 207427 207502 207526 207766 207927 207934
[14:30:47.296] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.5 99.5 99.6 99.6 97.5 99.6 99.7 99.8 99.8 99.9 100.0 100.0
[14:30:47.296] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.6 99.5 99.5 99.5 99.6 95.9 99.6 99.7 99.8 99.8 99.9 100.0 100.0
[14:30:47.296] INFO: X-ray hit rate [MHz/cm2]: 47.6 31.1 51.5 78.9 86.8 88.7 94.1 71.6 64.0 78.0 73.5 59.3 60.4 37.9 16.7 18.7
[14:30:47.296] INFO: PixTestHighRate::doXPixelAlive() done
[14:30:47.347] INFO: PixTest:: pg_setup set to default.
[14:30:47.366] INFO: enter test to run
[14:30:52.773] INFO: test: exit no parameter change
[14:30:53.055] QUIET: Connection to board 33 closed.
[14:30:53.056] INFO: pXar: this is the end, my friend