[09:13:38.001]     INFO: *** Welcome to pxar ***
[09:13:38.001]     INFO: *** Today: 2016/09/22
[09:13:39.020]     INFO: *** Version: v1.9.0-818-g96727
[09:13:39.020]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//dacParameters35_C15.dat
[09:13:39.021]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:13:39.021]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//defaultMaskFile.dat
[09:13:39.021]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C15.dat
[09:13:39.093]     INFO:         clk: 4
[09:13:39.093]     INFO:         ctr: 4
[09:13:39.093]     INFO:         sda: 19
[09:13:39.093]     INFO:         tin: 9
[09:13:39.093]     INFO:         level: 15
[09:13:39.093]     INFO:         triggerdelay: 0
[09:13:39.093]    QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[09:13:39.093]     INFO: Log level: INFO
[09:13:39.109]    QUIET: Connection to board DTB_WREKRL opened.
[09:13:39.112]     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:     
------------------------------------------------------
[09:13:39.115]     INFO: RPC call hashes of host and DTB match: 398089610
[09:13:40.649]     INFO: DUT info: 
[09:13:40.649]     INFO: The DUT currently contains the following objects:
[09:13:40.649]     INFO:  2 TBM Cores tbm08c (2 ON)
[09:13:40.649]     INFO: 	TBM Core alpha (0): 7 registers set
[09:13:40.649]     INFO: 	TBM Core beta  (1): 7 registers set
[09:13:40.649]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:13:40.649]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.649]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.650]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:40.650]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:41.053]     INFO: enter 'restricted' command line mode
[09:13:41.053]     INFO: enter test to run
[09:13:42.910]     INFO:   test: PixelAlive no parameter change
[09:13:42.910]     INFO:   running: pixelalive
[09:13:42.919]     INFO:    ----------------------------------------------------------------------
[09:13:42.919]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:13:42.919]     INFO:    ----------------------------------------------------------------------
[09:13:43.244]     INFO: Expecting 41600 events.
[09:13:47.597]     INFO: 41600 events read in total (3634ms).
[09:13:47.766]     INFO: Test took 4845ms.
[09:13:47.781]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:13:48.046]     INFO: PixTestAlive::aliveTest() done
[09:13:48.046]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[09:13:48.075]     INFO: enter test to run
[09:14:16.901]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:14:16.901]     INFO:   running: highrate
[09:14:16.902]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:14:17.113]     INFO:    ----------------------------------------------------------------------
[09:14:17.113]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:14:17.113]     INFO:    ----------------------------------------------------------------------
[09:14:17.113]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:14:17.113]     INFO: edge/corner pixel THR is adjusted
[09:14:17.113]     INFO: PixTestHighRate::trimHotPixels: step 0...
[09:14:18.072]     INFO: Collecting data for 5 seconds...
[09:14:23.089]     INFO: Done with hot pixel readout
[09:14:33.820]     INFO: PixTest::       pg_setup set to default.
[09:14:33.821]     INFO: 1 hot pixels found in step 0
[09:14:34.811]     INFO: Collecting data for 5 seconds...
[09:14:39.830]     INFO: Done with hot pixel readout
[09:14:51.480]     INFO: PixTest::       pg_setup set to default.
[09:14:51.481]     INFO: 1 hot pixels found in step 1
[09:14:52.475]     INFO: Collecting data for 5 seconds...
[09:14:57.493]     INFO: Done with hot pixel readout
[09:15:09.167]     INFO: PixTest::       pg_setup set to default.
[09:15:09.168]     INFO: 5 hot pixels found in step 2
[09:15:10.161]     INFO: Collecting data for 5 seconds...
[09:15:15.179]     INFO: Done with hot pixel readout
[09:15:26.686]     INFO: PixTest::       pg_setup set to default.
[09:15:26.687]     INFO: 1 hot pixels found in step 3
[09:15:27.681]     INFO: Collecting data for 5 seconds...
[09:15:32.699]     INFO: Done with hot pixel readout
[09:15:44.547]     INFO: PixTest::       pg_setup set to default.
[09:15:44.548]     INFO: 3 hot pixels found in step 4
[09:15:45.541]     INFO: Collecting data for 5 seconds...
[09:15:50.561]     INFO: Done with hot pixel readout
[09:16:02.534]     INFO: PixTest::       pg_setup set to default.
[09:16:02.535]     INFO: 1 hot pixels found in step 5
[09:16:03.527]     INFO: Collecting data for 5 seconds...
[09:16:08.547]     INFO: Done with hot pixel readout
[09:16:20.527]     INFO: PixTest::       pg_setup set to default.
[09:16:20.528]     INFO: 0 hot pixels found in step 6
[09:16:20.566]     INFO: 0 hot pixels could not be trimmed and have been masked.
[09:16:20.704]     INFO: PixTest::trimHotPixels() done
[09:16:20.802]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C0.dat
[09:16:20.881]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C1.dat
[09:16:20.956]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C2.dat
[09:16:20.963]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C3.dat
[09:16:20.969]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C4.dat
[09:16:20.974]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C5.dat
[09:16:20.979]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C6.dat
[09:16:20.985]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C7.dat
[09:16:20.990]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C8.dat
[09:16:20.996]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C9.dat
[09:16:20.001]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C10.dat
[09:16:21.033]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C11.dat
[09:16:21.045]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C12.dat
[09:16:21.053]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C13.dat
[09:16:21.059]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C14.dat
[09:16:21.064]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C15.dat
[09:16:21.069]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//defaultMaskFile.dat
[09:16:21.085]     INFO: enter test to run
[09:16:43.132]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:16:43.133]     INFO:   running: highrate
[09:16:43.137]     INFO:    ----------------------------------------------------------------------
[09:16:43.137]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:16:43.137]     INFO:    ----------------------------------------------------------------------
[09:16:43.137]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:16:43.137]     INFO: edge/corner pixel THR is adjusted
[09:16:43.137]     INFO: PixTestHighRate::trimHotPixels: step 0...
[09:16:44.095]     INFO: Collecting data for 1 seconds...
[09:16:45.099]     INFO: Done with hot pixel readout
[09:16:49.212]     INFO: PixTest::       pg_setup set to default.
[09:16:49.213]     INFO: 0 hot pixels found in step 0
[09:16:49.220]     INFO: 0 hot pixels could not be trimmed and have been masked.
[09:16:49.302]     INFO: PixTest::trimHotPixels() done
[09:16:49.302]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C0.dat
[09:16:49.334]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C1.dat
[09:16:49.346]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C2.dat
[09:16:49.358]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C3.dat
[09:16:49.364]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C4.dat
[09:16:49.370]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C5.dat
[09:16:49.375]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C6.dat
[09:16:49.381]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C7.dat
[09:16:49.386]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C8.dat
[09:16:49.392]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C9.dat
[09:16:49.397]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C10.dat
[09:16:49.403]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C11.dat
[09:16:49.408]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C12.dat
[09:16:49.414]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C13.dat
[09:16:49.419]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C14.dat
[09:16:49.425]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//trimParameters35_C15.dat
[09:16:49.430]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-1-33_FPIXTest-17C-FNAL-160916-1156-150V_2016-09-16_11h56m_1474044985/000_FPIXTest_p17//defaultMaskFile.dat
[09:16:49.440]     INFO: enter test to run
[09:17:17.364]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[09:17:17.364]     INFO:   running: xray
[09:17:17.380]     INFO:    ----------------------------------------------------------------------
[09:17:17.380]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[09:17:17.380]     INFO:    ----------------------------------------------------------------------
[09:17:18.370]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[09:17:29.994]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:17:59.489]     INFO: Resuming triggers.
[09:18:11.112]     INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[09:18:40.450]     INFO: Resuming triggers.
[09:18:52.081]     INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[09:19:21.471]     INFO: Resuming triggers.
[09:19:33.095]     INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[09:20:02.263]     INFO: Resuming triggers.
[09:20:13.885]     INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[09:20:43.329]     INFO: Resuming triggers.
[09:20:54.951]     INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[09:21:24.413]     INFO: Resuming triggers.
[09:21:36.039]     INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[09:22:05.431]     INFO: Resuming triggers.
[09:22:17.051]     INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[09:22:46.504]     INFO: Resuming triggers.
[09:22:53.847]     INFO: data taking finished, elapsed time: 100 seconds.
[09:23:12.595]     INFO: PixTest::       pg_setup set to default.
[09:23:12.598]     INFO: PixTestXray::doPhRun() done
[09:23:12.788]     INFO: enter test to run
[09:25:23.425]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[09:25:23.425]     INFO:   running: xray
[09:25:23.426]     INFO:    ----------------------------------------------------------------------
[09:25:23.426]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[09:25:23.426]     INFO:    ----------------------------------------------------------------------
[09:25:24.388]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[09:25:31.176]     INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:26:02.017]     INFO: Resuming triggers.
[09:26:08.807]     INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[09:26:39.723]     INFO: Resuming triggers.
[09:26:46.510]     INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[09:27:17.585]     INFO: Resuming triggers.
[09:27:24.379]     INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[09:27:55.405]     INFO: Resuming triggers.
[09:28:02.195]     INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[09:28:33.768]     INFO: Resuming triggers.
[09:28:40.554]     INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[09:29:12.381]     INFO: Resuming triggers.
[09:29:19.171]     INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[09:29:50.794]     INFO: Resuming triggers.
[09:29:57.583]     INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[09:30:28.623]     INFO: Resuming triggers.
[09:30:35.407]     INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[09:31:05.626]     INFO: Resuming triggers.
[09:31:12.416]     INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[09:31:42.634]     INFO: Resuming triggers.
[09:31:49.424]     INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[09:32:19.699]     INFO: Resuming triggers.
[09:32:26.489]     INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[09:32:56.680]     INFO: Resuming triggers.
[09:33:03.467]     INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[09:33:33.698]     INFO: Resuming triggers.
[09:33:40.487]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[09:34:10.647]     INFO: Resuming triggers.
[09:34:15.953]     INFO: data taking finished, elapsed time: 100 seconds.
[09:34:39.715]     INFO: PixTest::       pg_setup set to default.
[09:34:39.719]     INFO: PixTestXray::doPhRun() done
[09:34:39.867]     INFO: enter test to run
[09:35:07.781]     INFO:   test: HighRate no parameter change
[09:35:07.781]     INFO:   running: highrate
[09:35:07.797]     INFO:    ----------------------------------------------------------------------
[09:35:07.797]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:35:07.797]     INFO:    ----------------------------------------------------------------------
[09:35:07.952]     INFO: Expecting 768 events.
[09:35:09.086]     INFO: 768 events read in total (419ms).
[09:35:09.086]     INFO: Test took 1269ms.
[09:35:09.890]     INFO: Expecting 41600 events.
[09:35:12.993]     INFO: 41600 events read in total (2577ms).
[09:35:12.994]     INFO: Test took 3900ms.
[09:35:13.026]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:13.756]     INFO: Expecting 41600 events.
[09:35:16.965]     INFO: 41600 events read in total (2682ms).
[09:35:16.966]     INFO: Test took 3922ms.
[09:35:16.999]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:17.722]     INFO: Expecting 41600 events.
[09:35:20.966]     INFO: 41600 events read in total (2717ms).
[09:35:20.967]     INFO: Test took 3950ms.
[09:35:20.999]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:21.729]     INFO: Expecting 41600 events.
[09:35:24.974]     INFO: 41600 events read in total (2718ms).
[09:35:24.975]     INFO: Test took 3957ms.
[09:35:25.008]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:25.736]     INFO: Expecting 41600 events.
[09:35:28.981]     INFO: 41600 events read in total (2719ms).
[09:35:28.982]     INFO: Test took 3955ms.
[09:35:29.015]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:29.742]     INFO: Expecting 41600 events.
[09:35:32.998]     INFO: 41600 events read in total (2729ms).
[09:35:32.999]     INFO: Test took 3966ms.
[09:35:33.032]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:33.755]     INFO: Expecting 41600 events.
[09:35:37.029]     INFO: 41600 events read in total (2747ms).
[09:35:37.030]     INFO: Test took 3979ms.
[09:35:37.063]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:37.785]     INFO: Expecting 41600 events.
[09:35:41.051]     INFO: 41600 events read in total (2739ms).
[09:35:41.052]     INFO: Test took 3971ms.
[09:35:41.087]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:41.810]     INFO: Expecting 41600 events.
[09:35:45.084]     INFO: 41600 events read in total (2747ms).
[09:35:45.085]     INFO: Test took 3979ms.
[09:35:45.119]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:45.846]     INFO: Expecting 41600 events.
[09:35:49.105]     INFO: 41600 events read in total (2733ms).
[09:35:49.106]     INFO: Test took 3969ms.
[09:35:49.140]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:49.866]     INFO: Expecting 41600 events.
[09:35:53.126]     INFO: 41600 events read in total (2733ms).
[09:35:53.127]     INFO: Test took 3969ms.
[09:35:53.161]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:53.886]     INFO: Expecting 41600 events.
[09:35:57.144]     INFO: 41600 events read in total (2731ms).
[09:35:57.145]     INFO: Test took 3964ms.
[09:35:57.179]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:57.905]     INFO: Expecting 41600 events.
[09:36:01.175]     INFO: 41600 events read in total (2744ms).
[09:36:01.176]     INFO: Test took 3980ms.
[09:36:01.210]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:01.933]     INFO: Expecting 41600 events.
[09:36:05.232]     INFO: 41600 events read in total (2772ms).
[09:36:05.233]     INFO: Test took 4004ms.
[09:36:05.268]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:05.990]     INFO: Expecting 41600 events.
[09:36:09.237]     INFO: 41600 events read in total (2720ms).
[09:36:09.238]     INFO: Test took 3951ms.
[09:36:09.271]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:09.993]     INFO: Expecting 41600 events.
[09:36:13.250]     INFO: 41600 events read in total (2731ms).
[09:36:13.251]     INFO: Test took 3963ms.
[09:36:13.285]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:14.012]     INFO: Expecting 41600 events.
[09:36:17.257]     INFO: 41600 events read in total (2718ms).
[09:36:17.258]     INFO: Test took 3955ms.
[09:36:17.292]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:18.017]     INFO: Expecting 41600 events.
[09:36:21.284]     INFO: 41600 events read in total (2740ms).
[09:36:21.285]     INFO: Test took 3975ms.
[09:36:21.318]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:22.041]     INFO: Expecting 41600 events.
[09:36:25.250]     INFO: 41600 events read in total (2682ms).
[09:36:25.251]     INFO: Test took 3914ms.
[09:36:25.285]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:26.012]     INFO: Expecting 41600 events.
[09:36:29.081]     INFO: 41600 events read in total (2542ms).
[09:36:29.082]     INFO: Test took 3780ms.
[09:36:29.115]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:29.474]     INFO: enter test to run
[09:37:09.740]     INFO:   test: HighRate no parameter change
[09:37:09.740]     INFO:   running: highrate
[09:37:09.741]     INFO:    ----------------------------------------------------------------------
[09:37:09.741]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:37:09.741]     INFO:    ----------------------------------------------------------------------
[09:37:10.359]     INFO: Expecting 208000 events.
[09:37:22.209]     INFO: 208000 events read in total (11323ms).
[09:37:22.212]     INFO: Test took 12462ms.
[09:37:22.351]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:22.601]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[09:37:22.601]     INFO: number of red-efficiency pixels:    83   36   75  144  130  169  133  112  122  123  110  121  103   72   23   20
[09:37:22.601]     INFO: number of X-ray hits detected:    61332 41288 65646 101125 110345 114007 113148 79697 83923 94804 92694 79864 82674 49235 21882 25476
[09:37:22.601]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:37:22.601]     INFO: number of Vcal hits detected:  207917 207963 207922 207844 207867 207829 207861 207883 207877 207875 207888 207878 207894 207928 207977 207980
[09:37:22.601]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[09:37:22.601]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[09:37:22.601]     INFO: X-ray hit rate [MHz/cm2]:  18.0 12.1 19.2 29.6 32.3 33.4 33.2 23.4 24.6 27.8 27.2 23.4 24.2 14.4 6.4 7.5
[09:37:22.601]     INFO: PixTestHighRate::doXPixelAlive() done
[09:37:22.648]     INFO: PixTest::       pg_setup set to default.
[09:37:22.660]     INFO: enter test to run
[09:38:08.356]     INFO:   test: HighRate no parameter change
[09:38:08.356]     INFO:   running: highrate
[09:38:08.357]     INFO:    ----------------------------------------------------------------------
[09:38:08.357]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:38:08.357]     INFO:    ----------------------------------------------------------------------
[09:38:08.976]     INFO: Expecting 208000 events.
[09:38:22.646]     INFO: 208000 events read in total (13143ms).
[09:38:22.651]     INFO: Test took 14285ms.
[09:38:22.932]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:23.229]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[09:38:23.229]     INFO: number of red-efficiency pixels:   208  105  230  372  427  519  411  265  320  300  295  313  296  188   54   43
[09:38:23.229]     INFO: number of X-ray hits detected:    122832 82112 131781 201256 219707 226460 225408 158190 167297 189602 185326 159100 163778 98624 44361 50595
[09:38:23.229]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:38:23.229]     INFO: number of Vcal hits detected:  207780 207891 207751 207610 207542 207419 207553 207704 207654 207681 207682 207672 207690 207798 207944 207956
[09:38:23.229]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.9 99.8 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[09:38:23.229]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[09:38:23.229]     INFO: X-ray hit rate [MHz/cm2]:  36.0 24.1 38.6 59.0 64.4 66.4 66.1 46.4 49.0 55.6 54.3 46.6 48.0 28.9 13.0 14.8
[09:38:23.229]     INFO: PixTestHighRate::doXPixelAlive() done
[09:38:23.275]     INFO: PixTest::       pg_setup set to default.
[09:38:23.288]     INFO: enter test to run
[09:38:47.467]     INFO:   test: HighRate no parameter change
[09:38:47.468]     INFO:   running: highrate
[09:38:47.469]     INFO:    ----------------------------------------------------------------------
[09:38:47.469]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:38:47.469]     INFO:    ----------------------------------------------------------------------
[09:38:48.093]     INFO: Expecting 208000 events.
[09:39:03.278]     INFO: 208000 events read in total (14659ms).
[09:39:03.286]     INFO: Test took 15809ms.
[09:39:03.711]     INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:04.060]     INFO: number of dead pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
[09:39:04.060]     INFO: number of red-efficiency pixels:   431  226  511  968  983 1346  949  595  641  687  629  661  727  436   88   94
[09:39:04.060]     INFO: number of X-ray hits detected:    189524 127957 203953 311596 340796 351135 348859 246531 259047 291110 285892 246461 254589 153392 69012 78885
[09:39:04.060]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:39:04.060]     INFO: number of Vcal hits detected:  207501 207750 207369 206810 206777 206217 206814 207287 207247 207230 207283 207243 207151 207502 207910 207905
[09:39:04.060]     INFO: Vcal hit fiducial efficiency (%):  99.8 99.9 99.7 99.5 99.5 99.2 99.5 99.7 99.7 99.7 99.7 99.7 99.6 99.8 100.0 100.0
[09:39:04.060]     INFO: Vcal hit overall efficiency (%):  99.8 99.9 99.7 99.4 99.4 99.1 99.4 99.7 99.6 99.6 99.7 99.6 99.6 99.8 100.0 100.0
[09:39:04.060]     INFO: X-ray hit rate [MHz/cm2]:  55.6 37.5 59.8 91.3 99.9 102.9 102.3 72.3 75.9 85.3 83.8 72.2 74.6 45.0 20.2 23.1
[09:39:04.060]     INFO: PixTestHighRate::doXPixelAlive() done
[09:39:04.107]     INFO: PixTest::       pg_setup set to default.
[09:39:04.121]     INFO: enter test to run
[09:39:06.907]     INFO:   test: exit no parameter change
[09:39:07.295]    QUIET: Connection to board 33 closed.
[09:39:07.308]     INFO: pXar: this is the end, my friend