[14:32:11.150] INFO: *** Welcome to pxar ***
[14:32:11.150] INFO: *** Today: 2016/08/31
[14:32:11.983] INFO: *** Version: v1.9.0-818-g96727
[14:32:11.983] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//dacParameters35_C15.dat
[14:32:11.999] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:32:11.999] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//defaultMaskFile.dat
[14:32:11.001] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C15.dat
[14:32:12.167] INFO: clk: 4
[14:32:12.167] INFO: ctr: 4
[14:32:12.167] INFO: sda: 19
[14:32:12.167] INFO: tin: 9
[14:32:12.167] INFO: level: 15
[14:32:12.167] INFO: triggerdelay: 0
[14:32:12.167] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:32:12.167] INFO: Log level: INFO
[14:32:12.186] QUIET: Connection to board DTB_WREK4U opened.
[14:32:12.189] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[14:32:12.192] INFO: RPC call hashes of host and DTB match: 398089610
[14:32:13.726] INFO: DUT info:
[14:32:13.726] INFO: The DUT currently contains the following objects:
[14:32:13.726] INFO: 2 TBM Cores tbm08c (2 ON)
[14:32:13.726] INFO: TBM Core alpha (0): 7 registers set
[14:32:13.727] INFO: TBM Core beta (1): 7 registers set
[14:32:13.727] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:32:13.727] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.727] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.727] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.727] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.727] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.727] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.727] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.727] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.727] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.727] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.727] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.728] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.728] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.728] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.728] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:13.728] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:14.131] INFO: enter 'restricted' command line mode
[14:32:14.131] INFO: enter test to run
[14:32:21.755] INFO: test: PixelAlive no parameter change
[14:32:21.755] INFO: running: pixelalive
[14:32:21.776] INFO: ----------------------------------------------------------------------
[14:32:21.776] 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:32:21.776] INFO: ----------------------------------------------------------------------
[14:32:22.097] INFO: Expecting 41600 events.
[14:32:26.428] INFO: 41600 events read in total (3613ms).
[14:32:26.596] INFO: Test took 4817ms.
[14:32:26.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:26.886] INFO: PixTestAlive::aliveTest() done
[14:32:26.886] INFO: number of dead pixels (per ROC): 0 0 1 0 1 0 0 0 0 0 0 0 0 0 0 0
[14:32:26.915] INFO: enter test to run
[14:33:12.315] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:33:12.315] INFO: running: highrate
[14:33:12.315] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:33:12.543] INFO: ----------------------------------------------------------------------
[14:33:12.543] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:33:12.543] INFO: ----------------------------------------------------------------------
[14:33:12.544] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:33:12.544] INFO: edge/corner pixel THR is adjusted
[14:33:12.544] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:33:13.503] INFO: Collecting data for 5 seconds...
[14:33:18.519] INFO: Done with hot pixel readout
[14:33:30.347] INFO: PixTest:: pg_setup set to default.
[14:33:30.348] INFO: 8 hot pixels found in step 0
[14:33:31.339] INFO: Collecting data for 5 seconds...
[14:33:36.354] INFO: Done with hot pixel readout
[14:33:48.119] INFO: PixTest:: pg_setup set to default.
[14:33:48.120] INFO: 8 hot pixels found in step 1
[14:33:49.117] INFO: Collecting data for 5 seconds...
[14:33:54.133] INFO: Done with hot pixel readout
[14:34:05.937] INFO: PixTest:: pg_setup set to default.
[14:34:05.938] INFO: 6 hot pixels found in step 2
[14:34:06.931] INFO: Collecting data for 5 seconds...
[14:34:11.947] INFO: Done with hot pixel readout
[14:34:23.980] INFO: PixTest:: pg_setup set to default.
[14:34:23.981] INFO: 5 hot pixels found in step 3
[14:34:24.974] INFO: Collecting data for 5 seconds...
[14:34:29.994] INFO: Done with hot pixel readout
[14:34:41.620] INFO: PixTest:: pg_setup set to default.
[14:34:41.621] INFO: 8 hot pixels found in step 4
[14:34:42.614] INFO: Collecting data for 5 seconds...
[14:34:47.633] INFO: Done with hot pixel readout
[14:34:59.062] INFO: PixTest:: pg_setup set to default.
[14:34:59.063] INFO: 4 hot pixels found in step 5
[14:35:00.057] INFO: Collecting data for 5 seconds...
[14:35:05.078] INFO: Done with hot pixel readout
[14:35:16.540] INFO: PixTest:: pg_setup set to default.
[14:35:16.541] INFO: 2 hot pixels found in step 6
[14:35:17.534] INFO: Collecting data for 5 seconds...
[14:35:22.552] INFO: Done with hot pixel readout
[14:35:34.097] INFO: PixTest:: pg_setup set to default.
[14:35:34.098] INFO: 3 hot pixels found in step 7
[14:35:35.091] INFO: Collecting data for 5 seconds...
[14:35:40.110] INFO: Done with hot pixel readout
[14:35:51.790] INFO: PixTest:: pg_setup set to default.
[14:35:51.791] INFO: 2 hot pixels found in step 8
[14:35:52.785] INFO: Collecting data for 5 seconds...
[14:35:57.803] INFO: Done with hot pixel readout
[14:36:09.237] INFO: PixTest:: pg_setup set to default.
[14:36:09.238] INFO: 1 hot pixels found in step 9
[14:36:10.231] INFO: Collecting data for 5 seconds...
[14:36:15.249] INFO: Done with hot pixel readout
[14:36:27.027] INFO: PixTest:: pg_setup set to default.
[14:36:27.028] INFO: 5 hot pixels found in step 10
[14:36:28.022] INFO: Collecting data for 5 seconds...
[14:36:33.040] INFO: Done with hot pixel readout
[14:36:44.607] INFO: PixTest:: pg_setup set to default.
[14:36:44.608] INFO: 2 hot pixels found in step 11
[14:36:45.602] INFO: Collecting data for 5 seconds...
[14:36:50.621] INFO: Done with hot pixel readout
[14:37:02.759] INFO: PixTest:: pg_setup set to default.
[14:37:02.759] INFO: 2 hot pixels found in step 12
[14:37:03.753] INFO: Collecting data for 5 seconds...
[14:37:08.772] INFO: Done with hot pixel readout
[14:37:20.911] INFO: PixTest:: pg_setup set to default.
[14:37:20.912] INFO: 1 hot pixels found in step 13
[14:37:21.905] INFO: Collecting data for 5 seconds...
[14:37:26.925] INFO: Done with hot pixel readout
[14:37:39.023] INFO: PixTest:: pg_setup set to default.
[14:37:39.024] INFO: 1 hot pixels found in step 14
[14:37:39.060] INFO: 1 hot pixels could not be trimmed and have been masked.
[14:37:39.064] INFO: PixTest::trimHotPixels() done
[14:37:39.064] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C0.dat
[14:37:39.070] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C1.dat
[14:37:39.076] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C2.dat
[14:37:39.081] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C3.dat
[14:37:39.086] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C4.dat
[14:37:39.091] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C5.dat
[14:37:39.096] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C6.dat
[14:37:39.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C7.dat
[14:37:39.107] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C8.dat
[14:37:39.112] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C9.dat
[14:37:39.117] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C10.dat
[14:37:39.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C11.dat
[14:37:39.128] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C12.dat
[14:37:39.133] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C13.dat
[14:37:39.138] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C14.dat
[14:37:39.143] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C15.dat
[14:37:39.149] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//defaultMaskFile.dat
[14:37:39.158] INFO: enter test to run
[14:38:21.289] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:38:21.289] INFO: running: highrate
[14:38:21.293] INFO: ----------------------------------------------------------------------
[14:38:21.293] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:38:21.293] INFO: ----------------------------------------------------------------------
[14:38:21.293] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:38:21.293] INFO: edge/corner pixel THR is adjusted
[14:38:21.293] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:38:22.250] INFO: Collecting data for 1 seconds...
[14:38:23.253] INFO: Done with hot pixel readout
[14:38:27.497] INFO: PixTest:: pg_setup set to default.
[14:38:27.498] INFO: 0 hot pixels found in step 0
[14:38:27.503] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:38:27.577] INFO: PixTest::trimHotPixels() done
[14:38:27.577] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C0.dat
[14:38:27.588] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C1.dat
[14:38:27.595] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C2.dat
[14:38:27.600] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C3.dat
[14:38:27.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C4.dat
[14:38:27.611] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C5.dat
[14:38:27.616] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C6.dat
[14:38:27.622] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C7.dat
[14:38:27.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C8.dat
[14:38:27.632] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C9.dat
[14:38:27.638] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C10.dat
[14:38:27.643] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C11.dat
[14:38:27.649] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C12.dat
[14:38:27.654] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C13.dat
[14:38:27.659] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C14.dat
[14:38:27.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//trimParameters35_C15.dat
[14:38:27.670] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-2-36_FPIXTest-17C-FNAL-160824-1359-150V_2016-08-24_13h59m_1472065161/000_FPIXTest_p17//defaultMaskFile.dat
[14:38:27.680] INFO: enter test to run
[14:38:43.856] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:38:43.857] INFO: running: xray
[14:38:43.858] INFO: ----------------------------------------------------------------------
[14:38:43.858] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:38:43.858] INFO: ----------------------------------------------------------------------
[14:38:44.820] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:38:55.972] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:39:25.605] INFO: Resuming triggers.
[14:39:36.759] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:40:06.397] INFO: Resuming triggers.
[14:40:17.550] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:40:47.217] INFO: Resuming triggers.
[14:40:58.369] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:41:28.058] INFO: Resuming triggers.
[14:41:39.213] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:42:08.843] INFO: Resuming triggers.
[14:42:19.994] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:42:49.686] INFO: Resuming triggers.
[14:43:00.837] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:43:30.447] INFO: Resuming triggers.
[14:43:41.596] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:44:11.265] INFO: Resuming triggers.
[14:44:22.388] INFO: data taking finished, elapsed time: 100 seconds.
[14:44:51.999] INFO: PixTest:: pg_setup set to default.
[14:44:51.002] INFO: PixTestXray::doPhRun() done
[14:44:52.139] INFO: enter test to run
[14:45:14.222] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:45:14.222] INFO: running: xray
[14:45:14.223] INFO: ----------------------------------------------------------------------
[14:45:14.223] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:45:14.223] INFO: ----------------------------------------------------------------------
[14:45:15.194] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:45:21.506] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:45:51.631] INFO: Resuming triggers.
[14:45:57.943] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:46:28.087] INFO: Resuming triggers.
[14:46:34.399] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[14:47:05.333] INFO: Resuming triggers.
[14:47:11.645] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[14:47:42.075] INFO: Resuming triggers.
[14:47:48.390] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[14:48:19.057] INFO: Resuming triggers.
[14:48:25.367] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[14:48:56.515] INFO: Resuming triggers.
[14:49:02.824] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:49:33.629] INFO: Resuming triggers.
[14:49:39.939] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[14:50:10.826] INFO: Resuming triggers.
[14:50:17.142] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:50:47.619] INFO: Resuming triggers.
[14:50:53.937] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[14:51:24.101] INFO: Resuming triggers.
[14:51:30.414] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:52:00.337] INFO: Resuming triggers.
[14:52:06.650] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[14:52:36.799] INFO: Resuming triggers.
[14:52:43.115] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:53:13.225] INFO: Resuming triggers.
[14:53:19.544] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:53:49.715] INFO: Resuming triggers.
[14:53:56.030] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:54:26.211] INFO: Resuming triggers.
[14:54:31.857] INFO: data taking finished, elapsed time: 100 seconds.
[14:54:59.382] INFO: PixTest:: pg_setup set to default.
[14:54:59.385] INFO: PixTestXray::doPhRun() done
[14:54:59.535] INFO: enter test to run
[14:55:17.826] INFO: test: HighRate no parameter change
[14:55:17.826] INFO: running: highrate
[14:55:17.841] INFO: ----------------------------------------------------------------------
[14:55:17.841] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:55:17.841] INFO: ----------------------------------------------------------------------
[14:55:17.996] INFO: Expecting 768 events.
[14:55:19.130] INFO: 768 events read in total (418ms).
[14:55:19.130] INFO: Test took 1268ms.
[14:55:19.933] INFO: Expecting 41600 events.
[14:55:22.929] INFO: 41600 events read in total (2469ms).
[14:55:22.930] INFO: Test took 3792ms.
[14:55:22.964] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:23.695] INFO: Expecting 41600 events.
[14:55:26.841] INFO: 41600 events read in total (2619ms).
[14:55:26.842] INFO: Test took 3860ms.
[14:55:26.877] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:27.599] INFO: Expecting 41600 events.
[14:55:30.828] INFO: 41600 events read in total (2702ms).
[14:55:30.829] INFO: Test took 3933ms.
[14:55:30.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:31.584] INFO: Expecting 41600 events.
[14:55:34.839] INFO: 41600 events read in total (2728ms).
[14:55:34.840] INFO: Test took 3956ms.
[14:55:34.876] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:35.598] INFO: Expecting 41600 events.
[14:55:38.847] INFO: 41600 events read in total (2722ms).
[14:55:38.848] INFO: Test took 3952ms.
[14:55:38.884] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:39.607] INFO: Expecting 41600 events.
[14:55:42.875] INFO: 41600 events read in total (2742ms).
[14:55:42.876] INFO: Test took 3972ms.
[14:55:42.912] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:43.631] INFO: Expecting 41600 events.
[14:55:46.886] INFO: 41600 events read in total (2729ms).
[14:55:46.887] INFO: Test took 3955ms.
[14:55:46.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:47.644] INFO: Expecting 41600 events.
[14:55:50.896] INFO: 41600 events read in total (2725ms).
[14:55:50.897] INFO: Test took 3956ms.
[14:55:50.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:51.655] INFO: Expecting 41600 events.
[14:55:54.925] INFO: 41600 events read in total (2743ms).
[14:55:54.926] INFO: Test took 3973ms.
[14:55:54.962] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:55.683] INFO: Expecting 41600 events.
[14:55:58.936] INFO: 41600 events read in total (2726ms).
[14:55:58.937] INFO: Test took 3957ms.
[14:55:58.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:59.696] INFO: Expecting 41600 events.
[14:56:02.957] INFO: 41600 events read in total (2735ms).
[14:56:02.958] INFO: Test took 3967ms.
[14:56:02.994] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:03.716] INFO: Expecting 41600 events.
[14:56:06.975] INFO: 41600 events read in total (2732ms).
[14:56:06.976] INFO: Test took 3963ms.
[14:56:07.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:07.734] INFO: Expecting 41600 events.
[14:56:10.992] INFO: 41600 events read in total (2731ms).
[14:56:10.993] INFO: Test took 3962ms.
[14:56:11.029] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:11.749] INFO: Expecting 41600 events.
[14:56:14.004] INFO: 41600 events read in total (2728ms).
[14:56:14.005] INFO: Test took 3957ms.
[14:56:15.042] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:15.763] INFO: Expecting 41600 events.
[14:56:19.019] INFO: 41600 events read in total (2729ms).
[14:56:19.020] INFO: Test took 3958ms.
[14:56:19.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:19.773] INFO: Expecting 41600 events.
[14:56:23.016] INFO: 41600 events read in total (2716ms).
[14:56:23.017] INFO: Test took 3943ms.
[14:56:23.053] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:23.770] INFO: Expecting 41600 events.
[14:56:27.061] INFO: 41600 events read in total (2765ms).
[14:56:27.062] INFO: Test took 3990ms.
[14:56:27.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:27.818] INFO: Expecting 41600 events.
[14:56:31.083] INFO: 41600 events read in total (2739ms).
[14:56:31.084] INFO: Test took 3967ms.
[14:56:31.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:31.841] INFO: Expecting 41600 events.
[14:56:35.112] INFO: 41600 events read in total (2744ms).
[14:56:35.113] INFO: Test took 3974ms.
[14:56:35.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:35.866] INFO: Expecting 41600 events.
[14:56:39.035] INFO: 41600 events read in total (2642ms).
[14:56:39.036] INFO: Test took 3870ms.
[14:56:39.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:39.423] INFO: enter test to run
[14:57:35.425] INFO: test: HighRate no parameter change
[14:57:35.425] INFO: running: highrate
[14:57:35.426] INFO: ----------------------------------------------------------------------
[14:57:35.426] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:57:35.426] INFO: ----------------------------------------------------------------------
[14:57:36.042] INFO: Expecting 208000 events.
[14:57:48.035] INFO: 208000 events read in total (11466ms).
[14:57:48.039] INFO: Test took 12604ms.
[14:57:48.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:48.449] INFO: number of dead pixels (per ROC): 0 0 1 0 1 0 0 0 0 0 0 0 0 0 0 0
[14:57:48.449] INFO: number of red-efficiency pixels: 81 53 98 143 151 191 155 108 96 127 128 111 103 61 22 31
[14:57:48.449] INFO: number of X-ray hits detected: 75296 48909 74034 119353 123599 124911 120261 85056 76914 101502 99997 88629 93652 56865 23340 27137
[14:57:48.449] 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:57:48.449] INFO: number of Vcal hits detected: 207917 207945 207847 207854 207798 207799 207842 207892 207898 207870 207869 207888 207895 207937 207978 207969
[14:57:48.449] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[14:57:48.449] INFO: Vcal hit overall efficiency (%): 100.0 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:57:48.449] INFO: X-ray hit rate [MHz/cm2]: 22.1 14.3 21.7 35.0 36.2 36.6 35.2 24.9 22.5 29.8 29.3 26.0 27.5 16.7 6.8 8.0
[14:57:48.449] INFO: PixTestHighRate::doXPixelAlive() done
[14:57:48.502] INFO: PixTest:: pg_setup set to default.
[14:57:48.519] INFO: enter test to run
[14:58:04.025] INFO: test: HighRate no parameter change
[14:58:04.025] INFO: running: highrate
[14:58:04.026] INFO: ----------------------------------------------------------------------
[14:58:04.026] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:58:04.026] INFO: ----------------------------------------------------------------------
[14:58:04.641] INFO: Expecting 208000 events.
[14:58:18.636] INFO: 208000 events read in total (13468ms).
[14:58:18.642] INFO: Test took 14605ms.
[14:58:18.970] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:19.281] INFO: number of dead pixels (per ROC): 0 0 1 0 1 0 0 0 0 0 0 0 0 0 0 0
[14:58:19.281] INFO: number of red-efficiency pixels: 279 167 400 524 526 753 492 318 307 487 404 387 444 206 67 67
[14:58:19.281] INFO: number of X-ray hits detected: 160671 104972 159269 254775 263641 267421 258523 183331 163686 216302 213922 191011 201088 122672 50355 58992
[14:58:19.281] 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:58:19.281] INFO: number of Vcal hits detected: 207690 207823 207488 207415 207366 207123 207469 207668 207674 207468 207563 207580 207518 207774 207933 207931
[14:58:19.281] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.6 99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:58:19.282] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.6 99.7 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[14:58:19.282] INFO: X-ray hit rate [MHz/cm2]: 47.1 30.8 46.7 74.7 77.3 78.4 75.8 53.7 48.0 63.4 62.7 56.0 58.9 36.0 14.8 17.3
[14:58:19.282] INFO: PixTestHighRate::doXPixelAlive() done
[14:58:19.336] INFO: PixTest:: pg_setup set to default.
[14:58:19.350] INFO: enter test to run
[14:58:26.025] INFO: test: HighRate no parameter change
[14:58:26.025] INFO: running: highrate
[14:58:26.026] INFO: ----------------------------------------------------------------------
[14:58:26.026] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:58:26.026] INFO: ----------------------------------------------------------------------
[14:58:26.635] INFO: Expecting 208000 events.
[14:58:42.669] INFO: 208000 events read in total (15507ms).
[14:58:42.677] INFO: Test took 16645ms.
[14:58:43.180] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:43.542] INFO: number of dead pixels (per ROC): 0 0 1 0 1 0 0 0 0 0 0 0 0 0 0 0
[14:58:43.542] INFO: number of red-efficiency pixels: 580 302 896 1264 1214 1726 1202 724 622 1155 872 924 900 463 84 105
[14:58:43.542] INFO: number of X-ray hits detected: 239815 156603 237110 380556 391523 398138 384127 271029 246836 321977 317885 282829 297801 181818 74680 87337
[14:58:43.542] 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:58:43.542] INFO: number of Vcal hits detected: 207297 207664 206632 206339 206375 205467 206443 207073 207279 206544 206921 206857 206932 207460 207912 207893
[14:58:43.542] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.4 99.3 99.3 98.9 99.3 99.6 99.7 99.4 99.5 99.5 99.5 99.8 100.0 99.9
[14:58:43.542] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.3 99.2 99.2 98.8 99.3 99.6 99.7 99.3 99.5 99.5 99.5 99.7 100.0 99.9
[14:58:43.542] INFO: X-ray hit rate [MHz/cm2]: 70.3 45.9 69.5 111.5 114.8 116.7 112.6 79.4 72.3 94.4 93.2 82.9 87.3 53.3 21.9 25.6
[14:58:43.542] INFO: PixTestHighRate::doXPixelAlive() done
[14:58:43.591] INFO: PixTest:: pg_setup set to default.
[14:58:43.605] INFO: enter test to run
[14:58:51.184] INFO: test: exit no parameter change
[14:58:51.550] QUIET: Connection to board 32 closed.
[14:58:51.587] INFO: pXar: this is the end, my friend