[14:15:54.290] INFO: *** Welcome to pxar ***
[14:15:54.290] INFO: *** Today: 2016/05/02
[14:15:54.337] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:15:54.337] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//dacParameters35_C15.dat
[14:15:54.340] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:15:54.340] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//defaultMaskFile.dat
[14:15:54.341] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C15.dat
[14:15:54.423] INFO: clk: 4
[14:15:54.423] INFO: ctr: 4
[14:15:54.423] INFO: sda: 19
[14:15:54.423] INFO: tin: 9
[14:15:54.423] INFO: level: 15
[14:15:54.423] INFO: triggerdelay: 0
[14:15:54.423] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:15:54.423] INFO: Log level: INFO
[14:15:54.442] QUIET: Connection to board DTB_WREKRL opened.
[14:15:54.445] 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:15:54.448] INFO: RPC call hashes of host and DTB match: 398089610
[14:15:55.973] INFO: DUT info:
[14:15:55.973] INFO: The DUT currently contains the following objects:
[14:15:55.973] INFO: 2 TBM Cores tbm08c (2 ON)
[14:15:55.973] INFO: TBM Core alpha (0): 7 registers set
[14:15:55.973] INFO: TBM Core beta (1): 7 registers set
[14:15:55.973] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:15:55.973] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.973] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.974] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.974] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.974] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:55.974] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:56.377] INFO: enter 'restricted' command line mode
[14:15:56.377] INFO: enter test to run
[14:16:03.547] INFO: test: PixelAlive no parameter change
[14:16:03.547] INFO: running: pixelalive
[14:16:03.556] INFO: ----------------------------------------------------------------------
[14:16:03.556] 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:16:03.556] INFO: ----------------------------------------------------------------------
[14:16:03.884] INFO: Expecting 41600 events.
[14:16:08.216] INFO: 41600 events read in total (3613ms).
[14:16:08.385] INFO: Test took 4826ms.
[14:16:08.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:08.673] INFO: PixTestAlive::aliveTest() done
[14:16:08.673] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:16:08.704] INFO: enter test to run
[14:17:00.538] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:17:00.538] INFO: running: highrate
[14:17:00.538] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:17:00.739] INFO: ----------------------------------------------------------------------
[14:17:00.739] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:17:00.739] INFO: ----------------------------------------------------------------------
[14:17:00.739] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:17:00.739] INFO: edge/corner pixel THR is adjusted
[14:17:00.739] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:17:01.697] INFO: Collecting data for 5 seconds...
[14:17:06.714] INFO: Done with hot pixel readout
[14:17:18.919] INFO: PixTest:: pg_setup set to default.
[14:17:18.920] INFO: 6 hot pixels found in step 0
[14:17:19.910] INFO: Collecting data for 5 seconds...
[14:17:24.927] INFO: Done with hot pixel readout
[14:17:37.084] INFO: PixTest:: pg_setup set to default.
[14:17:37.085] INFO: 4 hot pixels found in step 1
[14:17:38.076] INFO: Collecting data for 5 seconds...
[14:17:43.093] INFO: Done with hot pixel readout
[14:17:55.255] INFO: PixTest:: pg_setup set to default.
[14:17:55.256] INFO: 7 hot pixels found in step 2
[14:17:56.252] INFO: Collecting data for 5 seconds...
[14:18:01.268] INFO: Done with hot pixel readout
[14:18:13.439] INFO: PixTest:: pg_setup set to default.
[14:18:13.440] INFO: 3 hot pixels found in step 3
[14:18:14.435] INFO: Collecting data for 5 seconds...
[14:18:19.451] INFO: Done with hot pixel readout
[14:18:31.613] INFO: PixTest:: pg_setup set to default.

