[12:41:38.794] INFO: *** Welcome to pxar ***
[12:41:38.794] INFO: *** Today: 2016/05/26
[12:41:38.814] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:41:38.814] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//dacParameters35_C15.dat
[12:41:38.833] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:41:38.833] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//defaultMaskFile.dat
[12:41:38.833] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C15.dat
[12:41:38.915] INFO: clk: 4
[12:41:38.915] INFO: ctr: 4
[12:41:38.915] INFO: sda: 19
[12:41:38.915] INFO: tin: 9
[12:41:38.915] INFO: level: 15
[12:41:38.915] INFO: triggerdelay: 0
[12:41:38.915] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:41:38.915] INFO: Log level: INFO
[12:41:38.933] QUIET: Connection to board DTB_WREKRL opened.
[12:41:38.936] 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:
------------------------------------------------------
[12:41:38.939] INFO: RPC call hashes of host and DTB match: 398089610
[12:41:40.473] INFO: DUT info:
[12:41:40.473] INFO: The DUT currently contains the following objects:
[12:41:40.473] INFO: 2 TBM Cores tbm08c (2 ON)
[12:41:40.473] INFO: TBM Core alpha (0): 7 registers set
[12:41:40.473] INFO: TBM Core beta (1): 7 registers set
[12:41:40.473] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:41:40.473] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.473] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.473] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.473] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.473] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.473] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.473] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.473] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.473] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.473] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.474] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.474] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.474] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.474] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.474] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.474] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:41:40.877] INFO: enter 'restricted' command line mode
[12:41:40.877] INFO: enter test to run
[12:41:52.275] INFO: test: PixelAlive no parameter change
[12:41:52.276] INFO: running: pixelalive
[12:41:52.285] INFO: ----------------------------------------------------------------------
[12:41:52.285] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:41:52.285] INFO: ----------------------------------------------------------------------
[12:41:52.603] INFO: Expecting 41600 events.
[12:41:56.941] INFO: 41600 events read in total (3619ms).
[12:41:57.108] INFO: Test took 4821ms.
[12:41:57.122] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:57.385] INFO: PixTestAlive::aliveTest() done
[12:41:57.386] INFO: number of dead pixels (per ROC): 0 0 7 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:41:57.418] INFO: enter test to run
[12:43:12.467] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:43:12.467] INFO: running: highrate
[12:43:12.467] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:43:12.666] INFO: ----------------------------------------------------------------------
[12:43:12.667] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:43:12.667] INFO: ----------------------------------------------------------------------
[12:43:12.667] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:43:12.667] INFO: edge/corner pixel THR is adjusted
[12:43:12.667] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:43:13.626] INFO: Collecting data for 5 seconds...
[12:43:18.643] INFO: Done with hot pixel readout
[12:43:30.279] INFO: PixTest:: pg_setup set to default.
[12:43:30.280] INFO: 11 hot pixels found in step 0
[12:43:31.268] INFO: Collecting data for 5 seconds...
[12:43:36.286] INFO: Done with hot pixel readout
[12:43:47.933] INFO: PixTest:: pg_setup set to default.

