[14:38:11.421] INFO: *** Welcome to pxar ***
[14:38:11.421] INFO: *** Today: 2016/04/11
[14:38:11.438] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:38:11.438] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//dacParameters35_C15.dat
[14:38:11.471] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:38:11.472] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//defaultMaskFile.dat
[14:38:11.476] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C15.dat
[14:38:11.607] INFO: clk: 4
[14:38:11.607] INFO: ctr: 4
[14:38:11.607] INFO: sda: 19
[14:38:11.607] INFO: tin: 9
[14:38:11.607] INFO: level: 15
[14:38:11.607] INFO: triggerdelay: 0
[14:38:11.607] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:38:11.607] INFO: Log level: INFO
[14:38:11.624] QUIET: Connection to board DTB_WREKRL opened.
[14:38:11.628] 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:38:11.630] INFO: RPC call hashes of host and DTB match: 398089610
[14:38:13.161] INFO: DUT info:
[14:38:13.161] INFO: The DUT currently contains the following objects:
[14:38:13.161] INFO: 2 TBM Cores tbm08c (2 ON)
[14:38:13.161] INFO: TBM Core alpha (0): 7 registers set
[14:38:13.161] INFO: TBM Core beta (1): 7 registers set
[14:38:13.161] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:38:13.161] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.161] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.162] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.162] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.162] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.162] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:38:13.565] INFO: enter 'restricted' command line mode
[14:38:13.565] INFO: enter test to run
[14:38:18.559] INFO: test: PixelAlive no parameter change
[14:38:18.559] INFO: running: pixelalive
[14:38:18.566] INFO: ----------------------------------------------------------------------
[14:38:18.566] 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:38:18.566] INFO: ----------------------------------------------------------------------
[14:38:18.886] INFO: Expecting 41600 events.
[14:38:22.846] INFO: 41600 events read in total (3242ms).
[14:38:23.018] INFO: Test took 4450ms.
[14:38:23.025] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:23.287] INFO: PixTestAlive::aliveTest() done
[14:38:23.287] INFO: number of dead pixels (per ROC): 0 0 0 0 0 4 7 0 4 0 0 0 0 0 0 0
[14:38:23.313] INFO: enter test to run
[14:39:48.470] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:39:48.470] INFO: running: highrate
[14:39:48.471] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:39:48.702] INFO: ----------------------------------------------------------------------
[14:39:48.702] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:39:48.702] INFO: ----------------------------------------------------------------------
[14:39:48.702] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:39:48.702] INFO: edge/corner pixel THR is adjusted
[14:39:48.702] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:39:49.661] INFO: Collecting data for 5 seconds...
[14:39:54.677] INFO: Done with hot pixel readout
[14:40:06.769] INFO: PixTest:: pg_setup set to default.
[14:40:06.770] INFO: 3 hot pixels found in step 0
[14:40:07.764] INFO: Collecting data for 5 seconds...
[14:40:12.780] INFO: Done with hot pixel readout
[14:40:24.906] INFO: PixTest:: pg_setup set to default.
[14:40:24.907] INFO: 5 hot pixels found in step 1
[14:40:25.904] INFO: Collecting data for 5 seconds...
[14:40:30.920] INFO: Done with hot pixel readout
[14:40:43.037] INFO: PixTest:: pg_setup set to default.
[14:40:43.038] INFO: 3 hot pixels found in step 2
[14:40:44.033] INFO: Collecting data for 5 seconds...
[14:40:49.049] INFO: Done with hot pixel readout
[14:41:01.206] INFO: PixTest:: pg_setup set to default.
[14:41:01.206] INFO: 6 hot pixels found in step 3
[14:41:02.202] INFO: Collecting data for 5 seconds...
[14:41:07.219] INFO: Done with hot pixel readout
[14:41:19.398] INFO: PixTest:: pg_setup set to default.
[14:41:19.399] INFO: 5 hot pixels found in step 4
[14:41:20.393] INFO: Collecting data for 5 seconds...
[14:41:25.409] INFO: Done with hot pixel readout
[14:41:37.566] INFO: PixTest:: pg_setup set to default.
[14:41:37.567] INFO: 2 hot pixels found in step 5
[14:41:38.563] INFO: Collecting data for 5 seconds...
[14:41:43.579] INFO: Done with hot pixel readout
[14:41:55.554] INFO: PixTest:: pg_setup set to default.
[14:41:55.555] INFO: 3 hot pixels found in step 6
[14:41:56.551] INFO: Collecting data for 5 seconds...
[14:42:01.567] INFO: Done with hot pixel readout
[14:42:13.671] INFO: PixTest:: pg_setup set to default.
[14:42:13.672] INFO: 4 hot pixels found in step 7
[14:42:14.667] INFO: Collecting data for 5 seconds...
[14:42:19.683] INFO: Done with hot pixel readout
[14:42:31.851] INFO: PixTest:: pg_setup set to default.
[14:42:31.852] INFO: 2 hot pixels found in step 8
[14:42:32.847] INFO: Collecting data for 5 seconds...
[14:42:37.864] INFO: Done with hot pixel readout
[14:42:50.034] INFO: PixTest:: pg_setup set to default.
[14:42:50.035] INFO: 5 hot pixels found in step 9
[14:42:51.030] INFO: Collecting data for 5 seconds...
[14:42:56.045] INFO: Done with hot pixel readout
[14:43:08.175] INFO: PixTest:: pg_setup set to default.
[14:43:08.176] INFO: 4 hot pixels found in step 10
[14:43:09.171] INFO: Collecting data for 5 seconds...
[14:43:14.188] INFO: Done with hot pixel readout
[14:43:26.331] INFO: PixTest:: pg_setup set to default.