[14:18:31.613] INFO: 6 hot pixels found in step 4
[14:18:32.609] INFO: Collecting data for 5 seconds...
[14:18:37.625] INFO: Done with hot pixel readout
[14:18:49.803] INFO: PixTest:: pg_setup set to default.
[14:18:49.804] INFO: 4 hot pixels found in step 5
[14:18:50.799] INFO: Collecting data for 5 seconds...
[14:18:55.815] INFO: Done with hot pixel readout
[14:19:07.944] INFO: PixTest:: pg_setup set to default.
[14:19:07.945] INFO: 3 hot pixels found in step 6
[14:19:08.939] INFO: Collecting data for 5 seconds...
[14:19:13.955] INFO: Done with hot pixel readout
[14:19:26.126] INFO: PixTest:: pg_setup set to default.
[14:19:26.127] INFO: 2 hot pixels found in step 7
[14:19:27.122] INFO: Collecting data for 5 seconds...
[14:19:32.138] INFO: Done with hot pixel readout
[14:19:44.306] INFO: PixTest:: pg_setup set to default.
[14:19:44.307] INFO: 9 hot pixels found in step 8
[14:19:45.302] INFO: Collecting data for 5 seconds...
[14:19:50.319] INFO: Done with hot pixel readout
[14:20:01.993] INFO: PixTest:: pg_setup set to default.

[14:20:01.995] INFO: 4 hot pixels found in step 9
[14:20:02.990] INFO: Collecting data for 5 seconds...
[14:20:08.007] INFO: Done with hot pixel readout
[14:20:20.151] INFO: PixTest:: pg_setup set to default.

[14:20:20.152] INFO: 5 hot pixels found in step 10
[14:20:21.147] INFO: Collecting data for 5 seconds...
[14:20:26.164] INFO: Done with hot pixel readout
[14:20:38.353] INFO: PixTest:: pg_setup set to default.
[14:20:38.354] INFO: 4 hot pixels found in step 11
[14:20:39.349] INFO: Collecting data for 5 seconds...
[14:20:44.366] INFO: Done with hot pixel readout
[14:20:56.556] INFO: PixTest:: pg_setup set to default.

