[10:18:20.556] INFO: *** Welcome to pxar ***
[10:18:20.556] INFO: *** Today: 2016/05/26
[10:18:20.575] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:18:20.575] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//dacParameters35_C15.dat
[10:18:20.576] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:18:20.576] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//defaultMaskFile.dat
[10:18:20.576] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C15.dat
[10:18:20.657] INFO: clk: 4
[10:18:20.657] INFO: ctr: 4
[10:18:20.658] INFO: sda: 19
[10:18:20.658] INFO: tin: 9
[10:18:20.658] INFO: level: 15
[10:18:20.658] INFO: triggerdelay: 0
[10:18:20.658] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:18:20.658] INFO: Log level: INFO
[10:18:20.673] QUIET: Connection to board DTB_WREKRL opened.
[10:18:20.676] 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:
------------------------------------------------------
[10:18:20.679] INFO: RPC call hashes of host and DTB match: 398089610
[10:18:22.215] INFO: DUT info:
[10:18:22.215] INFO: The DUT currently contains the following objects:
[10:18:22.215] INFO: 2 TBM Cores tbm08c (2 ON)
[10:18:22.215] INFO: TBM Core alpha (0): 7 registers set
[10:18:22.216] INFO: TBM Core beta (1): 7 registers set
[10:18:22.216] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:18:22.216] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.216] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:18:22.620] INFO: enter 'restricted' command line mode
[10:18:22.620] INFO: enter test to run
[10:18:31.922] INFO: test: PixelAlive no parameter change
[10:18:31.922] INFO: running: pixelalive
[10:18:31.932] INFO: ----------------------------------------------------------------------
[10:18:31.932] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:18:31.932] INFO: ----------------------------------------------------------------------
[10:18:32.255] INFO: Expecting 41600 events.
[10:18:36.592] INFO: 41600 events read in total (3619ms).
[10:18:36.760] INFO: Test took 4825ms.
[10:18:36.772] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:37.037] INFO: PixTestAlive::aliveTest() done
[10:18:37.037] INFO: number of dead pixels (per ROC): 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:18:37.147] INFO: enter test to run
[10:19:02.530] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:19:02.530] INFO: running: highrate
[10:19:02.531] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:19:02.772] INFO: ----------------------------------------------------------------------
[10:19:02.772] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:19:02.772] INFO: ----------------------------------------------------------------------
[10:19:02.772] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:19:02.772] INFO: edge/corner pixel THR is adjusted
[10:19:02.772] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:19:03.730] INFO: Collecting data for 5 seconds...
[10:19:08.749] INFO: Done with hot pixel readout
[10:19:20.424] INFO: PixTest:: pg_setup set to default.
[10:19:20.425] INFO: 1 hot pixels found in step 0
[10:19:21.411] INFO: Collecting data for 5 seconds...
[10:19:26.429] INFO: Done with hot pixel readout
[10:19:38.018] INFO: PixTest:: pg_setup set to default.
[10:19:38.018] INFO: 0 hot pixels found in step 1
[10:19:38.051] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:19:38.055] INFO: PixTest::trimHotPixels() done
[10:19:38.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C0.dat
[10:19:38.061] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C1.dat
[10:19:38.067] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C2.dat
[10:19:38.072] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C3.dat
[10:19:38.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C4.dat
[10:19:38.082] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C5.dat
[10:19:38.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C6.dat
[10:19:38.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C7.dat
[10:19:38.098] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C8.dat
[10:19:38.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C9.dat
[10:19:38.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C10.dat
[10:19:38.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C11.dat
[10:19:38.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C12.dat
[10:19:38.124] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C13.dat
[10:19:38.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C14.dat
[10:19:38.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C15.dat
[10:19:38.140] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//defaultMaskFile.dat
[10:19:38.158] INFO: enter test to run
[10:20:08.826] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:20:08.826] INFO: running: highrate
[10:20:08.830] INFO: ----------------------------------------------------------------------
[10:20:08.830] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:20:08.830] INFO: ----------------------------------------------------------------------
[10:20:08.830] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:20:08.830] INFO: edge/corner pixel THR is adjusted
[10:20:08.830] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:20:09.791] INFO: Collecting data for 1 seconds...
[10:20:10.795] INFO: Done with hot pixel readout
[10:20:14.721] INFO: PixTest:: pg_setup set to default.
[10:20:14.722] INFO: 0 hot pixels found in step 0
[10:20:14.727] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:20:14.820] INFO: PixTest::trimHotPixels() done
[10:20:14.820] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C0.dat
[10:20:14.831] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C1.dat
[10:20:14.838] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C2.dat
[10:20:14.843] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C3.dat
[10:20:14.848] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C4.dat
[10:20:14.853] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C5.dat
[10:20:14.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C6.dat
[10:20:14.864] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C7.dat
[10:20:14.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C8.dat
[10:20:14.874] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C9.dat
[10:20:14.880] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C10.dat
[10:20:14.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C11.dat
[10:20:14.890] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C12.dat
[10:20:14.895] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C13.dat
[10:20:14.900] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C14.dat
[10:20:14.906] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//trimParameters35_C15.dat
[10:20:14.911] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-2-06_FPIXTest-17C-FNAL-160519-0755_2016-05-19_07h55m_1463662516/000_FPIXTest_p17//defaultMaskFile.dat
[10:20:14.921] INFO: enter test to run
[10:20:55.617] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:20:55.617] INFO: running: xray
[10:20:55.618] INFO: ----------------------------------------------------------------------
[10:20:55.618] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:20:55.619] INFO: ----------------------------------------------------------------------
[10:20:56.600] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:21:08.241] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:21:37.526] INFO: Resuming triggers.
[10:21:49.168] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:22:18.576] INFO: Resuming triggers.
[10:22:30.216] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:22:59.540] INFO: Resuming triggers.
[10:23:11.174] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:23:40.516] INFO: Resuming triggers.
[10:23:52.152] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[10:24:21.404] INFO: Resuming triggers.
[10:24:33.045] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:25:02.391] INFO: Resuming triggers.
[10:25:14.030] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:25:43.330] INFO: Resuming triggers.
[10:25:54.967] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:26:24.287] INFO: Resuming triggers.
[10:26:31.508] INFO: data taking finished, elapsed time: 100 seconds.
[10:26:50.122] INFO: PixTest:: pg_setup set to default.
[10:26:50.125] INFO: PixTestXray::doPhRun() done
[10:26:50.295] INFO: enter test to run
[10:27:55.078] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:27:55.078] INFO: running: xray
[10:27:55.079] INFO: ----------------------------------------------------------------------
[10:27:55.079] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:27:55.079] INFO: ----------------------------------------------------------------------
[10:27:56.042] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:28:02.874] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:28:32.953] INFO: Resuming triggers.
[10:28:39.787] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:29:10.969] INFO: Resuming triggers.
[10:29:17.804] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[10:29:48.908] INFO: Resuming triggers.
[10:29:55.744] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[10:30:26.161] INFO: Resuming triggers.
[10:30:32.997] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:31:02.660] INFO: Resuming triggers.
[10:31:09.497] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[10:31:39.536] INFO: Resuming triggers.
[10:31:46.369] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[10:32:16.499] INFO: Resuming triggers.
[10:32:23.333] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[10:32:53.383] INFO: Resuming triggers.
[10:33:00.214] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[10:33:30.222] INFO: Resuming triggers.
[10:33:37.056] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[10:34:07.226] INFO: Resuming triggers.
[10:34:14.060] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[10:34:44.198] INFO: Resuming triggers.
[10:34:51.032] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:35:21.077] INFO: Resuming triggers.
[10:35:27.906] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:35:57.976] INFO: Resuming triggers.
[10:36:04.806] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[10:36:34.875] INFO: Resuming triggers.
[10:36:39.554] INFO: data taking finished, elapsed time: 100 seconds.
[10:37:00.408] INFO: PixTest:: pg_setup set to default.
[10:37:00.411] INFO: PixTestXray::doPhRun() done
[10:37:00.560] INFO: enter test to run
[10:37:49.202] INFO: test: HighRate no parameter change
[10:37:49.202] INFO: running: highrate
[10:37:49.203] INFO: ----------------------------------------------------------------------
[10:37:49.203] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:37:49.203] INFO: ----------------------------------------------------------------------
[10:37:49.344] INFO: Expecting 768 events.
[10:37:50.478] INFO: 768 events read in total (418ms).
[10:37:50.479] INFO: Test took 1268ms.
[10:37:51.282] INFO: Expecting 41600 events.
[10:37:54.342] INFO: 41600 events read in total (2533ms).
[10:37:54.343] INFO: Test took 3857ms.
[10:37:54.375] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:55.105] INFO: Expecting 41600 events.
[10:37:58.283] INFO: 41600 events read in total (2651ms).
[10:37:58.284] INFO: Test took 3892ms.
[10:37:58.316] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:59.046] INFO: Expecting 41600 events.
[10:38:02.266] INFO: 41600 events read in total (2693ms).
[10:38:02.267] INFO: Test took 3934ms.
[10:38:02.299] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:03.028] INFO: Expecting 41600 events.
[10:38:06.239] INFO: 41600 events read in total (2684ms).
[10:38:06.240] INFO: Test took 3923ms.
[10:38:06.272] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:06.998] INFO: Expecting 41600 events.
[10:38:10.223] INFO: 41600 events read in total (2698ms).
[10:38:10.224] INFO: Test took 3934ms.
[10:38:10.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:10.984] INFO: Expecting 41600 events.
[10:38:14.217] INFO: 41600 events read in total (2706ms).
[10:38:14.218] INFO: Test took 3945ms.
[10:38:14.251] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:14.976] INFO: Expecting 41600 events.
[10:38:18.203] INFO: 41600 events read in total (2701ms).
[10:38:18.204] INFO: Test took 3937ms.
[10:38:18.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:18.963] INFO: Expecting 41600 events.
[10:38:22.185] INFO: 41600 events read in total (2695ms).
[10:38:22.186] INFO: Test took 3932ms.
[10:38:22.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:22.945] INFO: Expecting 41600 events.
[10:38:26.180] INFO: 41600 events read in total (2709ms).
[10:38:26.181] INFO: Test took 3946ms.
[10:38:26.212] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:26.937] INFO: Expecting 41600 events.
[10:38:30.151] INFO: 41600 events read in total (2688ms).
[10:38:30.152] INFO: Test took 3923ms.
[10:38:30.184] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:30.909] INFO: Expecting 41600 events.
[10:38:34.137] INFO: 41600 events read in total (2701ms).
[10:38:34.138] INFO: Test took 3936ms.
[10:38:34.170] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:34.894] INFO: Expecting 41600 events.
[10:38:38.129] INFO: 41600 events read in total (2708ms).
[10:38:38.130] INFO: Test took 3943ms.
[10:38:38.163] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:38.886] INFO: Expecting 41600 events.
[10:38:42.164] INFO: 41600 events read in total (2751ms).
[10:38:42.165] INFO: Test took 3984ms.
[10:38:42.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:42.918] INFO: Expecting 41600 events.
[10:38:46.103] INFO: 41600 events read in total (2658ms).
[10:38:46.104] INFO: Test took 3889ms.
[10:38:46.137] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:46.863] INFO: Expecting 41600 events.
[10:38:50.137] INFO: 41600 events read in total (2747ms).
[10:38:50.138] INFO: Test took 3984ms.
[10:38:50.172] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:50.889] INFO: Expecting 41600 events.
[10:38:54.137] INFO: 41600 events read in total (2721ms).
[10:38:54.138] INFO: Test took 3949ms.
[10:38:54.171] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:54.890] INFO: Expecting 41600 events.
[10:38:58.149] INFO: 41600 events read in total (2732ms).
[10:38:58.150] INFO: Test took 3961ms.
[10:38:58.184] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:58.907] INFO: Expecting 41600 events.
[10:39:02.125] INFO: 41600 events read in total (2691ms).
[10:39:02.126] INFO: Test took 3925ms.
[10:39:02.158] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:02.885] INFO: Expecting 41600 events.
[10:39:05.985] INFO: 41600 events read in total (2573ms).
[10:39:05.986] INFO: Test took 3810ms.
[10:39:06.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:06.740] INFO: Expecting 41600 events.
[10:39:09.809] INFO: 41600 events read in total (2542ms).
[10:39:09.810] INFO: Test took 3773ms.
[10:39:09.843] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:10.205] INFO: enter test to run
[10:39:25.417] INFO: test: HighRate no parameter change
[10:39:25.417] INFO: running: highrate
[10:39:25.418] INFO: ----------------------------------------------------------------------
[10:39:25.418] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:39:25.418] INFO: ----------------------------------------------------------------------
[10:39:26.039] INFO: Expecting 208000 events.
[10:39:37.683] INFO: 208000 events read in total (11118ms).
[10:39:37.686] INFO: Test took 12260ms.
[10:39:37.825] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:38.076] INFO: number of dead pixels (per ROC): 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:39:38.076] INFO: number of red-efficiency pixels: 73 46 98 120 131 142 131 97 79 128 116 72 88 48 22 35
[10:39:38.076] INFO: number of X-ray hits detected: 57827 40062 63371 102148 106036 108653 112021 77159 69607 91821 91347 75194 77240 46460 22034 27659
[10:39:38.076] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:39:38.076] INFO: number of Vcal hits detected: 207926 207954 207752 207875 207869 207852 207862 207902 207921 207871 207883 207927 207909 207951 207977 207963
[10:39:38.076] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[10:39:38.076] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[10:39:38.076] INFO: X-ray hit rate [MHz/cm2]: 16.9 11.7 18.6 29.9 31.1 31.8 32.8 22.6 20.4 26.9 26.8 22.0 22.6 13.6 6.5 8.1
[10:39:38.076] INFO: PixTestHighRate::doXPixelAlive() done
[10:39:38.125] INFO: PixTest:: pg_setup set to default.
[10:39:38.140] INFO: enter test to run
[10:40:01.521] INFO: test: HighRate no parameter change
[10:40:01.521] INFO: running: highrate
[10:40:01.522] INFO: ----------------------------------------------------------------------
[10:40:01.522] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:40:01.522] INFO: ----------------------------------------------------------------------
[10:40:02.145] INFO: Expecting 208000 events.
[10:40:15.793] INFO: 208000 events read in total (13121ms).
[10:40:15.798] INFO: Test took 14267ms.
[10:40:16.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:16.387] INFO: number of dead pixels (per ROC): 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:40:16.387] INFO: number of red-efficiency pixels: 166 111 260 462 423 455 419 297 199 319 323 255 247 132 58 74
[10:40:16.387] INFO: number of X-ray hits detected: 122986 84544 133768 217868 224609 229772 236995 163422 149210 195152 193586 160558 162974 98367 46826 58701
[10:40:16.387] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:40:16.387] INFO: number of Vcal hits detected: 207827 207885 207565 207504 207551 207511 207533 207679 207791 207655 207663 207733 207737 207865 207940 207925
[10:40:16.387] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[10:40:16.387] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[10:40:16.387] INFO: X-ray hit rate [MHz/cm2]: 36.0 24.8 39.2 63.9 65.8 67.3 69.5 47.9 43.7 57.2 56.7 47.1 47.8 28.8 13.7 17.2
[10:40:16.387] INFO: PixTestHighRate::doXPixelAlive() done
[10:40:16.433] INFO: PixTest:: pg_setup set to default.
[10:40:16.449] INFO: enter test to run
[10:40:41.641] INFO: test: HighRate no parameter change
[10:40:41.641] INFO: running: highrate
[10:40:41.642] INFO: ----------------------------------------------------------------------
[10:40:41.642] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:40:41.642] INFO: ----------------------------------------------------------------------
[10:40:42.270] INFO: Expecting 208000 events.
[10:40:57.618] INFO: 208000 events read in total (14821ms).
[10:40:57.625] INFO: Test took 15974ms.
[10:40:58.062] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:58.408] INFO: number of dead pixels (per ROC): 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:40:58.408] INFO: number of red-efficiency pixels: 352 259 612 1053 850 1145 876 734 404 902 658 530 593 273 84 109
[10:40:58.408] INFO: number of X-ray hits detected: 186605 127837 203939 330567 339548 347619 357802 247521 227050 295618 292914 244027 248758 149719 71486 89871
[10:40:58.408] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:40:58.408] INFO: number of Vcal hits detected: 207600 207722 207081 206719 207014 206528 206913 207100 207564 206910 207275 207407 207342 207708 207913 207887
[10:40:58.408] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.6 99.4 99.5 99.6 99.8 99.5 99.7 99.8 99.7 99.9 100.0 99.9
[10:40:58.408] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.4 99.5 99.3 99.5 99.6 99.8 99.5 99.7 99.7 99.7 99.9 100.0 99.9
[10:40:58.408] INFO: X-ray hit rate [MHz/cm2]: 54.7 37.5 59.8 96.9 99.5 101.9 104.9 72.6 66.6 86.6 85.9 71.5 72.9 43.9 21.0 26.3
[10:40:58.408] INFO: PixTestHighRate::doXPixelAlive() done
[10:40:58.453] INFO: PixTest:: pg_setup set to default.
[10:40:58.469] INFO: enter test to run
[10:41:13.656] INFO: test: exit no parameter change
[10:41:14.017] QUIET: Connection to board 33 closed.
[10:41:14.019] INFO: pXar: this is the end, my friend