[12:43:47.934] INFO: 15 hot pixels found in step 1
[12:43:48.928] INFO: Collecting data for 5 seconds...
[12:43:53.947] INFO: Done with hot pixel readout
[12:44:05.200] INFO: PixTest:: pg_setup set to default.
[12:44:05.201] INFO: 13 hot pixels found in step 2
[12:44:06.192] INFO: Collecting data for 5 seconds...
[12:44:11.211] INFO: Done with hot pixel readout
[12:44:21.961] INFO: PixTest:: pg_setup set to default.
[12:44:21.963] INFO: 14 hot pixels found in step 3
[12:44:22.954] INFO: Collecting data for 5 seconds...
[12:44:27.972] INFO: Done with hot pixel readout
[12:44:39.655] INFO: PixTest:: pg_setup set to default.
[12:44:39.655] INFO: 10 hot pixels found in step 4
[12:44:40.647] INFO: Collecting data for 5 seconds...
[12:44:45.664] INFO: Done with hot pixel readout
[12:44:57.139] INFO: PixTest:: pg_setup set to default.
[12:44:57.140] INFO: 7 hot pixels found in step 5
[12:44:58.133] INFO: Collecting data for 5 seconds...
[12:45:03.151] INFO: Done with hot pixel readout
[12:45:14.430] INFO: PixTest:: pg_setup set to default.
[12:45:14.431] INFO: 2 hot pixels found in step 6
[12:45:15.423] INFO: Collecting data for 5 seconds...
[12:45:20.442] INFO: Done with hot pixel readout
[12:45:31.417] INFO: PixTest:: pg_setup set to default.
[12:45:31.418] INFO: 5 hot pixels found in step 7
[12:45:32.409] INFO: Collecting data for 5 seconds...
[12:45:37.426] INFO: Done with hot pixel readout
[12:45:48.240] INFO: PixTest:: pg_setup set to default.
[12:45:48.240] INFO: 3 hot pixels found in step 8
[12:45:49.233] INFO: Collecting data for 5 seconds...
[12:45:54.250] INFO: Done with hot pixel readout
[12:46:04.402] INFO: PixTest:: pg_setup set to default.
[12:46:04.403] INFO: 5 hot pixels found in step 9
[12:46:05.395] INFO: Collecting data for 5 seconds...
[12:46:10.415] INFO: Done with hot pixel readout
[12:46:21.845] INFO: PixTest:: pg_setup set to default.
[12:46:21.846] INFO: 4 hot pixels found in step 10
[12:46:22.838] INFO: Collecting data for 5 seconds...
[12:46:27.856] INFO: Done with hot pixel readout
[12:46:39.355] INFO: PixTest:: pg_setup set to default.