[14:43:26.332] INFO: 6 hot pixels found in step 11
[14:43:27.328] INFO: Collecting data for 5 seconds...
[14:43:32.344] INFO: Done with hot pixel readout
[14:43:44.466] INFO: PixTest:: pg_setup set to default.
[14:43:44.467] INFO: 4 hot pixels found in step 12
[14:43:45.463] INFO: Collecting data for 5 seconds...
[14:43:50.479] INFO: Done with hot pixel readout
[14:44:02.616] INFO: PixTest:: pg_setup set to default.
[14:44:02.617] INFO: 3 hot pixels found in step 13
[14:44:03.613] INFO: Collecting data for 5 seconds...
[14:44:08.629] INFO: Done with hot pixel readout
[14:44:20.767] INFO: PixTest:: pg_setup set to default.
[14:44:20.768] INFO: 2 hot pixels found in step 14
[14:44:20.807] INFO: 2 hot pixels could not be trimmed and have been masked.
[14:44:20.810] INFO: PixTest::trimHotPixels() done
[14:44:20.811] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C0.dat
[14:44:20.816] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C1.dat
[14:44:20.823] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C2.dat
[14:44:20.828] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C3.dat
[14:44:20.834] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C4.dat
[14:44:20.839] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C5.dat
[14:44:20.844] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C6.dat
[14:44:20.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C7.dat
[14:44:20.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C8.dat
[14:44:20.860] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C9.dat
[14:44:20.865] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C10.dat
[14:44:20.870] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C11.dat
[14:44:20.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C12.dat
[14:44:20.881] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C13.dat
[14:44:20.886] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C14.dat
[14:44:20.891] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C15.dat
[14:44:20.897] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//defaultMaskFile.dat
[14:44:20.907] INFO: enter test to run
[14:46:38.155] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:46:38.155] INFO: running: highrate
[14:46:38.160] INFO: ----------------------------------------------------------------------
[14:46:38.160] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:46:38.160] INFO: ----------------------------------------------------------------------
[14:46:38.160] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:46:38.160] INFO: edge/corner pixel THR is adjusted
[14:46:38.160] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:46:39.118] INFO: Collecting data for 1 seconds...
[14:46:40.121] INFO: Done with hot pixel readout
[14:46:44.381] INFO: PixTest:: pg_setup set to default.
[14:46:44.382] INFO: 0 hot pixels found in step 0
[14:46:44.387] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:46:44.468] INFO: PixTest::trimHotPixels() done
[14:46:44.468] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C0.dat
[14:46:44.491] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C1.dat
[14:46:44.502] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C2.dat
[14:46:44.508] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C3.dat
[14:46:44.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C4.dat
[14:46:44.518] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C5.dat
[14:46:44.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C6.dat
[14:46:44.529] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C7.dat
[14:46:44.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C8.dat
[14:46:44.540] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C9.dat
[14:46:44.545] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C10.dat
[14:46:44.550] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C11.dat
[14:46:44.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C12.dat
[14:46:44.561] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C13.dat
[14:46:44.566] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C14.dat
[14:46:44.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C15.dat
[14:46:44.577] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-23_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//defaultMaskFile.dat
[14:46:44.586] INFO: enter test to run
[14:47:20.483] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:47:20.483] INFO: running: xray
[14:47:20.484] INFO: ----------------------------------------------------------------------
[14:47:20.484] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:47:20.484] INFO: ----------------------------------------------------------------------
[14:47:21.447] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:47:32.471] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[14:48:01.975] INFO: Resuming triggers.
[14:48:12.004] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:48:40.212] INFO: Resuming triggers.
[14:48:51.240] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:49:20.741] INFO: Resuming triggers.
[14:49:31.771] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:50:01.319] INFO: Resuming triggers.
[14:50:12.343] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:50:41.849] INFO: Resuming triggers.
[14:50:52.879] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:51:21.651] INFO: Resuming triggers.
[14:51:32.676] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[14:52:02.110] INFO: Resuming triggers.
[14:52:13.137] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[14:52:42.615] INFO: Resuming triggers.
[14:52:53.643] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:53:23.196] INFO: Resuming triggers.
[14:53:24.270] INFO: data taking finished, elapsed time: 100 seconds.
[14:53:27.525] INFO: PixTest:: pg_setup set to default.
[14:53:27.528] INFO: PixTestXray::doPhRun() done
[14:53:27.668] INFO: enter test to run
[14:54:17.040] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:54:17.040] INFO: running: xray
[14:54:17.041] INFO: ----------------------------------------------------------------------
[14:54:17.041] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:54:17.041] INFO: ----------------------------------------------------------------------
[14:54:18.023] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:54:24.209] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:54:54.320] INFO: Resuming triggers.
[14:55:00.508] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:55:30.547] INFO: Resuming triggers.
[14:55:36.735] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[14:56:06.855] INFO: Resuming triggers.
[14:56:13.042] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[14:56:43.075] INFO: Resuming triggers.
[14:56:49.265] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[14:57:19.369] INFO: Resuming triggers.
[14:57:25.559] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[14:57:55.644] INFO: Resuming triggers.
[14:58:01.834] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:58:32.137] INFO: Resuming triggers.
[14:58:38.327] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:59:04.987] INFO: Resuming triggers.
[14:59:11.176] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:59:41.141] INFO: Resuming triggers.
[14:59:47.330] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[15:00:17.666] INFO: Resuming triggers.
[15:00:23.856] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:00:54.035] INFO: Resuming triggers.
[15:01:00.224] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[15:01:30.250] INFO: Resuming triggers.
[15:01:36.436] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:02:06.567] INFO: Resuming triggers.
[15:02:12.753] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[15:02:42.854] INFO: Resuming triggers.
[15:02:49.042] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:03:19.128] INFO: Resuming triggers.
[15:03:25.314] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[15:03:55.413] INFO: Resuming triggers.
[15:03:56.710] INFO: data taking finished, elapsed time: 100 seconds.
[15:04:03.347] INFO: PixTest:: pg_setup set to default.
[15:04:03.350] INFO: PixTestXray::doPhRun() done
[15:04:03.501] INFO: enter test to run
[15:06:37.707] INFO: test: HighRate no parameter change
[15:06:37.707] INFO: running: highrate
[15:06:37.708] INFO: ----------------------------------------------------------------------
[15:06:37.708] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:06:37.708] INFO: ----------------------------------------------------------------------
[15:06:37.848] INFO: Expecting 768 events.
[15:06:38.989] INFO: 768 events read in total (418ms).
[15:06:38.989] INFO: Test took 1275ms.
[15:06:39.792] INFO: Expecting 41600 events.
[15:06:42.868] INFO: 41600 events read in total (2549ms).
[15:06:42.869] INFO: Test took 3875ms.
[15:06:42.904] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:43.632] INFO: Expecting 41600 events.
[15:06:46.854] INFO: 41600 events read in total (2695ms).
[15:06:46.855] INFO: Test took 3933ms.
[15:06:46.891] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:47.613] INFO: Expecting 41600 events.
[15:06:50.865] INFO: 41600 events read in total (2725ms).
[15:06:50.866] INFO: Test took 3956ms.
[15:06:50.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:51.623] INFO: Expecting 41600 events.
[15:06:54.879] INFO: 41600 events read in total (2729ms).
[15:06:54.880] INFO: Test took 3959ms.
[15:06:54.917] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:55.633] INFO: Expecting 41600 events.
[15:06:58.903] INFO: 41600 events read in total (2743ms).
[15:06:58.904] INFO: Test took 3968ms.
[15:06:58.941] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:59.661] INFO: Expecting 41600 events.
[15:07:02.934] INFO: 41600 events read in total (2746ms).
[15:07:02.935] INFO: Test took 3976ms.
[15:07:02.971] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:03.690] INFO: Expecting 41600 events.
[15:07:06.954] INFO: 41600 events read in total (2737ms).
[15:07:06.955] INFO: Test took 3965ms.
[15:07:06.991] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:07.711] INFO: Expecting 41600 events.
[15:07:10.975] INFO: 41600 events read in total (2737ms).
[15:07:10.976] INFO: Test took 3966ms.
[15:07:11.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:11.734] INFO: Expecting 41600 events.
[15:07:15.009] INFO: 41600 events read in total (2749ms).
[15:07:15.010] INFO: Test took 3979ms.
[15:07:15.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:15.767] INFO: Expecting 41600 events.
[15:07:19.027] INFO: 41600 events read in total (2733ms).
[15:07:19.028] INFO: Test took 3964ms.
[15:07:19.065] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:19.785] INFO: Expecting 41600 events.
[15:07:23.049] INFO: 41600 events read in total (2738ms).
[15:07:23.050] INFO: Test took 3966ms.
[15:07:23.087] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:23.806] INFO: Expecting 41600 events.
[15:07:27.089] INFO: 41600 events read in total (2756ms).
[15:07:27.090] INFO: Test took 3985ms.
[15:07:27.127] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:27.844] INFO: Expecting 41600 events.
[15:07:31.108] INFO: 41600 events read in total (2737ms).
[15:07:31.109] INFO: Test took 3962ms.
[15:07:31.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:31.865] INFO: Expecting 41600 events.
[15:07:35.130] INFO: 41600 events read in total (2738ms).
[15:07:35.131] INFO: Test took 3966ms.
[15:07:35.168] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:35.886] INFO: Expecting 41600 events.
[15:07:39.165] INFO: 41600 events read in total (2752ms).
[15:07:39.166] INFO: Test took 3979ms.
[15:07:39.203] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:39.925] INFO: Expecting 41600 events.
[15:07:43.194] INFO: 41600 events read in total (2742ms).
[15:07:43.194] INFO: Test took 3971ms.
[15:07:43.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:43.951] INFO: Expecting 41600 events.
[15:07:47.203] INFO: 41600 events read in total (2725ms).
[15:07:47.204] INFO: Test took 3955ms.
[15:07:47.240] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:47.960] INFO: Expecting 41600 events.
[15:07:51.222] INFO: 41600 events read in total (2735ms).
[15:07:51.223] INFO: Test took 3964ms.
[15:07:51.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:51.981] INFO: Expecting 41600 events.
[15:07:55.254] INFO: 41600 events read in total (2746ms).
[15:07:55.255] INFO: Test took 3976ms.
[15:07:55.292] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:56.009] INFO: Expecting 41600 events.
[15:07:59.187] INFO: 41600 events read in total (2651ms).
[15:07:59.188] INFO: Test took 3876ms.
[15:07:59.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:59.583] INFO: enter test to run
[15:09:17.753] INFO: test: HighRate no parameter change
[15:09:17.753] INFO: running: highrate
[15:09:17.755] INFO: ----------------------------------------------------------------------
[15:09:17.755] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:09:17.755] INFO: ----------------------------------------------------------------------
[15:09:18.372] INFO: Expecting 208000 events.
[15:09:30.377] INFO: 208000 events read in total (11478ms).
[15:09:30.381] INFO: Test took 12618ms.
[15:09:30.537] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:30.794] INFO: number of dead pixels (per ROC): 0 0 0 0 0 4 7 0 4 0 0 0 0 0 0 0
[15:09:30.794] INFO: number of red-efficiency pixels: 74 58 94 147 163 151 190 110 91 145 122 109 107 71 23 43
[15:09:30.794] INFO: number of X-ray hits detected: 72004 48361 73023 119256 121053 127776 124619 90830 89347 107227 102776 91369 95510 56639 24301 28602
[15:09:30.794] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:09:30.794] INFO: number of Vcal hits detected: 207926 207942 207875 207850 207834 207651 207455 207888 207713 207851 207876 207890 207890 207928 207976 207957
[15:09:30.794] INFO: Vcal hit fiducial 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 100.0 100.0 100.0 100.0
[15:09:30.794] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.8 99.7 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:09:30.794] INFO: X-ray hit rate [MHz/cm2]: 21.1 14.2 21.4 35.0 35.5 37.5 36.5 26.6 26.2 31.4 30.1 26.8 28.0 16.6 7.1 8.4
[15:09:30.794] INFO: PixTestHighRate::doXPixelAlive() done
[15:09:30.841] INFO: PixTest:: pg_setup set to default.
[15:09:30.858] INFO: enter test to run
[15:11:14.921] INFO: test: HighRate no parameter change
[15:11:14.921] INFO: running: highrate
[15:11:14.922] INFO: ----------------------------------------------------------------------
[15:11:14.922] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:11:14.922] INFO: ----------------------------------------------------------------------
[15:11:15.539] INFO: Expecting 208000 events.
[15:11:29.559] INFO: 208000 events read in total (13493ms).
[15:11:29.565] INFO: Test took 14635ms.
[15:11:29.900] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:30.212] INFO: number of dead pixels (per ROC): 0 0 0 0 0 4 7 0 4 0 0 0 0 0 0 0
[15:11:30.212] INFO: number of red-efficiency pixels: 206 180 310 459 617 507 729 322 222 471 406 361 333 202 47 74
[15:11:30.212] INFO: number of X-ray hits detected: 150437 100482 153112 249014 252002 265956 260137 189014 185227 223635 214026 192355 200284 119560 50977 60226
[15:11:30.212] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:11:30.212] INFO: number of Vcal hits detected: 207778 207806 207643 207505 207315 207241 206850 207649 207568 207489 207563 207616 207652 207789 207952 207925
[15:11:30.212] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.8 99.6 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[15:11:30.212] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.6 99.4 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:11:30.212] INFO: X-ray hit rate [MHz/cm2]: 44.1 29.5 44.9 73.0 73.9 78.0 76.2 55.4 54.3 65.5 62.7 56.4 58.7 35.0 14.9 17.7
[15:11:30.212] INFO: PixTestHighRate::doXPixelAlive() done
[15:11:30.263] INFO: PixTest:: pg_setup set to default.
[15:11:30.282] INFO: enter test to run
[15:11:52.088] INFO: test: HighRate no parameter change
[15:11:52.088] INFO: running: highrate
[15:11:52.090] INFO: ----------------------------------------------------------------------
[15:11:52.090] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:11:52.090] INFO: ----------------------------------------------------------------------
[15:11:52.704] INFO: Expecting 208000 events.
[15:12:09.020] INFO: 208000 events read in total (15789ms).
[15:12:09.028] INFO: Test took 16929ms.
[15:12:09.547] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:09.916] INFO: number of dead pixels (per ROC): 0 0 0 0 0 4 7 0 4 0 0 0 0 0 0 0
[15:12:09.916] INFO: number of red-efficiency pixels: 513 357 807 1134 1522 1162 1642 736 584 1229 889 851 839 522 84 141
[15:12:09.916] INFO: number of X-ray hits detected: 231205 155699 236118 384806 388450 409761 399701 293556 287578 342227 330536 296225 308253 184075 79216 93523
[15:12:09.916] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:12:09.916] INFO: number of Vcal hits detected: 207380 207594 206853 206567 205869 206263 205353 207076 207163 206439 206907 206973 207006 207353 207912 207855
[15:12:09.916] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.5 99.4 99.1 99.3 99.0 99.6 99.7 99.3 99.5 99.6 99.6 99.7 100.0 99.9
[15:12:09.916] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.4 99.3 99.0 99.2 98.7 99.6 99.6 99.2 99.5 99.5 99.5 99.7 100.0 99.9
[15:12:09.917] INFO: X-ray hit rate [MHz/cm2]: 67.8 45.6 69.2 112.8 113.9 120.1 117.2 86.0 84.3 100.3 96.9 86.8 90.4 54.0 23.2 27.4
[15:12:09.917] INFO: PixTestHighRate::doXPixelAlive() done
[15:12:09.964] INFO: PixTest:: pg_setup set to default.
[15:12:09.981] INFO: enter test to run
[15:12:33.376] INFO: test: exit no parameter change
[15:12:33.647] QUIET: Connection to board 33 closed.
[15:12:33.648] INFO: pXar: this is the end, my friend