[19:13:19.618] INFO: *** Welcome to pxar ***
[19:13:19.618] INFO: *** Today: 2016/10/06
[19:13:20.402] INFO: *** Version: v1.9.0-818-g96727
[19:13:20.402] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//dacParameters35_C15.dat
[19:13:20.414] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//tbmParameters_C0b.dat
[19:13:20.414] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//defaultMaskFile.dat
[19:13:20.415] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C15.dat
[19:13:20.499] INFO: clk: 4
[19:13:20.499] INFO: ctr: 4
[19:13:20.499] INFO: sda: 19
[19:13:20.499] INFO: tin: 9
[19:13:20.499] INFO: level: 15
[19:13:20.499] INFO: triggerdelay: 0
[19:13:20.499] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[19:13:20.499] INFO: Log level: INFO
[19:13:20.516] QUIET: Connection to board DTB_WREKRL opened.
[19:13:20.519] 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:
------------------------------------------------------
[19:13:20.522] INFO: RPC call hashes of host and DTB match: 398089610
[19:13:22.052] INFO: DUT info:
[19:13:22.052] INFO: The DUT currently contains the following objects:
[19:13:22.052] INFO: 2 TBM Cores tbm08c (2 ON)
[19:13:22.052] INFO: TBM Core alpha (0): 7 registers set
[19:13:22.052] INFO: TBM Core beta (1): 7 registers set
[19:13:22.052] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[19:13:22.052] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.052] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.052] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.053] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[19:13:22.456] INFO: enter 'restricted' command line mode
[19:13:22.456] INFO: enter test to run
[19:13:30.096] INFO: test: PixelAlive no parameter change
[19:13:30.096] INFO: running: pixelalive
[19:13:30.105] INFO: ----------------------------------------------------------------------
[19:13:30.105] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[19:13:30.105] INFO: ----------------------------------------------------------------------
[19:13:30.429] INFO: Expecting 41600 events.
[19:13:34.849] INFO: 41600 events read in total (3701ms).
[19:13:35.013] INFO: Test took 4905ms.
[19:13:35.029] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:13:35.513] INFO: PixTestAlive::aliveTest() done
[19:13:35.514] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[19:13:35.578] INFO: enter test to run
[19:14:00.288] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[19:14:00.288] INFO: running: highrate
[19:14:00.288] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[19:14:00.498] INFO: ----------------------------------------------------------------------
[19:14:00.498] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[19:14:00.498] INFO: ----------------------------------------------------------------------
[19:14:00.498] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[19:14:00.498] INFO: edge/corner pixel THR is adjusted
[19:14:00.498] INFO: PixTestHighRate::trimHotPixels: step 0...
[19:14:01.457] INFO: Collecting data for 5 seconds...
[19:14:06.474] INFO: Done with hot pixel readout
[19:14:18.110] INFO: PixTest:: pg_setup set to default.

