[18:25:11.226] INFO: *** Welcome to pxar ***
[18:25:11.226] INFO: *** Today: 2016/06/01
[18:25:11.245] INFO: *** Version: v1.9.0-796-gef167-dirty
[18:25:11.246] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//dacParameters35_C15.dat
[18:25:11.249] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//tbmParameters_C0b.dat
[18:25:11.249] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//defaultMaskFile.dat
[18:25:11.249] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C15.dat
[18:25:11.354] INFO: clk: 4
[18:25:11.354] INFO: ctr: 4
[18:25:11.354] INFO: sda: 19
[18:25:11.354] INFO: tin: 9
[18:25:11.354] INFO: level: 15
[18:25:11.354] INFO: triggerdelay: 0
[18:25:11.354] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[18:25:11.354] INFO: Log level: INFO
[18:25:11.371] QUIET: Connection to board DTB_WREK4U opened.
[18:25:11.375] 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:
------------------------------------------------------
[18:25:11.378] INFO: RPC call hashes of host and DTB match: 398089610
[18:25:12.909] INFO: DUT info:
[18:25:12.909] INFO: The DUT currently contains the following objects:
[18:25:12.909] INFO: 2 TBM Cores tbm08c (2 ON)
[18:25:12.909] INFO: TBM Core alpha (0): 7 registers set
[18:25:12.909] INFO: TBM Core beta (1): 7 registers set
[18:25:12.909] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[18:25:12.909] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:12.909] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:25:13.319] INFO: enter 'restricted' command line mode
[18:25:13.319] INFO: enter test to run
[18:25:17.641] INFO: test: PixelAlive no parameter change
[18:25:17.642] INFO: running: pixelalive
[18:25:17.651] INFO: ----------------------------------------------------------------------
[18:25:17.651] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:25:17.651] INFO: ----------------------------------------------------------------------
[18:25:17.977] INFO: Expecting 41600 events.
[18:25:22.256] INFO: 41600 events read in total (3561ms).
[18:25:22.422] INFO: Test took 4767ms.
[18:25:22.436] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:25:22.696] INFO: PixTestAlive::aliveTest() done
[18:25:22.696] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0
[18:25:22.725] INFO: enter test to run
[18:25:37.217] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[18:25:37.217] INFO: running: highrate
[18:25:37.217] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[18:25:37.458] INFO: ----------------------------------------------------------------------
[18:25:37.458] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[18:25:37.458] INFO: ----------------------------------------------------------------------
[18:25:37.458] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[18:25:37.458] INFO: edge/corner pixel THR is adjusted
[18:25:37.458] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:25:38.417] INFO: Collecting data for 5 seconds...
[18:25:43.434] INFO: Done with hot pixel readout
[18:25:55.048] INFO: PixTest:: pg_setup set to default.
[18:25:55.049] INFO: 11 hot pixels found in step 0
[18:25:56.039] INFO: Collecting data for 5 seconds...
[18:26:01.055] INFO: Done with hot pixel readout
[18:26:12.644] INFO: PixTest:: pg_setup set to default.
[18:26:12.645] INFO: 8 hot pixels found in step 1
[18:26:13.636] INFO: Collecting data for 5 seconds...
[18:26:18.652] INFO: Done with hot pixel readout
[18:26:30.251] INFO: PixTest:: pg_setup set to default.
[18:26:30.252] INFO: 11 hot pixels found in step 2
[18:26:31.242] INFO: Collecting data for 5 seconds...
[18:26:36.258] INFO: Done with hot pixel readout
[18:26:47.871] INFO: PixTest:: pg_setup set to default.
[18:26:47.872] INFO: 11 hot pixels found in step 3
[18:26:48.862] INFO: Collecting data for 5 seconds...
[18:26:53.878] INFO: Done with hot pixel readout
[18:27:05.521] INFO: PixTest:: pg_setup set to default.
[18:27:05.522] INFO: 10 hot pixels found in step 4
[18:27:06.513] INFO: Collecting data for 5 seconds...
[18:27:11.529] INFO: Done with hot pixel readout
[18:27:23.207] INFO: PixTest:: pg_setup set to default.

