[12:37:22.440]     INFO: *** Welcome to pxar ***
[12:37:22.440]     INFO: *** Today: 2016/03/31
[12:37:22.601]     INFO: *** Version: prod-12-dirty
[12:37:22.601]     INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//dacParameters35_C15.dat
[12:37:22.612]     INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:37:22.612]     INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//defaultMaskFile.dat
[12:37:22.612]     INFO: MASKED Roc 2 col/row: 51 70
[12:37:22.612]     INFO: MASKED Roc 2 col/row: 51 72
[12:37:22.612]     INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C15.dat
[12:37:22.627]     INFO:   masking Roc 2 col/row: 51 70
[12:37:22.627]     INFO:   masking Roc 2 col/row: 51 72
[12:37:22.693]     INFO:         clk: 4
[12:37:22.693]     INFO:         ctr: 4
[12:37:22.694]     INFO:         sda: 19
[12:37:22.694]     INFO:         tin: 9
[12:37:22.694]     INFO:         level: 15
[12:37:22.694]     INFO:         triggerdelay: 0
[12:37:22.694]    QUIET: Instanciating API for pxar prod-12
[12:37:22.694]     INFO: Log level: INFO
[12:37:22.712]    QUIET: Connection to board DTB_WREKRL opened.
[12:37:22.716]     INFO: DTB startup information
--- DTB info------------------------------------------
Board id:    33
HW version:  DTB1.2
FW version:  4.2
SW version:  4.5
USB id:      DTB_WREKRL
MAC address: 40D855118021
Hostname:    pixelDTB033
Comment:     
------------------------------------------------------
[12:37:22.718]     INFO: RPC call hashes of host and DTB match: 398089610
[12:37:24.248]     INFO: DUT info: 
[12:37:24.248]     INFO: The DUT currently contains the following objects:
[12:37:24.248]     INFO:  2 TBM Cores tbm08c (2 ON)
[12:37:24.248]     INFO: 	TBM Core alpha (0): 7 registers set
[12:37:24.248]     INFO: 	TBM Core beta  (1): 7 registers set
[12:37:24.248]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:37:24.248]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.248]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 2: 19 DACs set, Pixels: 2 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.249]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:24.689]     INFO: enter 'restricted' command line mode
[12:37:24.689]     INFO: enter test to run
[12:37:33.868]     INFO:   test: PixelAlive no parameter change
[12:37:33.868]     INFO:   running: pixelalive
[12:37:33.896]     INFO:    ----------------------------------------------------------------------
[12:37:33.896]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:37:33.896]     INFO:    ----------------------------------------------------------------------
[12:37:33.899]     INFO: ROC 2 masking pixel 51/70
[12:37:33.899]     INFO: ROC 2 masking pixel 51/72
[12:37:34.214]     INFO: Expecting 41600 events.
[12:37:38.536]     INFO: 41600 events read in total (3603ms).
[12:37:38.701]     INFO: Test took 4802ms.
[12:37:38.710]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:38.972]     INFO: PixTestAlive::aliveTest() done with 771 decoding errors
[12:37:38.972]     INFO: number of dead pixels (per ROC):     0    1    3    0    0    0    0    0    0    0    0  160    0    0    0    0
[12:37:38.972]     INFO: ROC 2 masking pixel 51/70
[12:37:38.972]     INFO: ROC 2 masking pixel 51/72
[12:37:39.003]     INFO: enter test to run
[12:38:11.427]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:38:11.427]     INFO:   running: highrate
[12:38:11.428]     INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:38:11.583]     INFO:    ----------------------------------------------------------------------
[12:38:11.583]     INFO:    PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:38:11.583]     INFO:    ----------------------------------------------------------------------
[12:38:11.583]     INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:38:11.583]     INFO: edge/corner pixel THR is adjusted
[12:38:11.583]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:38:12.542]     INFO: Collecting data for 5 seconds...
[12:38:17.559]     INFO: Done with hot pixel readout
[12:38:28.753]     INFO: PixTest::       pg_setup set to default.
[12:38:28.753]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:28.753]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:28.754]     INFO: 2 hot pixels found in step 0
[12:38:28.766]     INFO: 2 hot pixels could not be trimmed and have been masked.
[12:38:28.776]     INFO: PixTest::trimHotPixels() done
[12:38:28.818]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C0.dat
[12:38:28.825]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C1.dat
[12:38:28.833]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C2.dat
[12:38:28.840]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C3.dat
[12:38:28.847]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C4.dat
[12:38:28.855]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C5.dat
[12:38:28.862]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C6.dat
[12:38:28.869]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C7.dat
[12:38:28.876]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C8.dat
[12:38:28.884]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C9.dat
[12:38:28.891]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C10.dat
[12:38:28.898]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C11.dat
[12:38:28.906]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C12.dat
[12:38:28.913]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C13.dat
[12:38:28.920]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C14.dat
[12:38:28.928]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C15.dat
[12:38:28.935]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//defaultMaskFile.dat
[12:38:28.945]     INFO: enter test to run
[12:38:47.627]     INFO:   test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:38:47.627]     INFO:   running: highrate
[12:38:47.631]     INFO:    ----------------------------------------------------------------------
[12:38:47.631]     INFO:    PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:38:47.631]     INFO:    ----------------------------------------------------------------------
[12:38:47.631]     INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:38:47.631]     INFO: edge/corner pixel THR is adjusted
[12:38:47.631]     INFO: PixTestHighRate::trimHotPixels: step 0...
[12:38:48.589]     INFO: Collecting data for 1 seconds...
[12:38:49.593]     INFO: Done with hot pixel readout
[12:38:53.359]     INFO: PixTest::       pg_setup set to default.
[12:38:53.359]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:53.359]  WARNING:   => trimBits already at highest possible threshold, 'real' hot pixel found
[12:38:53.360]     INFO: 2 hot pixels found in step 0
[12:38:53.365]     INFO: 2 hot pixels could not be trimmed and have been masked.
[12:38:53.465]     INFO: PixTest::trimHotPixels() done
[12:38:53.465]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C0.dat
[12:38:53.479]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C1.dat
[12:38:53.487]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C2.dat
[12:38:53.495]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C3.dat
[12:38:53.502]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C4.dat
[12:38:53.510]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C5.dat
[12:38:53.517]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C6.dat
[12:38:53.525]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C7.dat
[12:38:53.533]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C8.dat
[12:38:53.540]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C9.dat
[12:38:53.547]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C10.dat
[12:38:53.555]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C11.dat
[12:38:53.563]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C12.dat
[12:38:53.570]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C13.dat
[12:38:53.577]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C14.dat
[12:38:53.600]     INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C15.dat
[12:38:53.611]     INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-37_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//defaultMaskFile.dat
[12:38:53.622]     INFO: enter test to run
[12:39:09.315]     INFO:   test: Xray setting parameters: ->source=DCLowRate<-
[12:39:09.315]     INFO:   running: xray
[12:39:09.316]     INFO:    ----------------------------------------------------------------------
[12:39:09.316]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:39:09.316]     INFO:    ----------------------------------------------------------------------
[12:39:09.320]     INFO: ROC 2 masking pixel 51/70
[12:39:09.320]     INFO: ROC 2 masking pixel 51/72
[12:39:10.280]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:39:22.163]     INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:39:51.415]     INFO: Resuming triggers.
[12:40:03.296]     INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:40:32.574]     INFO: Resuming triggers.
[12:40:44.456]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:41:13.654]     INFO: Resuming triggers.
[12:41:25.532]     INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:41:54.826]     INFO: Resuming triggers.
[12:42:06.709]     INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:42:35.888]     INFO: Resuming triggers.
[12:42:47.773]     INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[12:43:16.965]     INFO: Resuming triggers.
[12:43:28.852]     INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:43:58.202]     INFO: Resuming triggers.
[12:44:10.088]     INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:44:39.341]     INFO: Resuming triggers.
[12:44:44.605]     INFO: data taking finished, elapsed time: 100 seconds.
[12:44:57.885]     INFO: PixTest::       pg_setup set to default.
[12:44:57.888]     INFO: PixTestXray::doPhRun() done
[12:44:58.024]     INFO: enter test to run
[12:45:24.752]     INFO:   test: Xray setting parameters: ->source=DCHighRate<-
[12:45:24.752]     INFO:   running: xray
[12:45:24.753]     INFO:    ----------------------------------------------------------------------
[12:45:24.753]     INFO:    PixTestXray::doPhRun() fParRunSeconds = 100
[12:45:24.753]     INFO:    ----------------------------------------------------------------------
[12:45:24.757]     INFO: ROC 2 masking pixel 51/70
[12:45:24.757]     INFO: ROC 2 masking pixel 51/72
[12:45:25.718]     INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds,  fEventsMax = 10000000
[12:45:32.901]     INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[12:46:00.069]     INFO: Resuming triggers.
[12:46:07.255]     INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[12:46:37.357]     INFO: Resuming triggers.
[12:46:44.543]     INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:47:14.596]     INFO: Resuming triggers.
[12:47:21.787]     INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[12:47:51.769]     INFO: Resuming triggers.
[12:47:58.958]     INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:48:29.059]     INFO: Resuming triggers.
[12:48:36.244]     INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[12:49:06.289]     INFO: Resuming triggers.
[12:49:13.478]     INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[12:49:43.648]     INFO: Resuming triggers.
[12:49:50.833]     INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:50:20.923]     INFO: Resuming triggers.
[12:50:28.108]     INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[12:50:58.187]     INFO: Resuming triggers.
[12:51:05.375]     INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[12:51:35.426]     INFO: Resuming triggers.
[12:51:42.610]     INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[12:52:12.737]     INFO: Resuming triggers.
[12:52:19.922]     INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[12:52:49.001]     INFO: Resuming triggers.
[12:52:57.184]     INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:53:27.235]     INFO: Resuming triggers.
[12:53:34.144]     INFO: data taking finished, elapsed time: 100 seconds.
[12:54:03.287]     INFO: PixTest::       pg_setup set to default.
[12:54:03.290]     INFO: PixTestXray::doPhRun() done
[12:54:03.438]     INFO: enter test to run
[12:54:36.772]     INFO:   test: HighRate no parameter change
[12:54:36.772]     INFO:   running: highrate
[12:54:36.773]     INFO:    ----------------------------------------------------------------------
[12:54:36.773]     INFO:    PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:54:36.773]     INFO:    ----------------------------------------------------------------------
[12:54:36.914]     INFO: Expecting 768 events.
[12:54:38.052]     INFO: 768 events read in total (418ms).
[12:54:38.053]     INFO: Test took 1273ms.
[12:54:38.057]     INFO: ROC 2 masking pixel 51/70
[12:54:38.058]     INFO: ROC 2 masking pixel 51/72
[12:54:38.855]     INFO: Expecting 41600 events.
[12:54:41.960]     INFO: 41600 events read in total (2578ms).
[12:54:41.961]     INFO: Test took 3901ms.
[12:54:41.992]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:42.720]     INFO: Expecting 41600 events.
[12:54:45.903]     INFO: 41600 events read in total (2656ms).
[12:54:45.904]     INFO: Test took 3896ms.
[12:54:45.936]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:46.667]     INFO: Expecting 41600 events.
[12:54:49.858]     INFO: 41600 events read in total (2664ms).
[12:54:49.859]     INFO: Test took 3906ms.
[12:54:49.890]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:50.622]     INFO: Expecting 41600 events.
[12:54:53.845]     INFO: 41600 events read in total (2696ms).
[12:54:53.846]     INFO: Test took 3939ms.
[12:54:53.878]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:54.604]     INFO: Expecting 41600 events.
[12:54:57.805]     INFO: 41600 events read in total (2674ms).
[12:54:57.806]     INFO: Test took 3910ms.
[12:54:57.837]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:58.565]     INFO: Expecting 41600 events.
[12:55:01.776]     INFO: 41600 events read in total (2684ms).
[12:55:01.777]     INFO: Test took 3924ms.
[12:55:01.809]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:02.537]     INFO: Expecting 41600 events.
[12:55:05.762]     INFO: 41600 events read in total (2699ms).
[12:55:05.763]     INFO: Test took 3938ms.
[12:55:05.794]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:06.523]     INFO: Expecting 41600 events.
[12:55:09.722]     INFO: 41600 events read in total (2672ms).
[12:55:09.723]     INFO: Test took 3911ms.
[12:55:09.754]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:10.483]     INFO: Expecting 41600 events.
[12:55:13.691]     INFO: 41600 events read in total (2681ms).
[12:55:13.692]     INFO: Test took 3921ms.
[12:55:13.724]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:14.450]     INFO: Expecting 41600 events.
[12:55:17.679]     INFO: 41600 events read in total (2702ms).
[12:55:17.680]     INFO: Test took 3938ms.
[12:55:17.712]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:18.441]     INFO: Expecting 41600 events.
[12:55:21.659]     INFO: 41600 events read in total (2691ms).
[12:55:21.660]     INFO: Test took 3930ms.
[12:55:21.692]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:22.417]     INFO: Expecting 41600 events.
[12:55:25.621]     INFO: 41600 events read in total (2677ms).
[12:55:25.622]     INFO: Test took 3914ms.
[12:55:25.653]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:26.382]     INFO: Expecting 41600 events.
[12:55:29.591]     INFO: 41600 events read in total (2682ms).
[12:55:29.592]     INFO: Test took 3923ms.
[12:55:29.623]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:30.352]     INFO: Expecting 41600 events.
[12:55:33.565]     INFO: 41600 events read in total (2686ms).
[12:55:33.566]     INFO: Test took 3926ms.
[12:55:33.597]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:34.327]     INFO: Expecting 41600 events.
[12:55:37.537]     INFO: 41600 events read in total (2683ms).
[12:55:37.538]     INFO: Test took 3924ms.
[12:55:37.570]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:38.296]     INFO: Expecting 41600 events.
[12:55:41.509]     INFO: 41600 events read in total (2686ms).
[12:55:41.510]     INFO: Test took 3923ms.
[12:55:41.541]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:42.269]     INFO: Expecting 41600 events.
[12:55:45.479]     INFO: 41600 events read in total (2683ms).
[12:55:45.480]     INFO: Test took 3922ms.
[12:55:45.511]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:46.238]     INFO: Expecting 41600 events.
[12:55:49.424]     INFO: 41600 events read in total (2659ms).
[12:55:49.425]     INFO: Test took 3897ms.
[12:55:49.457]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:50.189]     INFO: Expecting 41600 events.
[12:55:52.967]     INFO: 41600 events read in total (2251ms).
[12:55:52.968]     INFO: Test took 3494ms.
[12:55:52.000]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:53.733]     INFO: Expecting 41600 events.
[12:55:56.435]     INFO: 41600 events read in total (2175ms).
[12:55:56.436]     INFO: Test took 3418ms.
[12:55:56.466]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:56.833]     INFO: enter test to run
[12:57:17.003]     INFO:   test: HighRate no parameter change
[12:57:17.003]     INFO:   running: highrate
[12:57:17.004]     INFO:    ----------------------------------------------------------------------
[12:57:17.004]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:57:17.004]     INFO:    ----------------------------------------------------------------------
[12:57:17.011]     INFO: ROC 2 masking pixel 51/70
[12:57:17.011]     INFO: ROC 2 masking pixel 51/72
[12:57:17.620]     INFO: Expecting 208000 events.
[12:57:29.379]     INFO: 208000 events read in total (11232ms).
[12:57:29.381]     INFO: Test took 12369ms.
[12:57:29.515]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:29.762]     INFO: number of dead pixels (per ROC):     0    1    3    0    0    0    0    0    0    0    0  160    0    0    0    0
[12:57:29.762]     INFO: number of red-efficiency pixels:    59   48   82  125  122  133  122   75  248  100  107  239   80   46   21   32
[12:57:29.762]     INFO: number of X-ray hits detected:    56131 39983 63328 95897 101411 107028 103275 70328 70688 88861 88514 72114 77687 47618 22774 24560
[12:57:29.762]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:57:29.762]     INFO: number of Vcal hits detected:  207939 207902 207769 207871 207878 207863 207877 207924 201187 207896 207892 199921 207920 207954 207979 207967
[12:57:29.762]     INFO: Vcal hit fiducial efficiency (%):  100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 96.6 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[12:57:29.762]     INFO: Vcal hit overall efficiency (%):  100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 96.7 100.0 99.9 96.1 100.0 100.0 100.0 100.0
[12:57:29.762]     INFO: X-ray hit rate [MHz/cm2]:  16.5 11.7 18.6 28.1 29.7 31.4 30.3 20.6 20.7 26.0 25.9 21.1 22.8 14.0 6.7 7.2
[12:57:29.762]     INFO: PixTestHighRate::doXPixelAlive() done
[12:57:29.813]     INFO: PixTest::       pg_setup set to default.
[12:57:29.828]     INFO: enter test to run
[12:58:28.506]     INFO:   test: HighRate no parameter change
[12:58:28.506]     INFO:   running: highrate
[12:58:28.507]     INFO:    ----------------------------------------------------------------------
[12:58:28.507]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:58:28.507]     INFO:    ----------------------------------------------------------------------
[12:58:28.514]     INFO: ROC 2 masking pixel 51/70
[12:58:28.514]     INFO: ROC 2 masking pixel 51/72
[12:58:29.113]     INFO: Expecting 208000 events.
[12:58:42.267]     INFO: 208000 events read in total (12627ms).
[12:58:42.272]     INFO: Test took 13757ms.
[12:58:42.541]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:42.831]     INFO: number of dead pixels (per ROC):     0    1    3    0    0    0    0    0   17    0    0  160    0    0    0    0
[12:58:42.831]     INFO: number of red-efficiency pixels:   128  109  248  366  430  317  358  245  386  342  301  384  273  165   43   53
[12:58:42.831]     INFO: number of X-ray hits detected:    113032 80444 127565 192111 202937 214410 206430 142619 141460 177714 177693 144918 156592 96173 45892 48772
[12:58:42.831]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:58:42.831]     INFO: number of Vcal hits detected:  207864 207839 207585 207613 207531 207658 207615 207735 200137 207641 207682 199767 207711 207832 207956 207947
[12:58:42.831]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.9 99.8 99.8 99.9 99.8 99.9 96.5 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[12:58:42.831]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 96.2 99.8 99.8 96.0 99.9 99.9 100.0 100.0
[12:58:42.831]     INFO: X-ray hit rate [MHz/cm2]:  33.1 23.6 37.4 56.3 59.5 62.8 60.5 41.8 41.5 52.1 52.1 42.5 45.9 28.2 13.5 14.3
[12:58:42.831]     INFO: PixTestHighRate::doXPixelAlive() done
[12:58:42.882]     INFO: PixTest::       pg_setup set to default.
[12:58:42.897]     INFO: enter test to run
[12:59:29.490]     INFO:   test: HighRate no parameter change
[12:59:29.490]     INFO:   running: highrate
[12:59:29.491]     INFO:    ----------------------------------------------------------------------
[12:59:29.491]     INFO:    PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:59:29.491]     INFO:    ----------------------------------------------------------------------
[12:59:29.499]     INFO: ROC 2 masking pixel 51/70
[12:59:29.499]     INFO: ROC 2 masking pixel 51/72
[12:59:30.102]     INFO: Expecting 208000 events.
[12:59:44.973]     INFO: 208000 events read in total (14344ms).
[12:59:44.979]     INFO: Test took 15479ms.
[12:59:45.381]     INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:45.715]     INFO: number of dead pixels (per ROC):     0    1    3    0    0    0    0    0   67    0    0  160    0    0    0    0
[12:59:45.715]     INFO: number of red-efficiency pixels:   275  243  525  825  878  744  792  541  636  738  723  633  597  331   78   88
[12:59:45.715]     INFO: number of X-ray hits detected:    172515 122697 193376 292077 308086 323913 314453 216739 215783 271816 270987 223520 237597 146860 69324 74411
[12:59:45.716]     INFO: number of triggers sent (total per ROC):  208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:59:45.716]     INFO: number of Vcal hits detected:  207701 207690 207213 207023 206948 207120 207029 207339 199602 207123 207165 199492 207335 207634 207922 207911
[12:59:45.716]     INFO: Vcal hit fiducial efficiency (%):  99.9 99.9 99.7 99.6 99.5 99.6 99.6 99.7 97.5 99.6 99.6 99.8 99.7 99.8 100.0 100.0
[12:59:45.716]     INFO: Vcal hit overall efficiency (%):  99.9 99.9 99.6 99.5 99.5 99.6 99.5 99.7 96.0 99.6 99.6 95.9 99.7 99.8 100.0 100.0
[12:59:45.716]     INFO: X-ray hit rate [MHz/cm2]:  50.6 36.0 56.7 85.6 90.3 94.9 92.2 63.5 63.2 79.7 79.4 65.5 69.6 43.0 20.3 21.8
[12:59:45.716]     INFO: PixTestHighRate::doXPixelAlive() done
[12:59:45.765]     INFO: PixTest::       pg_setup set to default.
[12:59:45.780]     INFO: enter test to run
[13:00:10.210]     INFO:   test: exit no parameter change
[13:00:10.535]    QUIET: Connection to board 33 closed.
[13:00:10.536]     INFO: pXar: this is the end, my friend