[19:14:18.111] INFO: 4 hot pixels found in step 0
[19:14:19.099] INFO: Collecting data for 5 seconds...
[19:14:24.115] INFO: Done with hot pixel readout
[19:14:35.793] INFO: PixTest:: pg_setup set to default.
[19:14:35.794] INFO: 10 hot pixels found in step 1
[19:14:36.786] INFO: Collecting data for 5 seconds...
[19:14:41.803] INFO: Done with hot pixel readout
[19:14:53.398] INFO: PixTest:: pg_setup set to default.
[19:14:53.399] INFO: 1 hot pixels found in step 2
[19:14:54.391] INFO: Collecting data for 5 seconds...
[19:14:59.407] INFO: Done with hot pixel readout
[19:15:11.065] INFO: PixTest:: pg_setup set to default.
[19:15:11.066] INFO: 2 hot pixels found in step 3
[19:15:12.056] INFO: Collecting data for 5 seconds...
[19:15:17.072] INFO: Done with hot pixel readout
[19:15:28.739] INFO: PixTest:: pg_setup set to default.
[19:15:28.740] INFO: 6 hot pixels found in step 4
[19:15:29.732] INFO: Collecting data for 5 seconds...
[19:15:34.748] INFO: Done with hot pixel readout
[19:15:46.385] INFO: PixTest:: pg_setup set to default.
[19:15:46.386] INFO: 3 hot pixels found in step 5
[19:15:47.378] INFO: Collecting data for 5 seconds...
[19:15:52.395] INFO: Done with hot pixel readout
[19:16:04.040] INFO: PixTest:: pg_setup set to default.
[19:16:04.041] INFO: 2 hot pixels found in step 6
[19:16:05.032] INFO: Collecting data for 5 seconds...
[19:16:10.049] INFO: Done with hot pixel readout
[19:16:21.766] INFO: PixTest:: pg_setup set to default.
[19:16:21.767] INFO: 2 hot pixels found in step 7
[19:16:22.759] INFO: Collecting data for 5 seconds...
[19:16:27.776] INFO: Done with hot pixel readout
[19:16:39.420] INFO: PixTest:: pg_setup set to default.
[19:16:39.421] INFO: 6 hot pixels found in step 8
[19:16:40.413] INFO: Collecting data for 5 seconds...
[19:16:45.429] INFO: Done with hot pixel readout
[19:16:57.069] INFO: PixTest:: pg_setup set to default.
[19:16:57.070] INFO: 6 hot pixels found in step 9
[19:16:58.063] INFO: Collecting data for 5 seconds...
[19:17:03.079] INFO: Done with hot pixel readout
[19:17:14.710] INFO: PixTest:: pg_setup set to default.
[19:17:14.710] INFO: 0 hot pixels found in step 10
[19:17:14.746] INFO: 0 hot pixels could not be trimmed and have been masked.
[19:17:14.750] INFO: PixTest::trimHotPixels() done
[19:17:14.750] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C0.dat
[19:17:14.774] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C1.dat
[19:17:14.786] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C2.dat
[19:17:14.792] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C3.dat
[19:17:14.797] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C4.dat
[19:17:14.803] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C5.dat
[19:17:14.809] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C6.dat
[19:17:14.814] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C7.dat
[19:17:14.819] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C8.dat
[19:17:14.825] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C9.dat
[19:17:14.831] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C10.dat
[19:17:14.836] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C11.dat
[19:17:14.842] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C12.dat
[19:17:14.847] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C13.dat
[19:17:14.852] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C14.dat
[19:17:14.858] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C15.dat
[19:17:14.864] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//defaultMaskFile.dat
[19:17:14.882] INFO: enter test to run
[19:17:48.046] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[19:17:48.046] INFO: running: highrate
[19:17:48.051] INFO: ----------------------------------------------------------------------
[19:17:48.051] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[19:17:48.051] INFO: ----------------------------------------------------------------------
[19:17:48.051] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[19:17:48.051] INFO: edge/corner pixel THR is adjusted
[19:17:48.051] INFO: PixTestHighRate::trimHotPixels: step 0...
[19:17:49.008] INFO: Collecting data for 1 seconds...
[19:17:50.012] INFO: Done with hot pixel readout
[19:17:54.034] INFO: PixTest:: pg_setup set to default.
[19:17:54.035] INFO: 0 hot pixels found in step 0
[19:17:54.040] INFO: 0 hot pixels could not be trimmed and have been masked.
[19:17:54.130] INFO: PixTest::trimHotPixels() done
[19:17:54.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C0.dat
[19:17:54.138] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C1.dat
[19:17:54.143] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C2.dat
[19:17:54.148] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C3.dat
[19:17:54.153] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C4.dat
[19:17:54.159] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C5.dat
[19:17:54.164] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C6.dat
[19:17:54.169] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C7.dat
[19:17:54.174] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C8.dat
[19:17:54.180] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C9.dat
[19:17:54.185] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C10.dat
[19:17:54.190] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C11.dat
[19:17:54.196] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C12.dat
[19:17:54.201] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C13.dat
[19:17:54.206] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C14.dat
[19:17:54.211] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//trimParameters35_C15.dat
[19:17:54.216] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-5-04_FPIXTest-17C-FNAL-161003-1228-150V_2016-10-03_12h28m_1475515713/000_FPIXTest_p17//defaultMaskFile.dat
[19:17:54.226] INFO: enter test to run
[19:18:18.438] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[19:18:18.438] INFO: running: xray
[19:18:18.439] INFO: ----------------------------------------------------------------------
[19:18:18.439] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[19:18:18.439] INFO: ----------------------------------------------------------------------
[19:18:19.402] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[19:18:31.055] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[19:19:00.559] INFO: Resuming triggers.
[19:19:12.215] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[19:19:41.859] INFO: Resuming triggers.
[19:19:53.515] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[19:20:23.059] INFO: Resuming triggers.
[19:20:34.715] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[19:21:04.319] INFO: Resuming triggers.
[19:21:15.976] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[19:21:45.549] INFO: Resuming triggers.
[19:21:57.208] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[19:22:27.107] INFO: Resuming triggers.
[19:22:38.768] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[19:23:07.844] INFO: Resuming triggers.
[19:23:19.505] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[19:23:49.404] INFO: Resuming triggers.
[19:23:56.482] INFO: data taking finished, elapsed time: 100 seconds.
[19:24:14.888] INFO: PixTest:: pg_setup set to default.
[19:24:14.892] INFO: PixTestXray::doPhRun() done
[19:24:15.060] INFO: enter test to run
[19:24:37.596] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[19:24:37.596] INFO: running: xray
[19:24:37.597] INFO: ----------------------------------------------------------------------
[19:24:37.597] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[19:24:37.597] INFO: ----------------------------------------------------------------------
[19:24:38.562] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[19:24:45.385] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[19:25:16.803] INFO: Resuming triggers.
[19:25:23.630] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[19:25:55.126] INFO: Resuming triggers.
[19:26:01.953] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[19:26:33.382] INFO: Resuming triggers.
[19:26:40.206] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[19:27:10.636] INFO: Resuming triggers.
[19:27:17.459] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[19:27:47.728] INFO: Resuming triggers.
[19:27:54.550] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[19:28:24.852] INFO: Resuming triggers.
[19:28:31.670] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[19:29:01.939] INFO: Resuming triggers.
[19:29:08.761] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[19:29:39.046] INFO: Resuming triggers.
[19:29:45.867] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[19:30:16.056] INFO: Resuming triggers.
[19:30:22.874] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[19:30:53.101] INFO: Resuming triggers.
[19:30:59.920] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[19:31:30.187] INFO: Resuming triggers.
[19:31:37.011] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[19:32:07.254] INFO: Resuming triggers.
[19:32:14.079] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[19:32:44.324] INFO: Resuming triggers.
[19:32:51.145] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[19:33:21.472] INFO: Resuming triggers.
[19:33:26.299] INFO: data taking finished, elapsed time: 100 seconds.
[19:33:47.857] INFO: PixTest:: pg_setup set to default.
[19:33:47.860] INFO: PixTestXray::doPhRun() done
[19:33:47.006] INFO: enter test to run
[19:34:44.200] INFO: test: HighRate no parameter change
[19:34:44.200] INFO: running: highrate
[19:34:44.212] INFO: ----------------------------------------------------------------------
[19:34:44.212] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[19:34:44.212] INFO: ----------------------------------------------------------------------
[19:34:44.367] INFO: Expecting 768 events.
[19:34:45.500] INFO: 768 events read in total (419ms).
[19:34:45.501] INFO: Test took 1268ms.
[19:34:46.304] INFO: Expecting 41600 events.
[19:34:49.390] INFO: 41600 events read in total (2559ms).
[19:34:49.391] INFO: Test took 3860ms.
[19:34:49.423] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:34:50.155] INFO: Expecting 41600 events.
[19:34:53.340] INFO: 41600 events read in total (2658ms).
[19:34:53.341] INFO: Test took 3902ms.
[19:34:53.373] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:34:54.103] INFO: Expecting 41600 events.
[19:34:57.402] INFO: 41600 events read in total (2772ms).
[19:34:57.403] INFO: Test took 4012ms.
[19:34:57.446] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:34:58.143] INFO: Expecting 41600 events.
[19:35:01.355] INFO: 41600 events read in total (2685ms).
[19:35:01.356] INFO: Test took 3885ms.
[19:35:01.389] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:02.111] INFO: Expecting 41600 events.
[19:35:05.356] INFO: 41600 events read in total (2719ms).
[19:35:05.357] INFO: Test took 3951ms.
[19:35:05.391] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:06.107] INFO: Expecting 41600 events.
[19:35:09.376] INFO: 41600 events read in total (2742ms).
[19:35:09.377] INFO: Test took 3968ms.
[19:35:09.411] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:10.134] INFO: Expecting 41600 events.
[19:35:13.354] INFO: 41600 events read in total (2693ms).
[19:35:13.355] INFO: Test took 3927ms.
[19:35:13.388] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:14.109] INFO: Expecting 41600 events.
[19:35:17.349] INFO: 41600 events read in total (2713ms).
[19:35:17.350] INFO: Test took 3943ms.
[19:35:17.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:18.104] INFO: Expecting 41600 events.
[19:35:21.395] INFO: 41600 events read in total (2764ms).
[19:35:21.396] INFO: Test took 3995ms.
[19:35:21.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:22.153] INFO: Expecting 41600 events.
[19:35:25.449] INFO: 41600 events read in total (2769ms).
[19:35:25.450] INFO: Test took 4002ms.
[19:35:25.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:26.206] INFO: Expecting 41600 events.
[19:35:29.512] INFO: 41600 events read in total (2780ms).
[19:35:29.513] INFO: Test took 4013ms.
[19:35:29.548] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:30.271] INFO: Expecting 41600 events.
[19:35:33.341] INFO: 41600 events read in total (2543ms).
[19:35:33.342] INFO: Test took 3777ms.
[19:35:33.375] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:34.086] INFO: Expecting 41600 events.
[19:35:37.368] INFO: 41600 events read in total (2755ms).
[19:35:37.369] INFO: Test took 3976ms.
[19:35:37.403] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:38.127] INFO: Expecting 41600 events.
[19:35:41.366] INFO: 41600 events read in total (2712ms).
[19:35:41.367] INFO: Test took 3947ms.
[19:35:41.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:42.126] INFO: Expecting 41600 events.
[19:35:45.284] INFO: 41600 events read in total (2632ms).
[19:35:45.285] INFO: Test took 3867ms.
[19:35:45.319] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:46.039] INFO: Expecting 41600 events.
[19:35:49.306] INFO: 41600 events read in total (2740ms).
[19:35:49.306] INFO: Test took 3971ms.
[19:35:49.340] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:50.062] INFO: Expecting 41600 events.
[19:35:53.245] INFO: 41600 events read in total (2656ms).
[19:35:53.246] INFO: Test took 3887ms.
[19:35:53.285] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:53.004] INFO: Expecting 41600 events.
[19:35:57.333] INFO: 41600 events read in total (2802ms).
[19:35:57.334] INFO: Test took 4031ms.
[19:35:57.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:58.095] INFO: Expecting 41600 events.
[19:36:01.354] INFO: 41600 events read in total (2732ms).
[19:36:01.355] INFO: Test took 3968ms.
[19:36:01.389] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:36:02.112] INFO: Expecting 41600 events.
[19:36:05.275] INFO: 41600 events read in total (2636ms).
[19:36:05.276] INFO: Test took 3870ms.
[19:36:05.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:36:05.670] INFO: enter test to run
[19:36:13.551] INFO: test: HighRate no parameter change
[19:36:13.551] INFO: running: highrate
[19:36:13.552] INFO: ----------------------------------------------------------------------
[19:36:13.552] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:36:13.552] INFO: ----------------------------------------------------------------------
[19:36:14.171] INFO: Expecting 208000 events.
[19:36:25.950] INFO: 208000 events read in total (11252ms).
[19:36:25.953] INFO: Test took 12395ms.
[19:36:26.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:36:26.348] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[19:36:26.348] INFO: number of red-efficiency pixels: 74 42 75 169 129 146 136 103 84 92 109 72 83 46 17 30
[19:36:26.348] INFO: number of X-ray hits detected: 65316 43262 66234 107776 109647 112140 114298 80702 70760 90189 87161 72949 76654 45085 17532 22850
[19:36:26.348] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:36:26.348] INFO: number of Vcal hits detected: 207925 207958 207920 207826 207861 207848 207857 207848 207916 207906 207888 207928 207915 207953 207983 207969
[19:36:26.348] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[19:36:26.348] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[19:36:26.348] INFO: X-ray hit rate [MHz/cm2]: 19.1 12.7 19.4 31.6 32.1 32.9 33.5 23.7 20.7 26.4 25.5 21.4 22.5 13.2 5.1 6.7
[19:36:26.348] INFO: PixTestHighRate::doXPixelAlive() done
[19:36:26.395] INFO: PixTest:: pg_setup set to default.
[19:36:26.410] INFO: enter test to run
[19:37:01.951] INFO: test: HighRate no parameter change
[19:37:01.951] INFO: running: highrate
[19:37:01.952] INFO: ----------------------------------------------------------------------
[19:37:01.952] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:37:01.952] INFO: ----------------------------------------------------------------------
[19:37:02.577] INFO: Expecting 208000 events.
[19:37:16.016] INFO: 208000 events read in total (12913ms).
[19:37:16.021] INFO: Test took 14061ms.
[19:37:16.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:37:16.596] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[19:37:16.596] INFO: number of red-efficiency pixels: 236 125 261 534 396 428 395 254 193 319 342 195 186 125 36 54
[19:37:16.596] INFO: number of X-ray hits detected: 132897 88702 134145 218662 222299 227177 231708 163136 143437 181414 177598 148202 156639 91992 35615 46678
[19:37:16.596] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:37:16.596] INFO: number of Vcal hits detected: 207746 207870 207709 207409 207557 207534 207569 207678 207795 207660 207635 207799 207802 207871 207963 207945
[19:37:16.596] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.8 99.8 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[19:37:16.596] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[19:37:16.596] INFO: X-ray hit rate [MHz/cm2]: 39.0 26.0 39.3 64.1 65.2 66.6 67.9 47.8 42.0 53.2 52.1 43.4 45.9 27.0 10.4 13.7
[19:37:16.596] INFO: PixTestHighRate::doXPixelAlive() done
[19:37:16.641] INFO: PixTest:: pg_setup set to default.
[19:37:16.652] INFO: enter test to run
[19:37:43.710] INFO: test: HighRate no parameter change
[19:37:43.710] INFO: running: highrate
[19:37:43.712] INFO: ----------------------------------------------------------------------
[19:37:43.712] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:37:43.712] INFO: ----------------------------------------------------------------------
[19:37:44.332] INFO: Expecting 208000 events.
[19:37:59.811] INFO: 208000 events read in total (14952ms).
[19:37:59.818] INFO: Test took 16097ms.
[19:38:00.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:38:00.605] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[19:38:00.606] INFO: number of red-efficiency pixels: 587 268 689 1305 1014 1164 1079 593 482 810 841 538 509 297 55 88
[19:38:00.606] INFO: number of X-ray hits detected: 211540 141385 213334 347370 353405 359658 367694 260052 228823 288731 284268 235495 248723 146268 56819 74539
[19:38:00.606] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:38:00.606] INFO: number of Vcal hits detected: 207246 207716 207008 206219 206740 206515 206610 207231 207459 207070 207008 207406 207435 207674 207944 207910
[19:38:00.606] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.2 99.5 99.4 99.4 99.7 99.8 99.6 99.6 99.7 99.8 99.9 100.0 100.0
[19:38:00.606] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.5 99.1 99.4 99.3 99.3 99.6 99.7 99.6 99.5 99.7 99.7 99.8 100.0 100.0
[19:38:00.606] INFO: X-ray hit rate [MHz/cm2]: 62.0 41.4 62.5 101.8 103.6 105.4 107.8 76.2 67.1 84.6 83.3 69.0 72.9 42.9 16.7 21.8
[19:38:00.606] INFO: PixTestHighRate::doXPixelAlive() done
[19:38:00.658] INFO: PixTest:: pg_setup set to default.
[19:38:00.674] INFO: enter test to run
[19:38:17.583] INFO: test: exit no parameter change
[19:38:17.985] QUIET: Connection to board 33 closed.
[19:38:17.986] INFO: pXar: this is the end, my friend