[18:27:23.208] INFO: 8 hot pixels found in step 5
[18:27:24.199] INFO: Collecting data for 5 seconds...
[18:27:29.216] INFO: Done with hot pixel readout
[18:27:40.779] INFO: PixTest:: pg_setup set to default.
[18:27:40.780] INFO: 7 hot pixels found in step 6
[18:27:41.772] INFO: Collecting data for 5 seconds...
[18:27:46.789] INFO: Done with hot pixel readout
[18:27:58.350] INFO: PixTest:: pg_setup set to default.
[18:27:58.351] INFO: 6 hot pixels found in step 7
[18:27:59.341] INFO: Collecting data for 5 seconds...
[18:28:04.359] INFO: Done with hot pixel readout
[18:28:15.984] INFO: PixTest:: pg_setup set to default.
[18:28:15.985] INFO: 3 hot pixels found in step 8
[18:28:16.976] INFO: Collecting data for 5 seconds...
[18:28:21.993] INFO: Done with hot pixel readout
[18:28:33.404] INFO: PixTest:: pg_setup set to default.
[18:28:33.405] INFO: 3 hot pixels found in step 9
[18:28:34.395] INFO: Collecting data for 5 seconds...
[18:28:39.411] INFO: Done with hot pixel readout
[18:28:51.043] INFO: PixTest:: pg_setup set to default.
[18:28:51.044] INFO: 1 hot pixels found in step 10
[18:28:52.035] INFO: Collecting data for 5 seconds...
[18:28:57.051] INFO: Done with hot pixel readout
[18:29:08.634] INFO: PixTest:: pg_setup set to default.
[18:29:08.635] INFO: 2 hot pixels found in step 11
[18:29:09.625] INFO: Collecting data for 5 seconds...
[18:29:14.641] INFO: Done with hot pixel readout
[18:29:26.262] INFO: PixTest:: pg_setup set to default.
[18:29:26.263] INFO: 2 hot pixels found in step 12
[18:29:27.254] INFO: Collecting data for 5 seconds...
[18:29:32.269] INFO: Done with hot pixel readout
[18:29:43.878] INFO: PixTest:: pg_setup set to default.
[18:29:43.879] INFO: 4 hot pixels found in step 13
[18:29:44.870] INFO: Collecting data for 5 seconds...
[18:29:49.886] INFO: Done with hot pixel readout
[18:30:01.509] INFO: PixTest:: pg_setup set to default.
[18:30:01.510] INFO: 4 hot pixels found in step 14
[18:30:01.544] INFO: 4 hot pixels could not be trimmed and have been masked.
[18:30:01.548] INFO: PixTest::trimHotPixels() done
[18:30:01.548] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C0.dat
[18:30:01.554] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C1.dat
[18:30:01.559] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C2.dat
[18:30:01.564] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C3.dat
[18:30:01.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C4.dat
[18:30:01.575] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C5.dat
[18:30:01.580] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C6.dat
[18:30:01.585] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C7.dat
[18:30:01.591] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C8.dat
[18:30:01.596] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C9.dat
[18:30:01.601] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C10.dat
[18:30:01.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C11.dat
[18:30:01.611] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C12.dat
[18:30:01.616] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C13.dat
[18:30:01.622] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C14.dat
[18:30:01.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C15.dat
[18:30:01.632] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//defaultMaskFile.dat
[18:30:01.642] INFO: enter test to run
[18:30:24.943] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[18:30:24.943] INFO: running: highrate
[18:30:24.948] INFO: ----------------------------------------------------------------------
[18:30:24.948] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[18:30:24.948] INFO: ----------------------------------------------------------------------
[18:30:24.948] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[18:30:24.948] INFO: edge/corner pixel THR is adjusted
[18:30:24.948] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:30:25.906] INFO: Collecting data for 1 seconds...
[18:30:26.910] INFO: Done with hot pixel readout
[18:30:30.748] INFO: PixTest:: pg_setup set to default.
[18:30:30.749] INFO: 0 hot pixels found in step 0
[18:30:30.754] INFO: 0 hot pixels could not be trimmed and have been masked.
[18:30:30.850] INFO: PixTest::trimHotPixels() done
[18:30:30.851] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C0.dat
[18:30:30.862] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C1.dat
[18:30:30.867] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C2.dat
[18:30:30.872] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C3.dat
[18:30:30.877] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C4.dat
[18:30:30.883] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C5.dat
[18:30:30.888] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C6.dat
[18:30:30.893] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C7.dat
[18:30:30.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C8.dat
[18:30:30.903] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C9.dat
[18:30:30.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C10.dat
[18:30:30.914] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C11.dat
[18:30:30.919] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C12.dat
[18:30:30.924] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C13.dat
[18:30:30.929] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C14.dat
[18:30:30.934] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//trimParameters35_C15.dat
[18:30:30.940] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-08_FPIXTest-17C-FNAL-160527-0907_2016-05-27_09h08m_1464358099/000_FPIXTest_p17//defaultMaskFile.dat
[18:30:30.950] INFO: enter test to run
[18:30:45.951] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[18:30:45.951] INFO: running: xray
[18:30:45.952] INFO: ----------------------------------------------------------------------
[18:30:45.952] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:30:45.952] INFO: ----------------------------------------------------------------------
[18:30:46.916] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:30:58.622] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[18:31:27.779] INFO: Resuming triggers.
[18:31:39.483] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[18:32:08.776] INFO: Resuming triggers.
[18:32:20.483] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[18:32:49.263] INFO: Resuming triggers.
[18:33:00.971] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[18:33:30.233] INFO: Resuming triggers.
[18:33:41.943] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[18:34:11.264] INFO: Resuming triggers.
[18:34:22.970] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[18:34:52.507] INFO: Resuming triggers.
[18:35:04.216] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[18:35:33.432] INFO: Resuming triggers.
[18:35:45.142] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[18:36:14.420] INFO: Resuming triggers.
[18:36:21.089] INFO: data taking finished, elapsed time: 100 seconds.
[18:36:37.810] INFO: PixTest:: pg_setup set to default.
[18:36:37.814] INFO: PixTestXray::doPhRun() done
[18:36:37.949] INFO: enter test to run
[18:37:04.780] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[18:37:04.780] INFO: running: xray
[18:37:04.781] INFO: ----------------------------------------------------------------------
[18:37:04.781] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:37:04.781] INFO: ----------------------------------------------------------------------
[18:37:05.751] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:37:12.749] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[18:37:42.866] INFO: Resuming triggers.
[18:37:49.865] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[18:38:19.865] INFO: Resuming triggers.
[18:38:26.861] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[18:38:56.884] INFO: Resuming triggers.
[18:39:03.882] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[18:39:33.847] INFO: Resuming triggers.
[18:39:40.845] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[18:40:10.326] INFO: Resuming triggers.
[18:40:17.327] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[18:40:47.121] INFO: Resuming triggers.
[18:40:54.123] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[18:41:24.183] INFO: Resuming triggers.
[18:41:31.181] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[18:42:01.190] INFO: Resuming triggers.
[18:42:08.186] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[18:42:38.592] INFO: Resuming triggers.
[18:42:45.594] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[18:43:15.556] INFO: Resuming triggers.
[18:43:22.560] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[18:43:52.573] INFO: Resuming triggers.
[18:43:59.574] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[18:44:29.571] INFO: Resuming triggers.
[18:44:36.573] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[18:45:06.401] INFO: Resuming triggers.
[18:45:13.402] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[18:45:43.493] INFO: Resuming triggers.
[18:45:45.820] INFO: data taking finished, elapsed time: 100 seconds.
[18:45:56.285] INFO: PixTest:: pg_setup set to default.
[18:45:56.288] INFO: PixTestXray::doPhRun() done
[18:45:56.441] INFO: enter test to run
[18:47:16.704] INFO: test: HighRate no parameter change
[18:47:16.704] INFO: running: highrate
[18:47:16.705] INFO: ----------------------------------------------------------------------
[18:47:16.705] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[18:47:16.705] INFO: ----------------------------------------------------------------------
[18:47:16.847] INFO: Expecting 768 events.
[18:47:17.981] INFO: 768 events read in total (419ms).
[18:47:17.981] INFO: Test took 1268ms.
[18:47:18.784] INFO: Expecting 41600 events.
[18:47:21.818] INFO: 41600 events read in total (2507ms).
[18:47:21.819] INFO: Test took 3828ms.
[18:47:21.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:22.585] INFO: Expecting 41600 events.
[18:47:25.746] INFO: 41600 events read in total (2635ms).
[18:47:25.747] INFO: Test took 3881ms.
[18:47:25.778] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:26.508] INFO: Expecting 41600 events.
[18:47:29.703] INFO: 41600 events read in total (2668ms).
[18:47:29.704] INFO: Test took 3910ms.
[18:47:29.736] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:30.464] INFO: Expecting 41600 events.
[18:47:33.668] INFO: 41600 events read in total (2677ms).
[18:47:33.669] INFO: Test took 3915ms.
[18:47:33.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:34.432] INFO: Expecting 41600 events.
[18:47:37.636] INFO: 41600 events read in total (2677ms).
[18:47:37.637] INFO: Test took 3920ms.
[18:47:37.670] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:38.396] INFO: Expecting 41600 events.
[18:47:41.492] INFO: 41600 events read in total (2569ms).
[18:47:41.493] INFO: Test took 3806ms.
[18:47:41.524] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:42.254] INFO: Expecting 41600 events.
[18:47:45.425] INFO: 41600 events read in total (2644ms).
[18:47:45.426] INFO: Test took 3884ms.
[18:47:45.457] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:46.187] INFO: Expecting 41600 events.
[18:47:49.395] INFO: 41600 events read in total (2681ms).
[18:47:49.396] INFO: Test took 3921ms.
[18:47:49.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:50.153] INFO: Expecting 41600 events.
[18:47:53.356] INFO: 41600 events read in total (2676ms).
[18:47:53.357] INFO: Test took 3914ms.
[18:47:53.388] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:54.114] INFO: Expecting 41600 events.
[18:47:57.318] INFO: 41600 events read in total (2678ms).
[18:47:57.319] INFO: Test took 3914ms.
[18:47:57.350] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:58.079] INFO: Expecting 41600 events.
[18:48:01.293] INFO: 41600 events read in total (2687ms).
[18:48:01.294] INFO: Test took 3926ms.
[18:48:01.325] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:02.056] INFO: Expecting 41600 events.
[18:48:05.273] INFO: 41600 events read in total (2690ms).
[18:48:05.274] INFO: Test took 3933ms.
[18:48:05.304] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:06.034] INFO: Expecting 41600 events.
[18:48:09.246] INFO: 41600 events read in total (2686ms).
[18:48:09.247] INFO: Test took 3925ms.
[18:48:09.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:10.008] INFO: Expecting 41600 events.
[18:48:13.218] INFO: 41600 events read in total (2683ms).
[18:48:13.219] INFO: Test took 3924ms.
[18:48:13.251] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:13.981] INFO: Expecting 41600 events.
[18:48:17.213] INFO: 41600 events read in total (2705ms).
[18:48:17.214] INFO: Test took 3946ms.
[18:48:17.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:17.975] INFO: Expecting 41600 events.
[18:48:21.199] INFO: 41600 events read in total (2697ms).
[18:48:21.200] INFO: Test took 3935ms.
[18:48:21.232] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:21.961] INFO: Expecting 41600 events.
[18:48:25.171] INFO: 41600 events read in total (2683ms).
[18:48:25.172] INFO: Test took 3923ms.
[18:48:25.204] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:25.933] INFO: Expecting 41600 events.
[18:48:29.144] INFO: 41600 events read in total (2684ms).
[18:48:29.144] INFO: Test took 3921ms.
[18:48:29.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:29.906] INFO: Expecting 41600 events.
[18:48:33.123] INFO: 41600 events read in total (2690ms).
[18:48:33.124] INFO: Test took 3931ms.
[18:48:33.154] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:33.880] INFO: Expecting 41600 events.
[18:48:36.999] INFO: 41600 events read in total (2592ms).
[18:48:36.000] INFO: Test took 3829ms.
[18:48:37.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:37.390] INFO: enter test to run
[18:49:25.359] INFO: test: HighRate no parameter change
[18:49:25.359] INFO: running: highrate
[18:49:25.360] INFO: ----------------------------------------------------------------------
[18:49:25.360] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:49:25.360] INFO: ----------------------------------------------------------------------
[18:49:25.978] INFO: Expecting 208000 events.
[18:49:37.716] INFO: 208000 events read in total (11211ms).
[18:49:37.719] INFO: Test took 12349ms.
[18:49:37.850] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:49:38.099] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0
[18:49:38.099] INFO: number of red-efficiency pixels: 55 48 65 106 161 152 109 104 88 103 100 66 83 69 24 21
[18:49:38.099] INFO: number of X-ray hits detected: 59185 40097 56755 99955 104864 114270 110579 82749 68552 88686 82791 67299 69439 42616 17878 22030
[18:49:38.099] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:49:38.099] INFO: number of Vcal hits detected: 207941 207951 207935 207893 207836 207842 207889 207895 207911 207896 207851 207934 207916 207918 207976 207978
[18:49:38.099] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[18:49:38.099] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[18:49:38.099] INFO: X-ray hit rate [MHz/cm2]: 17.3 11.8 16.6 29.3 30.7 33.5 32.4 24.3 20.1 26.0 24.3 19.7 20.4 12.5 5.2 6.5
[18:49:38.099] INFO: PixTestHighRate::doXPixelAlive() done
[18:49:38.149] INFO: PixTest:: pg_setup set to default.
[18:49:38.161] INFO: enter test to run
[18:49:57.679] INFO: test: HighRate no parameter change
[18:49:57.679] INFO: running: highrate
[18:49:57.680] INFO: ----------------------------------------------------------------------
[18:49:57.680] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:49:57.680] INFO: ----------------------------------------------------------------------
[18:49:58.296] INFO: Expecting 208000 events.
[18:50:11.296] INFO: 208000 events read in total (12473ms).
[18:50:11.301] INFO: Test took 13613ms.
[18:50:11.572] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:11.864] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0
[18:50:11.864] INFO: number of red-efficiency pixels: 161 120 215 307 485 541 407 296 235 357 286 170 228 113 42 52
[18:50:11.864] INFO: number of X-ray hits detected: 125929 84730 119766 212498 222390 239481 233439 173697 145698 186811 174374 142619 146925 90413 38649 46886
[18:50:11.864] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:50:11.864] INFO: number of Vcal hits detected: 207834 207876 207766 207670 207483 207394 207554 207682 207754 207623 207643 207825 207767 207864 207958 207947
[18:50:11.864] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.7 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[18:50:11.864] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[18:50:11.864] INFO: X-ray hit rate [MHz/cm2]: 36.9 24.8 35.1 62.3 65.2 70.2 68.4 50.9 42.7 54.8 51.1 41.8 43.1 26.5 11.3 13.7
[18:50:11.864] INFO: PixTestHighRate::doXPixelAlive() done
[18:50:11.917] INFO: PixTest:: pg_setup set to default.
[18:50:11.929] INFO: enter test to run
[18:50:59.486] INFO: test: HighRate no parameter change
[18:50:59.486] INFO: running: highrate
[18:50:59.487] INFO: ----------------------------------------------------------------------
[18:50:59.487] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:50:59.487] INFO: ----------------------------------------------------------------------
[18:51:00.107] INFO: Expecting 208000 events.
[18:51:15.177] INFO: 208000 events read in total (14543ms).
[18:51:15.184] INFO: Test took 15687ms.
[18:51:15.592] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:15.926] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0
[18:51:15.926] INFO: number of red-efficiency pixels: 333 188 455 733 1186 1335 930 670 494 818 678 356 491 230 61 74
[18:51:15.926] INFO: number of X-ray hits detected: 190137 128304 181999 320335 335208 362266 354046 264031 221433 284673 264209 216941 222456 137549 58785 70986
[18:51:15.926] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:51:15.926] INFO: number of Vcal hits detected: 207632 207799 207442 207175 206552 206272 206852 207153 207445 207059 207166 207617 207474 207738 207939 207923
[18:51:15.926] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.4 99.2 99.5 99.6 99.8 99.6 99.7 99.8 99.8 99.9 100.0 100.0
[18:51:15.927] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.6 99.3 99.2 99.4 99.6 99.7 99.5 99.6 99.8 99.7 99.9 100.0 100.0
[18:51:15.927] INFO: X-ray hit rate [MHz/cm2]: 55.7 37.6 53.3 93.9 98.3 106.2 103.8 77.4 64.9 83.4 77.4 63.6 65.2 40.3 17.2 20.8
[18:51:15.927] INFO: PixTestHighRate::doXPixelAlive() done
[18:51:15.981] INFO: PixTest:: pg_setup set to default.
[18:51:15.997] INFO: enter test to run
[18:51:19.838] INFO: test: exit no parameter change
[18:51:20.183] QUIET: Connection to board 32 closed.
[18:51:20.184] INFO: pXar: this is the end, my friend