[14:20:56.557] INFO: 4 hot pixels found in step 12
[14:20:57.552] INFO: Collecting data for 5 seconds...
[14:21:02.560] INFO: Done with hot pixel readout
[14:21:12.649] INFO: PixTest:: pg_setup set to default.
[14:21:12.650] INFO: 2 hot pixels found in step 13
[14:21:13.644] INFO: Collecting data for 5 seconds...
[14:21:18.656] INFO: Done with hot pixel readout
[14:21:30.794] INFO: PixTest:: pg_setup set to default.
[14:21:30.795] INFO: 5 hot pixels found in step 14
[14:21:30.834] INFO: 5 hot pixels could not be trimmed and have been masked.
[14:21:30.838] INFO: PixTest::trimHotPixels() done
[14:21:30.838] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C0.dat
[14:21:30.843] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C1.dat
[14:21:30.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C2.dat
[14:21:30.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C3.dat
[14:21:30.861] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C4.dat
[14:21:30.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C5.dat
[14:21:30.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C6.dat
[14:21:30.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C7.dat
[14:21:30.882] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C8.dat
[14:21:30.887] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C9.dat
[14:21:30.892] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C10.dat
[14:21:30.897] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C11.dat
[14:21:30.903] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C12.dat
[14:21:30.908] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C13.dat
[14:21:30.913] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C14.dat
[14:21:30.918] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C15.dat
[14:21:30.924] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//defaultMaskFile.dat
[14:21:30.934] INFO: enter test to run
[14:21:59.312] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:21:59.312] INFO: running: highrate
[14:21:59.317] INFO: ----------------------------------------------------------------------
[14:21:59.317] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:21:59.317] INFO: ----------------------------------------------------------------------
[14:21:59.317] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:21:59.317] INFO: edge/corner pixel THR is adjusted
[14:21:59.317] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:22:00.275] INFO: Collecting data for 1 seconds...
[14:22:01.279] INFO: Done with hot pixel readout
[14:22:05.472] INFO: PixTest:: pg_setup set to default.
[14:22:05.473] INFO: 0 hot pixels found in step 0
[14:22:05.478] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:22:05.560] INFO: PixTest::trimHotPixels() done
[14:22:05.560] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C0.dat
[14:22:05.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C1.dat
[14:22:05.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C2.dat
[14:22:05.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C3.dat
[14:22:05.589] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C4.dat
[14:22:05.594] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C5.dat
[14:22:05.599] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C6.dat
[14:22:05.604] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C7.dat
[14:22:05.610] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C8.dat
[14:22:05.615] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C9.dat
[14:22:05.620] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C10.dat
[14:22:05.625] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C11.dat
[14:22:05.631] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C12.dat
[14:22:05.636] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C13.dat
[14:22:05.641] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C14.dat
[14:22:05.646] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//trimParameters35_C15.dat
[14:22:05.652] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-39_FPIXTest-17C-FNAL-160425-1233_2016-04-25_12h33m_1461605635/000_FPIXTest_p17//defaultMaskFile.dat
[14:22:05.669] INFO: enter test to run
[14:23:16.887] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:23:16.887] INFO: running: xray
[14:23:16.889] INFO: ----------------------------------------------------------------------
[14:23:16.889] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:23:16.889] INFO: ----------------------------------------------------------------------
[14:23:17.852] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:23:28.947] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:23:58.486] INFO: Resuming triggers.
[14:24:09.583] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:24:39.190] INFO: Resuming triggers.
[14:24:50.287] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:25:19.763] INFO: Resuming triggers.
[14:25:30.856] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:26:00.386] INFO: Resuming triggers.
[14:26:11.481] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:26:40.993] INFO: Resuming triggers.
[14:26:52.087] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:27:21.608] INFO: Resuming triggers.
[14:27:32.702] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:28:02.240] INFO: Resuming triggers.
[14:28:13.336] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:28:43.033] INFO: Resuming triggers.
[14:28:54.123] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:29:22.565] INFO: Resuming triggers.
[14:29:23.047] INFO: data taking finished, elapsed time: 100 seconds.
[14:29:24.687] INFO: PixTest:: pg_setup set to default.
[14:29:24.690] INFO: PixTestXray::doPhRun() done
[14:29:24.830] INFO: enter test to run
[14:30:06.476] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:30:06.477] INFO: running: xray
[14:30:06.478] INFO: ----------------------------------------------------------------------
[14:30:06.478] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:30:06.478] INFO: ----------------------------------------------------------------------
[14:30:07.452] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:30:13.613] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:30:43.676] INFO: Resuming triggers.
[14:30:49.840] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[14:31:18.316] INFO: Resuming triggers.
[14:31:24.480] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[14:31:54.399] INFO: Resuming triggers.
[14:32:00.565] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[14:32:30.623] INFO: Resuming triggers.
[14:32:36.786] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[14:33:06.900] INFO: Resuming triggers.
[14:33:13.065] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[14:33:43.232] INFO: Resuming triggers.
[14:33:49.394] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:34:18.285] INFO: Resuming triggers.
[14:34:24.450] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:34:54.521] INFO: Resuming triggers.
[14:35:00.682] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:35:30.750] INFO: Resuming triggers.
[14:35:36.913] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:36:06.971] INFO: Resuming triggers.
[14:36:13.132] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:36:43.254] INFO: Resuming triggers.
[14:36:49.414] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[14:37:19.516] INFO: Resuming triggers.
[14:37:25.677] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:37:55.788] INFO: Resuming triggers.
[14:38:01.951] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:38:32.162] INFO: Resuming triggers.
[14:38:38.322] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:39:08.414] INFO: Resuming triggers.
[14:39:14.576] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:39:44.725] INFO: Resuming triggers.
[14:39:46.447] INFO: data taking finished, elapsed time: 100 seconds.
[14:39:55.221] INFO: PixTest:: pg_setup set to default.
[14:39:55.224] INFO: PixTestXray::doPhRun() done
[14:39:55.376] INFO: enter test to run
[14:40:49.768] INFO: test: HighRate no parameter change
[14:40:49.768] INFO: running: highrate
[14:40:49.769] INFO: ----------------------------------------------------------------------
[14:40:49.769] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:40:49.769] INFO: ----------------------------------------------------------------------
[14:40:49.909] INFO: Expecting 768 events.
[14:40:51.043] INFO: 768 events read in total (418ms).
[14:40:51.043] INFO: Test took 1268ms.
[14:40:51.846] INFO: Expecting 41600 events.
[14:40:54.886] INFO: 41600 events read in total (2513ms).
[14:40:54.887] INFO: Test took 3837ms.
[14:40:54.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:55.649] INFO: Expecting 41600 events.
[14:40:58.815] INFO: 41600 events read in total (2640ms).
[14:40:58.817] INFO: Test took 3877ms.
[14:40:58.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:59.570] INFO: Expecting 41600 events.
[14:41:02.804] INFO: 41600 events read in total (2707ms).
[14:41:02.805] INFO: Test took 3933ms.
[14:41:02.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:03.563] INFO: Expecting 41600 events.
[14:41:06.812] INFO: 41600 events read in total (2722ms).
[14:41:06.813] INFO: Test took 3953ms.
[14:41:06.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:07.571] INFO: Expecting 41600 events.
[14:41:10.390] INFO: 41600 events read in total (2293ms).
[14:41:10.391] INFO: Test took 3524ms.
[14:41:10.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:11.150] INFO: Expecting 41600 events.
[14:41:14.011] INFO: 41600 events read in total (2334ms).
[14:41:14.012] INFO: Test took 3566ms.
[14:41:14.047] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:14.770] INFO: Expecting 41600 events.
[14:41:17.982] INFO: 41600 events read in total (2685ms).
[14:41:17.983] INFO: Test took 3916ms.
[14:41:18.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:18.742] INFO: Expecting 41600 events.
[14:41:21.567] INFO: 41600 events read in total (2298ms).
[14:41:21.568] INFO: Test took 3530ms.
[14:41:21.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:22.329] INFO: Expecting 41600 events.
[14:41:25.225] INFO: 41600 events read in total (2370ms).
[14:41:25.226] INFO: Test took 3603ms.
[14:41:25.263] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:25.985] INFO: Expecting 41600 events.
[14:41:29.156] INFO: 41600 events read in total (2644ms).
[14:41:29.157] INFO: Test took 3876ms.
[14:41:29.193] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:29.914] INFO: Expecting 41600 events.
[14:41:33.149] INFO: 41600 events read in total (2708ms).
[14:41:33.150] INFO: Test took 3938ms.
[14:41:33.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:33.905] INFO: Expecting 41600 events.
[14:41:37.169] INFO: 41600 events read in total (2737ms).
[14:41:37.170] INFO: Test took 3966ms.
[14:41:37.205] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:37.925] INFO: Expecting 41600 events.
[14:41:41.191] INFO: 41600 events read in total (2739ms).
[14:41:41.192] INFO: Test took 3967ms.
[14:41:41.228] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:41.949] INFO: Expecting 41600 events.
[14:41:45.212] INFO: 41600 events read in total (2736ms).
[14:41:45.213] INFO: Test took 3966ms.
[14:41:45.249] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:45.971] INFO: Expecting 41600 events.
[14:41:49.241] INFO: 41600 events read in total (2743ms).
[14:41:49.242] INFO: Test took 3975ms.
[14:41:49.278] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:49.996] INFO: Expecting 41600 events.
[14:41:53.249] INFO: 41600 events read in total (2726ms).
[14:41:53.250] INFO: Test took 3952ms.
[14:41:53.287] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:54.005] INFO: Expecting 41600 events.
[14:41:57.272] INFO: 41600 events read in total (2741ms).
[14:41:57.273] INFO: Test took 3967ms.
[14:41:57.309] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:58.031] INFO: Expecting 41600 events.
[14:42:01.276] INFO: 41600 events read in total (2718ms).
[14:42:01.277] INFO: Test took 3948ms.
[14:42:01.313] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:02.032] INFO: Expecting 41600 events.
[14:42:05.262] INFO: 41600 events read in total (2703ms).
[14:42:05.263] INFO: Test took 3930ms.
[14:42:05.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:06.020] INFO: Expecting 41600 events.
[14:42:09.121] INFO: 41600 events read in total (2574ms).
[14:42:09.122] INFO: Test took 3805ms.
[14:42:09.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:09.518] INFO: enter test to run
[14:42:32.247] INFO: test: HighRate no parameter change
[14:42:32.247] INFO: running: highrate
[14:42:32.267] INFO: ----------------------------------------------------------------------
[14:42:32.268] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:42:32.268] INFO: ----------------------------------------------------------------------
[14:42:32.881] INFO: Expecting 208000 events.
[14:42:44.870] INFO: 208000 events read in total (11462ms).
[14:42:44.873] INFO: Test took 12595ms.
[14:42:45.029] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:45.283] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:42:45.283] INFO: number of red-efficiency pixels: 70 72 94 144 179 193 189 122 89 111 149 106 103 59 18 19
[14:42:45.283] INFO: number of X-ray hits detected: 68014 49448 77765 119038 123649 130096 127164 91383 81752 100021 101270 88434 87622 52739 23069 23653
[14:42:45.283] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:42:45.283] INFO: number of Vcal hits detected: 207929 207927 207905 207856 207818 207804 207806 207876 207910 207886 207850 207894 207895 207940 207982 207981
[14:42:45.283] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:42:45.283] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:42:45.283] INFO: X-ray hit rate [MHz/cm2]: 19.9 14.5 22.8 34.9 36.2 38.1 37.3 26.8 24.0 29.3 29.7 25.9 25.7 15.5 6.8 6.9
[14:42:45.283] INFO: PixTestHighRate::doXPixelAlive() done
[14:42:45.334] INFO: PixTest:: pg_setup set to default.
[14:42:45.351] INFO: enter test to run
[14:43:16.943] INFO: test: HighRate no parameter change
[14:43:16.943] INFO: running: highrate
[14:43:16.944] INFO: ----------------------------------------------------------------------
[14:43:16.944] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:43:16.944] INFO: ----------------------------------------------------------------------
[14:43:17.557] INFO: Expecting 208000 events.
[14:43:31.658] INFO: 208000 events read in total (13574ms).
[14:43:31.664] INFO: Test took 14710ms.
[14:43:31.983] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:32.292] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:43:32.292] INFO: number of red-efficiency pixels: 258 167 316 475 770 783 746 432 367 423 534 350 361 214 59 58
[14:43:32.292] INFO: number of X-ray hits detected: 147079 106546 166813 254699 265955 278523 273152 196098 177169 215409 217141 189573 187452 113611 50191 51927
[14:43:32.292] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:43:32.292] INFO: number of Vcal hits detected: 207724 207821 207645 207495 207132 207117 207158 207530 207623 207544 207425 207619 207621 207764 207941 207942
[14:43:32.292] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.6 99.6 99.6 99.8 99.8 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[14:43:32.292] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.6 99.6 99.6 99.8 99.8 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[14:43:32.292] INFO: X-ray hit rate [MHz/cm2]: 43.1 31.2 48.9 74.7 78.0 81.6 80.1 57.5 51.9 63.1 63.6 55.6 54.9 33.3 14.7 15.2
[14:43:32.293] INFO: PixTestHighRate::doXPixelAlive() done
[14:43:32.340] INFO: PixTest:: pg_setup set to default.
[14:43:32.352] INFO: enter test to run
[14:43:59.422] INFO: test: HighRate no parameter change
[14:43:59.422] INFO: running: highrate
[14:43:59.423] INFO: ----------------------------------------------------------------------
[14:43:59.423] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:43:59.424] INFO: ----------------------------------------------------------------------
[14:44:00.036] INFO: Expecting 208000 events.
[14:44:16.276] INFO: 208000 events read in total (15713ms).
[14:44:16.284] INFO: Test took 16851ms.
[14:44:16.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:17.157] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:44:17.158] INFO: number of red-efficiency pixels: 611 386 729 1117 1687 1754 1751 967 695 1006 1117 789 764 468 107 71
[14:44:17.158] INFO: number of X-ray hits detected: 220840 160193 252116 382897 399858 416928 410670 296609 265739 323918 326646 285595 283070 171084 75714 78604
[14:44:17.158] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:44:17.158] INFO: number of Vcal hits detected: 207255 207552 206992 206595 205575 205349 205433 206733 207182 206820 206613 207047 207086 207473 207888 207926
[14:44:17.158] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.4 99.0 98.8 98.9 99.4 99.6 99.5 99.4 99.6 99.6 99.8 99.9 100.0
[14:44:17.158] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.3 98.8 98.7 98.8 99.4 99.6 99.4 99.3 99.5 99.6 99.7 99.9 100.0
[14:44:17.158] INFO: X-ray hit rate [MHz/cm2]: 64.7 47.0 73.9 112.2 117.2 122.2 120.4 86.9 77.9 94.9 95.7 83.7 83.0 50.1 22.2 23.0
[14:44:17.158] INFO: PixTestHighRate::doXPixelAlive() done
[14:44:17.204] INFO: PixTest:: pg_setup set to default.
[14:44:17.219] INFO: enter test to run
[14:44:53.374] INFO: test: exit no parameter change
[14:44:53.733] QUIET: Connection to board 33 closed.
[14:44:53.735] INFO: pXar: this is the end, my friend