[12:46:39.356] INFO: 4 hot pixels found in step 11
[12:46:40.349] INFO: Collecting data for 5 seconds...
[12:46:45.367] INFO: Done with hot pixel readout
[12:46:57.090] INFO: PixTest:: pg_setup set to default.
[12:46:57.091] INFO: 3 hot pixels found in step 12
[12:46:58.083] INFO: Collecting data for 5 seconds...
[12:47:03.101] INFO: Done with hot pixel readout
[12:47:14.833] INFO: PixTest:: pg_setup set to default.
[12:47:14.834] INFO: 2 hot pixels found in step 13
[12:47:15.825] INFO: Collecting data for 5 seconds...
[12:47:20.842] INFO: Done with hot pixel readout
[12:47:32.473] INFO: PixTest:: pg_setup set to default.
[12:47:32.474] INFO: 1 hot pixels found in step 14
[12:47:32.509] INFO: 1 hot pixels could not be trimmed and have been masked.
[12:47:32.513] INFO: PixTest::trimHotPixels() done
[12:47:32.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C0.dat
[12:47:32.518] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C1.dat
[12:47:32.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C2.dat
[12:47:32.530] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C3.dat
[12:47:32.536] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C4.dat
[12:47:32.541] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C5.dat
[12:47:32.547] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C6.dat
[12:47:32.552] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C7.dat
[12:47:32.557] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C8.dat
[12:47:32.562] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C9.dat
[12:47:32.568] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C10.dat
[12:47:32.573] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C11.dat
[12:47:32.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C12.dat
[12:47:32.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C13.dat
[12:47:32.589] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C14.dat
[12:47:32.594] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C15.dat
[12:47:32.599] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//defaultMaskFile.dat
[12:47:32.617] INFO: enter test to run
[12:48:20.849] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:48:20.849] INFO: running: highrate
[12:48:20.853] INFO: ----------------------------------------------------------------------
[12:48:20.853] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:48:20.853] INFO: ----------------------------------------------------------------------
[12:48:20.853] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:48:20.853] INFO: edge/corner pixel THR is adjusted
[12:48:20.853] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:48:21.811] INFO: Collecting data for 1 seconds...
[12:48:22.815] INFO: Done with hot pixel readout
[12:48:26.723] INFO: PixTest:: pg_setup set to default.
[12:48:26.723] INFO: 0 hot pixels found in step 0
[12:48:26.729] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:48:26.823] INFO: PixTest::trimHotPixels() done
[12:48:26.824] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C0.dat
[12:48:26.835] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C1.dat
[12:48:26.840] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C2.dat
[12:48:26.845] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C3.dat
[12:48:26.850] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C4.dat
[12:48:26.856] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C5.dat
[12:48:26.861] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C6.dat
[12:48:26.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C7.dat
[12:48:26.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C8.dat
[12:48:26.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C9.dat
[12:48:26.882] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C10.dat
[12:48:26.887] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C11.dat
[12:48:26.892] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C12.dat
[12:48:26.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C13.dat
[12:48:26.903] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C14.dat
[12:48:26.908] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C15.dat
[12:48:26.913] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-1-26_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//defaultMaskFile.dat
[12:48:26.923] INFO: enter test to run
[12:49:04.056] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:49:04.056] INFO: running: xray
[12:49:04.057] INFO: ----------------------------------------------------------------------
[12:49:04.057] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:49:04.057] INFO: ----------------------------------------------------------------------
[12:49:05.020] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:49:16.792] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:49:45.977] INFO: Resuming triggers.
[12:49:57.744] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:50:26.562] INFO: Resuming triggers.
[12:50:38.331] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:51:07.390] INFO: Resuming triggers.
[12:51:19.155] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:51:47.952] INFO: Resuming triggers.
[12:51:59.722] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:52:29.008] INFO: Resuming triggers.
[12:52:40.777] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:53:10.017] INFO: Resuming triggers.
[12:53:21.784] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:53:51.132] INFO: Resuming triggers.
[12:54:02.901] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:54:32.083] INFO: Resuming triggers.
[12:54:38.283] INFO: data taking finished, elapsed time: 100 seconds.
[12:54:53.951] INFO: PixTest:: pg_setup set to default.
[12:54:53.954] INFO: PixTestXray::doPhRun() done
[12:54:54.111] INFO: enter test to run
[12:55:38.197] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:55:38.197] INFO: running: xray
[12:55:38.198] INFO: ----------------------------------------------------------------------
[12:55:38.198] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:55:38.199] INFO: ----------------------------------------------------------------------
[12:55:39.162] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:55:46.064] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:56:16.610] INFO: Resuming triggers.
[12:56:23.513] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:56:53.354] INFO: Resuming triggers.
[12:57:00.261] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:57:30.863] INFO: Resuming triggers.
[12:57:37.767] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[12:58:08.148] INFO: Resuming triggers.
[12:58:15.052] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:58:44.638] INFO: Resuming triggers.
[12:58:51.538] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[12:59:21.569] INFO: Resuming triggers.
[12:59:28.472] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[12:59:58.521] INFO: Resuming triggers.
[13:00:05.427] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:00:35.303] INFO: Resuming triggers.
[13:00:42.206] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:01:12.213] INFO: Resuming triggers.
[13:01:19.111] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:01:49.241] INFO: Resuming triggers.
[13:01:56.140] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:02:23.150] INFO: Resuming triggers.
[13:02:30.053] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:02:57.626] INFO: Resuming triggers.
[13:03:04.526] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[13:03:34.026] INFO: Resuming triggers.
[13:03:40.927] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[13:04:11.044] INFO: Resuming triggers.
[13:04:14.763] INFO: data taking finished, elapsed time: 100 seconds.
[13:04:31.216] INFO: PixTest:: pg_setup set to default.
[13:04:31.219] INFO: PixTestXray::doPhRun() done
[13:04:31.367] INFO: enter test to run
[13:05:04.857] INFO: test: HighRate no parameter change
[13:05:04.857] INFO: running: highrate
[13:05:04.874] INFO: ----------------------------------------------------------------------
[13:05:04.875] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:05:04.875] INFO: ----------------------------------------------------------------------
[13:05:05.031] INFO: Expecting 768 events.
[13:05:06.165] INFO: 768 events read in total (418ms).
[13:05:06.165] INFO: Test took 1269ms.
[13:05:06.968] INFO: Expecting 41600 events.
[13:05:10.099] INFO: 41600 events read in total (2604ms).
[13:05:10.100] INFO: Test took 3928ms.
[13:05:10.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:10.861] INFO: Expecting 41600 events.
[13:05:14.036] INFO: 41600 events read in total (2648ms).
[13:05:14.037] INFO: Test took 3888ms.
[13:05:14.069] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:14.797] INFO: Expecting 41600 events.
[13:05:17.987] INFO: 41600 events read in total (2663ms).
[13:05:17.988] INFO: Test took 3901ms.
[13:05:18.020] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:18.749] INFO: Expecting 41600 events.
[13:05:21.947] INFO: 41600 events read in total (2671ms).
[13:05:21.948] INFO: Test took 3910ms.
[13:05:21.979] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:22.709] INFO: Expecting 41600 events.
[13:05:25.931] INFO: 41600 events read in total (2695ms).
[13:05:25.932] INFO: Test took 3935ms.
[13:05:25.964] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:26.695] INFO: Expecting 41600 events.
[13:05:29.923] INFO: 41600 events read in total (2701ms).
[13:05:29.924] INFO: Test took 3942ms.
[13:05:29.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:30.681] INFO: Expecting 41600 events.
[13:05:33.896] INFO: 41600 events read in total (2688ms).
[13:05:33.897] INFO: Test took 3923ms.
[13:05:33.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:34.655] INFO: Expecting 41600 events.
[13:05:37.880] INFO: 41600 events read in total (2698ms).
[13:05:37.881] INFO: Test took 3934ms.
[13:05:37.912] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:38.638] INFO: Expecting 41600 events.
[13:05:41.857] INFO: 41600 events read in total (2692ms).
[13:05:41.858] INFO: Test took 3929ms.
[13:05:41.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:42.620] INFO: Expecting 41600 events.
[13:05:45.825] INFO: 41600 events read in total (2678ms).
[13:05:45.826] INFO: Test took 3919ms.
[13:05:45.858] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:46.587] INFO: Expecting 41600 events.
[13:05:49.801] INFO: 41600 events read in total (2687ms).
[13:05:49.802] INFO: Test took 3926ms.
[13:05:49.834] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:50.564] INFO: Expecting 41600 events.
[13:05:53.773] INFO: 41600 events read in total (2682ms).
[13:05:53.774] INFO: Test took 3922ms.
[13:05:53.805] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:54.536] INFO: Expecting 41600 events.
[13:05:57.752] INFO: 41600 events read in total (2689ms).
[13:05:57.753] INFO: Test took 3930ms.
[13:05:57.784] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:58.510] INFO: Expecting 41600 events.
[13:06:01.724] INFO: 41600 events read in total (2687ms).
[13:06:01.725] INFO: Test took 3923ms.
[13:06:01.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:02.483] INFO: Expecting 41600 events.
[13:06:05.716] INFO: 41600 events read in total (2706ms).
[13:06:05.717] INFO: Test took 3942ms.
[13:06:05.750] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:06.470] INFO: Expecting 41600 events.
[13:06:09.691] INFO: 41600 events read in total (2694ms).
[13:06:09.692] INFO: Test took 3925ms.
[13:06:09.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:10.449] INFO: Expecting 41600 events.
[13:06:13.663] INFO: 41600 events read in total (2688ms).
[13:06:13.664] INFO: Test took 3921ms.
[13:06:13.696] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:14.421] INFO: Expecting 41600 events.
[13:06:17.627] INFO: 41600 events read in total (2679ms).
[13:06:17.628] INFO: Test took 3914ms.
[13:06:17.660] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:18.389] INFO: Expecting 41600 events.
[13:06:21.572] INFO: 41600 events read in total (2656ms).
[13:06:21.573] INFO: Test took 3896ms.
[13:06:21.605] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:22.332] INFO: Expecting 41600 events.
[13:06:25.363] INFO: 41600 events read in total (2504ms).
[13:06:25.364] INFO: Test took 3741ms.
[13:06:25.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:25.763] INFO: enter test to run
[13:06:58.072] INFO: test: HighRate no parameter change
[13:06:58.072] INFO: running: highrate
[13:06:58.073] INFO: ----------------------------------------------------------------------
[13:06:58.073] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:06:58.073] INFO: ----------------------------------------------------------------------
[13:06:58.689] INFO: Expecting 208000 events.
[13:07:10.438] INFO: 208000 events read in total (11222ms).
[13:07:10.441] INFO: Test took 12360ms.
[13:07:10.579] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:10.829] INFO: number of dead pixels (per ROC): 0 0 7 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:07:10.829] INFO: number of red-efficiency pixels: 67 40 95 118 129 155 134 87 74 82 88 62 99 53 18 23
[13:07:10.829] INFO: number of X-ray hits detected: 57900 40399 64593 104438 105974 110160 109732 78175 70657 84754 83108 72787 71567 44576 21319 25503
[13:07:10.829] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:07:10.829] INFO: number of Vcal hits detected: 207933 207959 207516 207879 207870 207843 207863 207912 207926 207917 207910 207936 207901 207947 207982 207977
[13:07:10.829] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[13:07:10.829] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.8 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[13:07:10.829] INFO: X-ray hit rate [MHz/cm2]: 17.0 11.8 18.9 30.6 31.1 32.3 32.2 22.9 20.7 24.8 24.4 21.3 21.0 13.1 6.2 7.5
[13:07:10.829] INFO: PixTestHighRate::doXPixelAlive() done
[13:07:10.875] INFO: PixTest:: pg_setup set to default.
[13:07:10.888] INFO: enter test to run
[13:07:37.320] INFO: test: HighRate no parameter change
[13:07:37.320] INFO: running: highrate
[13:07:37.321] INFO: ----------------------------------------------------------------------
[13:07:37.321] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:07:37.321] INFO: ----------------------------------------------------------------------
[13:07:37.942] INFO: Expecting 208000 events.
[13:07:51.237] INFO: 208000 events read in total (12768ms).
[13:07:51.242] INFO: Test took 13913ms.
[13:07:51.530] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:51.826] INFO: number of dead pixels (per ROC): 0 0 7 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:07:51.826] INFO: number of red-efficiency pixels: 179 103 289 385 475 503 572 267 241 275 260 199 244 164 48 62
[13:07:51.826] INFO: number of X-ray hits detected: 122825 86012 137194 220551 225641 236503 235002 165983 150309 181960 177850 155686 152901 95304 44522 54238
[13:07:51.826] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:07:51.826] INFO: number of Vcal hits detected: 207809 207893 207292 207591 207480 207451 207352 207721 207751 207713 207733 207790 207748 207829 207950 207938
[13:07:51.826] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.8 99.8 99.8 99.8 99.7 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[13:07:51.826] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.7 99.8 99.8 99.7 99.7 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[13:07:51.826] INFO: X-ray hit rate [MHz/cm2]: 36.0 25.2 40.2 64.6 66.1 69.3 68.9 48.7 44.1 53.3 52.1 45.6 44.8 27.9 13.0 15.9
[13:07:51.826] INFO: PixTestHighRate::doXPixelAlive() done
[13:07:51.873] INFO: PixTest:: pg_setup set to default.
[13:07:51.887] INFO: enter test to run
[13:08:16.720] INFO: test: HighRate no parameter change
[13:08:16.720] INFO: running: highrate
[13:08:16.721] INFO: ----------------------------------------------------------------------
[13:08:16.721] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:08:16.721] INFO: ----------------------------------------------------------------------
[13:08:17.342] INFO: Expecting 208000 events.
[13:08:32.286] INFO: 208000 events read in total (14417ms).
[13:08:32.294] INFO: Test took 15564ms.
[13:08:32.727] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:33.075] INFO: number of dead pixels (per ROC): 0 0 7 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:08:33.075] INFO: number of red-efficiency pixels: 331 200 699 886 1165 1330 1300 623 487 539 539 434 524 339 73 87
[13:08:33.075] INFO: number of X-ray hits detected: 187953 131302 209295 335293 342304 359541 355501 252869 229221 275260 268896 235087 231811 145308 68188 83137
[13:08:33.075] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:08:33.075] INFO: number of Vcal hits detected: 207632 207782 206708 206952 206499 206254 206263 207272 207465 207375 207398 207535 207425 207621 207924 207913
[13:08:33.075] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.5 99.4 99.2 99.3 99.7 99.8 99.7 99.7 99.8 99.8 99.8 100.0 100.0
[13:08:33.075] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.4 99.5 99.3 99.2 99.2 99.7 99.7 99.7 99.7 99.8 99.7 99.8 100.0 100.0
[13:08:33.075] INFO: X-ray hit rate [MHz/cm2]: 55.1 38.5 61.3 98.3 100.3 105.4 104.2 74.1 67.2 80.7 78.8 68.9 67.9 42.6 20.0 24.4
[13:08:33.075] INFO: PixTestHighRate::doXPixelAlive() done
[13:08:33.122] INFO: PixTest:: pg_setup set to default.
[13:08:33.138] INFO: enter test to run
[13:08:39.256] INFO: test: exit no parameter change
[13:08:39.607] QUIET: Connection to board 33 closed.
[13:08:39.608] INFO: pXar: this is the end, my friend