[14:28:06.731] INFO: *** Welcome to pxar ***
[14:28:06.731] INFO: *** Today: 2016/04/04
[14:28:07.051] INFO: *** Version: v1.9.0-793-ge521-dirty
[14:28:07.051] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//dacParameters35_C15.dat
[14:28:07.097] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:28:07.097] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//defaultMaskFile.dat
[14:28:07.110] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C15.dat
[14:28:07.218] INFO: clk: 4
[14:28:07.218] INFO: ctr: 4
[14:28:07.218] INFO: sda: 19
[14:28:07.218] INFO: tin: 9
[14:28:07.218] INFO: level: 15
[14:28:07.218] INFO: triggerdelay: 0
[14:28:07.218] QUIET: Instanciating API for pxar v1.9.0+793~ge5211a7
[14:28:07.218] INFO: Log level: INFO
[14:28:07.236] QUIET: Connection to board DTB_WREKRL opened.
[14:28:07.239] 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:28:07.242] INFO: RPC call hashes of host and DTB match: 398089610
[14:28:08.778] INFO: DUT info:
[14:28:08.778] INFO: The DUT currently contains the following objects:
[14:28:08.778] INFO: 2 TBM Cores tbm08c (2 ON)
[14:28:08.778] INFO: TBM Core alpha (0): 7 registers set
[14:28:08.778] INFO: TBM Core beta (1): 7 registers set
[14:28:08.778] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:28:08.778] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.778] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.778] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.778] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.778] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.778] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.779] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.779] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.779] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.779] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.779] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.779] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.779] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.779] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.779] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:08.779] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:28:09.231] INFO: enter 'restricted' command line mode
[14:28:09.231] INFO: enter test to run
[14:28:15.816] INFO: test: PixelAlive no parameter change
[14:28:15.816] INFO: running: pixelalive
[14:28:15.847] INFO: ----------------------------------------------------------------------
[14:28:15.847] 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:28:15.847] INFO: ----------------------------------------------------------------------
[14:28:16.164] INFO: Expecting 41600 events.
[14:28:20.513] INFO: 41600 events read in total (3631ms).
[14:28:20.679] INFO: Test took 4830ms.
[14:28:20.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:20.956] INFO: PixTestAlive::aliveTest() done
[14:28:20.956] INFO: number of dead pixels (per ROC): 0 0 0 0 1 11 0 5 0 0 0 1 0 0 0 0
[14:28:20.989] INFO: enter test to run
[14:29:21.288] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:29:21.288] INFO: running: highrate
[14:29:21.288] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:29:21.561] INFO: ----------------------------------------------------------------------
[14:29:21.562] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:29:21.562] INFO: ----------------------------------------------------------------------
[14:29:21.562] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:29:21.562] INFO: edge/corner pixel THR is adjusted
[14:29:21.562] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:29:22.541] INFO: Collecting data for 5 seconds...
[14:29:27.558] INFO: Done with hot pixel readout
[14:29:39.458] INFO: PixTest:: pg_setup set to default.
[14:29:39.458] INFO: 3 hot pixels found in step 0
[14:29:40.473] INFO: Collecting data for 5 seconds...
[14:29:45.491] INFO: Done with hot pixel readout
[14:29:57.417] INFO: PixTest:: pg_setup set to default.
[14:29:57.417] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:29:57.418] INFO: 4 hot pixels found in step 1
[14:29:58.412] INFO: Collecting data for 5 seconds...
[14:30:03.429] INFO: Done with hot pixel readout
[14:30:15.364] INFO: PixTest:: pg_setup set to default.
[14:30:15.365] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:30:15.365] INFO: 2 hot pixels found in step 2
[14:30:16.359] INFO: Collecting data for 5 seconds...
[14:30:21.375] INFO: Done with hot pixel readout
[14:30:33.333] INFO: PixTest:: pg_setup set to default.
[14:30:33.333] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:30:33.333] INFO: 3 hot pixels found in step 3
[14:30:34.327] INFO: Collecting data for 5 seconds...
[14:30:39.343] INFO: Done with hot pixel readout
[14:30:51.253] INFO: PixTest:: pg_setup set to default.
[14:30:51.254] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:30:51.254] INFO: 3 hot pixels found in step 4
[14:30:52.249] INFO: Collecting data for 5 seconds...
[14:30:57.267] INFO: Done with hot pixel readout
[14:31:09.204] INFO: PixTest:: pg_setup set to default.
[14:31:09.204] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:31:09.204] INFO: 2 hot pixels found in step 5
[14:31:10.199] INFO: Collecting data for 5 seconds...
[14:31:15.216] INFO: Done with hot pixel readout
[14:31:27.175] INFO: PixTest:: pg_setup set to default.
[14:31:27.175] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:31:27.176] INFO: 3 hot pixels found in step 6
[14:31:28.171] INFO: Collecting data for 5 seconds...
[14:31:33.187] INFO: Done with hot pixel readout
[14:31:45.129] INFO: PixTest:: pg_setup set to default.
[14:31:45.129] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:31:45.130] INFO: 3 hot pixels found in step 7
[14:31:46.124] INFO: Collecting data for 5 seconds...
[14:31:51.141] INFO: Done with hot pixel readout
[14:32:03.117] INFO: PixTest:: pg_setup set to default.
[14:32:03.117] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:32:03.118] INFO: 2 hot pixels found in step 8
[14:32:04.111] INFO: Collecting data for 5 seconds...
[14:32:09.129] INFO: Done with hot pixel readout
[14:32:21.082] INFO: PixTest:: pg_setup set to default.
[14:32:21.083] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:32:21.083] INFO: 2 hot pixels found in step 9
[14:32:22.076] INFO: Collecting data for 5 seconds...
[14:32:27.094] INFO: Done with hot pixel readout
[14:32:39.062] INFO: PixTest:: pg_setup set to default.
[14:32:39.062] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:32:39.063] INFO: 1 hot pixels found in step 10
[14:32:39.100] INFO: 1 hot pixels could not be trimmed and have been masked.
[14:32:39.103] INFO: PixTest::trimHotPixels() done
[14:32:39.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C0.dat
[14:32:39.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C1.dat
[14:32:39.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C2.dat
[14:32:39.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C3.dat
[14:32:39.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C4.dat
[14:32:39.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C5.dat
[14:32:39.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C6.dat
[14:32:39.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C7.dat
[14:32:39.147] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C8.dat
[14:32:39.152] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C9.dat
[14:32:39.157] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C10.dat
[14:32:39.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C11.dat
[14:32:39.168] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C12.dat
[14:32:39.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C13.dat
[14:32:39.178] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C14.dat
[14:32:39.195] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C15.dat
[14:32:39.200] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//defaultMaskFile.dat
[14:32:39.210] INFO: enter test to run
[14:34:29.597] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:34:29.597] INFO: running: highrate
[14:34:29.602] INFO: ----------------------------------------------------------------------
[14:34:29.602] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:34:29.602] INFO: ----------------------------------------------------------------------
[14:34:29.602] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:34:29.602] INFO: edge/corner pixel THR is adjusted
[14:34:29.602] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:34:30.560] INFO: Collecting data for 1 seconds...
[14:34:31.563] INFO: Done with hot pixel readout
[14:34:35.017] INFO: PixTest:: pg_setup set to default.
[14:34:35.017] INFO: 1 hot pixels found in step 0
[14:34:36.088] INFO: Collecting data for 1 seconds...
[14:34:37.092] INFO: Done with hot pixel readout
[14:34:40.557] INFO: PixTest:: pg_setup set to default.
[14:34:40.557] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:34:40.559] INFO: 1 hot pixels found in step 1
[14:34:40.569] INFO: 1 hot pixels could not be trimmed and have been masked.
[14:34:40.676] INFO: PixTest::trimHotPixels() done
[14:34:40.676] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C0.dat
[14:34:40.687] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C1.dat
[14:34:40.692] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C2.dat
[14:34:40.697] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C3.dat
[14:34:40.703] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C4.dat
[14:34:40.708] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C5.dat
[14:34:40.713] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C6.dat
[14:34:40.719] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C7.dat
[14:34:40.724] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C8.dat
[14:34:40.729] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C9.dat
[14:34:40.734] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C10.dat
[14:34:40.740] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C11.dat
[14:34:40.745] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C12.dat
[14:34:40.750] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C13.dat
[14:34:40.755] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C14.dat
[14:34:40.760] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C15.dat
[14:34:40.766] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-23_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//defaultMaskFile.dat
[14:34:40.781] INFO: enter test to run
[14:35:14.445] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:35:14.445] INFO: running: xray
[14:35:14.446] INFO: ----------------------------------------------------------------------
[14:35:14.446] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:35:14.446] INFO: ----------------------------------------------------------------------
[14:35:15.410] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:35:26.511] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:35:55.971] INFO: Resuming triggers.
[14:36:07.075] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:36:36.573] INFO: Resuming triggers.
[14:36:47.678] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:37:17.139] INFO: Resuming triggers.
[14:37:28.244] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:37:57.730] INFO: Resuming triggers.
[14:38:08.833] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:38:38.323] INFO: Resuming triggers.
[14:38:49.426] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:39:16.232] INFO: Resuming triggers.
[14:39:27.338] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:39:56.804] INFO: Resuming triggers.
[14:40:07.914] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:40:37.333] INFO: Resuming triggers.
[14:40:48.443] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:41:17.995] INFO: Resuming triggers.
[14:41:18.376] INFO: data taking finished, elapsed time: 100 seconds.
[14:41:19.828] INFO: PixTest:: pg_setup set to default.
[14:41:19.831] INFO: PixTestXray::doPhRun() done
[14:41:19.972] INFO: enter test to run
[14:41:48.562] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:41:48.562] INFO: running: xray
[14:41:48.564] INFO: ----------------------------------------------------------------------
[14:41:48.564] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:41:48.564] INFO: ----------------------------------------------------------------------
[14:41:49.541] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:41:55.813] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:42:25.882] INFO: Resuming triggers.
[14:42:32.154] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:43:02.105] INFO: Resuming triggers.
[14:43:08.378] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[14:43:38.420] INFO: Resuming triggers.
[14:43:44.692] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[14:44:14.763] INFO: Resuming triggers.
[14:44:21.032] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[14:44:51.124] INFO: Resuming triggers.
[14:44:57.393] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[14:45:28.031] INFO: Resuming triggers.
[14:45:34.298] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:46:04.245] INFO: Resuming triggers.
[14:46:10.509] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:46:40.658] INFO: Resuming triggers.
[14:46:46.926] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:47:16.906] INFO: Resuming triggers.
[14:47:23.173] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[14:47:53.291] INFO: Resuming triggers.
[14:47:59.555] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:48:29.555] INFO: Resuming triggers.
[14:48:35.814] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:49:05.852] INFO: Resuming triggers.
[14:49:12.112] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:49:38.376] INFO: Resuming triggers.
[14:49:44.634] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[14:50:14.705] INFO: Resuming triggers.
[14:50:20.970] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[14:50:50.960] INFO: Resuming triggers.
[14:50:57.222] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:51:27.421] INFO: Resuming triggers.
[14:51:27.489] INFO: data taking finished, elapsed time: 100 seconds.
[14:51:28.319] INFO: PixTest:: pg_setup set to default.
[14:51:28.322] INFO: PixTestXray::doPhRun() done
[14:51:28.478] INFO: enter test to run
[14:52:18.774] INFO: test: HighRate no parameter change
[14:52:18.774] INFO: running: highrate
[14:52:18.775] INFO: ----------------------------------------------------------------------
[14:52:18.775] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:52:18.775] INFO: ----------------------------------------------------------------------
[14:52:18.917] INFO: Expecting 768 events.
[14:52:20.050] INFO: 768 events read in total (418ms).
[14:52:20.051] INFO: Test took 1268ms.
[14:52:20.854] INFO: Expecting 41600 events.
[14:52:23.943] INFO: 41600 events read in total (2563ms).
[14:52:23.944] INFO: Test took 3884ms.
[14:52:23.981] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:24.703] INFO: Expecting 41600 events.
[14:52:27.918] INFO: 41600 events read in total (2688ms).
[14:52:27.919] INFO: Test took 3918ms.
[14:52:27.957] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:28.676] INFO: Expecting 41600 events.
[14:52:31.938] INFO: 41600 events read in total (2735ms).
[14:52:31.939] INFO: Test took 3963ms.
[14:52:31.976] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:32.693] INFO: Expecting 41600 events.
[14:52:35.958] INFO: 41600 events read in total (2738ms).
[14:52:35.959] INFO: Test took 3963ms.
[14:52:35.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:36.714] INFO: Expecting 41600 events.
[14:52:39.983] INFO: 41600 events read in total (2742ms).
[14:52:39.984] INFO: Test took 3967ms.
[14:52:40.022] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:40.740] INFO: Expecting 41600 events.
[14:52:43.000] INFO: 41600 events read in total (2733ms).
[14:52:43.001] INFO: Test took 3961ms.
[14:52:44.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:44.755] INFO: Expecting 41600 events.
[14:52:48.040] INFO: 41600 events read in total (2758ms).
[14:52:48.041] INFO: Test took 3983ms.
[14:52:48.079] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:48.794] INFO: Expecting 41600 events.
[14:52:52.076] INFO: 41600 events read in total (2755ms).
[14:52:52.077] INFO: Test took 3979ms.
[14:52:52.115] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:52.830] INFO: Expecting 41600 events.
[14:52:56.108] INFO: 41600 events read in total (2751ms).
[14:52:56.109] INFO: Test took 3975ms.
[14:52:56.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:56.865] INFO: Expecting 41600 events.
[14:53:00.149] INFO: 41600 events read in total (2757ms).
[14:53:00.150] INFO: Test took 3985ms.
[14:53:00.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:00.902] INFO: Expecting 41600 events.
[14:53:04.182] INFO: 41600 events read in total (2753ms).
[14:53:04.183] INFO: Test took 3976ms.
[14:53:04.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:04.935] INFO: Expecting 41600 events.
[14:53:08.205] INFO: 41600 events read in total (2743ms).
[14:53:08.206] INFO: Test took 3965ms.
[14:53:08.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:08.964] INFO: Expecting 41600 events.
[14:53:12.238] INFO: 41600 events read in total (2747ms).
[14:53:12.239] INFO: Test took 3976ms.
[14:53:12.276] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:12.995] INFO: Expecting 41600 events.
[14:53:16.280] INFO: 41600 events read in total (2758ms).
[14:53:16.281] INFO: Test took 3985ms.
[14:53:16.318] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:17.037] INFO: Expecting 41600 events.
[14:53:20.310] INFO: 41600 events read in total (2746ms).
[14:53:20.311] INFO: Test took 3973ms.
[14:53:20.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:21.065] INFO: Expecting 41600 events.
[14:53:24.342] INFO: 41600 events read in total (2750ms).
[14:53:24.343] INFO: Test took 3974ms.
[14:53:24.381] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:25.095] INFO: Expecting 41600 events.
[14:53:28.385] INFO: 41600 events read in total (2763ms).
[14:53:28.386] INFO: Test took 3984ms.
[14:53:28.424] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:29.137] INFO: Expecting 41600 events.
[14:53:32.407] INFO: 41600 events read in total (2743ms).
[14:53:32.408] INFO: Test took 3964ms.
[14:53:32.446] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:33.163] INFO: Expecting 41600 events.
[14:53:36.438] INFO: 41600 events read in total (2748ms).
[14:53:36.439] INFO: Test took 3974ms.
[14:53:36.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:37.194] INFO: Expecting 41600 events.
[14:53:40.384] INFO: 41600 events read in total (2663ms).
[14:53:40.385] INFO: Test took 3889ms.
[14:53:40.421] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:40.777] INFO: enter test to run
[14:54:26.077] INFO: test: HighRate no parameter change
[14:54:26.077] INFO: running: highrate
[14:54:26.078] INFO: ----------------------------------------------------------------------
[14:54:26.078] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:54:26.078] INFO: ----------------------------------------------------------------------
[14:54:26.692] INFO: Expecting 208000 events.
[14:54:38.773] INFO: 208000 events read in total (11554ms).
[14:54:38.776] INFO: Test took 12688ms.
[14:54:38.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:39.195] INFO: number of dead pixels (per ROC): 0 0 0 0 1 11 0 5 0 0 0 1 0 0 0 0
[14:54:39.195] INFO: number of red-efficiency pixels: 112 49 111 174 176 244 171 154 108 147 124 147 121 77 29 36
[14:54:39.195] INFO: number of X-ray hits detected: 72900 47680 79462 120256 129456 140772 130894 98413 86586 110210 107971 94000 95350 58980 26892 27713
[14:54:39.195] 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:54:39.195] INFO: number of Vcal hits detected: 207884 207951 207887 207818 207772 207181 207827 207596 207891 207851 207874 207803 207877 207922 207971 207964
[14:54:39.195] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:54:39.195] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.6 99.9 99.8 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:54:39.195] INFO: X-ray hit rate [MHz/cm2]: 21.4 14.0 23.3 35.2 37.9 41.3 38.4 28.8 25.4 32.3 31.6 27.6 27.9 17.3 7.9 8.1
[14:54:39.195] INFO: PixTestHighRate::doXPixelAlive() done
[14:54:39.247] INFO: PixTest:: pg_setup set to default.
[14:54:39.261] INFO: enter test to run
[14:54:56.844] INFO: test: HighRate no parameter change
[14:54:56.844] INFO: running: highrate
[14:54:56.846] INFO: ----------------------------------------------------------------------
[14:54:56.846] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:54:56.846] INFO: ----------------------------------------------------------------------
[14:54:57.463] INFO: Expecting 208000 events.
[14:55:11.420] INFO: 208000 events read in total (13430ms).
[14:55:11.426] INFO: Test took 14571ms.
[14:55:11.751] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:12.060] INFO: number of dead pixels (per ROC): 0 0 0 0 1 11 0 4 0 0 0 1 0 0 0 0
[14:55:12.060] INFO: number of red-efficiency pixels: 225 101 266 572 482 742 509 457 301 511 354 352 342 226 83 73
[14:55:12.060] INFO: number of X-ray hits detected: 145283 94388 157848 237556 256485 275247 259647 196075 173537 217224 214589 186390 189938 117949 53611 54655
[14:55:12.060] 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:55:12.060] INFO: number of Vcal hits detected: 207756 207893 207716 207361 207398 206576 207431 207239 207688 207453 207621 207573 207641 207761 207913 207924
[14:55:12.060] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.7 99.8 99.6 99.8 99.7 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:55:12.060] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.3 99.7 99.6 99.9 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[14:55:12.060] INFO: X-ray hit rate [MHz/cm2]: 42.6 27.7 46.3 69.6 75.2 80.7 76.1 57.5 50.9 63.7 62.9 54.6 55.7 34.6 15.7 16.0
[14:55:12.060] INFO: PixTestHighRate::doXPixelAlive() done
[14:55:12.113] INFO: PixTest:: pg_setup set to default.
[14:55:12.129] INFO: enter test to run
[14:55:38.316] INFO: test: HighRate no parameter change
[14:55:38.316] INFO: running: highrate
[14:55:38.317] INFO: ----------------------------------------------------------------------
[14:55:38.317] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:55:38.317] INFO: ----------------------------------------------------------------------
[14:55:38.929] INFO: Expecting 208000 events.
[14:55:55.092] INFO: 208000 events read in total (15637ms).
[14:55:55.100] INFO: Test took 16774ms.
[14:55:55.597] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:55.959] INFO: number of dead pixels (per ROC): 0 0 0 0 1 11 0 5 0 0 0 1 0 0 0 0
[14:55:55.959] INFO: number of red-efficiency pixels: 499 238 671 1295 1186 1652 1227 1038 648 1195 836 810 669 548 139 111
[14:55:55.959] INFO: number of X-ray hits detected: 220498 144370 242061 362476 391805 418583 396874 299562 266338 332387 327581 286774 291258 180915 82034 84335
[14:55:55.959] 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:55:55.959] INFO: number of Vcal hits detected: 207419 207736 207120 206270 206393 204983 206386 206364 207255 206507 206998 207003 207240 207311 207853 207889
[14:55:55.959] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.2 99.3 98.9 99.3 99.4 99.7 99.3 99.6 99.6 99.7 99.7 99.9 99.9
[14:55:55.959] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.2 99.2 98.5 99.2 99.2 99.6 99.3 99.5 99.5 99.6 99.7 99.9 99.9
[14:55:55.959] INFO: X-ray hit rate [MHz/cm2]: 64.6 42.3 70.9 106.2 114.8 122.7 116.3 87.8 78.1 97.4 96.0 84.1 85.4 53.0 24.0 24.7
[14:55:55.959] INFO: PixTestHighRate::doXPixelAlive() done
[14:55:56.004] INFO: PixTest:: pg_setup set to default.
[14:55:56.016] INFO: enter test to run
[14:55:58.532] INFO: test: exit no parameter change
[14:55:58.896] QUIET: Connection to board 33 closed.
[14:55:58.896] INFO: pXar: this is the end, my friend