[12:30:06.229] INFO: *** Welcome to pxar ***
[12:30:06.230] INFO: *** Today: 2016/05/06
[12:30:06.319] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:30:06.320] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//dacParameters35_C15.dat
[12:30:06.357] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:30:06.357] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//defaultMaskFile.dat
[12:30:06.358] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C15.dat
[12:30:06.486] INFO: clk: 4
[12:30:06.486] INFO: ctr: 4
[12:30:06.486] INFO: sda: 19
[12:30:06.486] INFO: tin: 9
[12:30:06.486] INFO: level: 15
[12:30:06.486] INFO: triggerdelay: 0
[12:30:06.486] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:30:06.486] INFO: Log level: INFO
[12:30:06.503] QUIET: Connection to board DTB_WREKRL opened.
[12:30:06.506] 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:30:06.510] INFO: RPC call hashes of host and DTB match: 398089610
[12:30:08.042] INFO: DUT info:
[12:30:08.042] INFO: The DUT currently contains the following objects:
[12:30:08.042] INFO: 2 TBM Cores tbm08c (2 ON)
[12:30:08.042] INFO: TBM Core alpha (0): 7 registers set
[12:30:08.042] INFO: TBM Core beta (1): 7 registers set
[12:30:08.042] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:30:08.042] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.042] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.043] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.043] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.043] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.043] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:30:08.446] INFO: enter 'restricted' command line mode
[12:30:08.446] INFO: enter test to run
[12:30:16.510] INFO: test: PixelAlive no parameter change
[12:30:16.510] INFO: running: pixelalive
[12:30:16.517] INFO: ----------------------------------------------------------------------
[12:30:16.517] 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:30:16.517] INFO: ----------------------------------------------------------------------
[12:30:16.833] INFO: Expecting 41600 events.
[12:30:21.161] INFO: 41600 events read in total (3609ms).
[12:30:21.330] INFO: Test took 4811ms.
[12:30:21.339] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:21.605] INFO: PixTestAlive::aliveTest() done
[12:30:21.605] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0
[12:30:21.636] INFO: enter test to run
[12:30:54.573] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:30:54.573] INFO: running: highrate
[12:30:54.574] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:30:54.793] INFO: ----------------------------------------------------------------------
[12:30:54.793] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:30:54.793] INFO: ----------------------------------------------------------------------
[12:30:54.793] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:30:54.793] INFO: edge/corner pixel THR is adjusted
[12:30:54.793] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:30:55.753] INFO: Collecting data for 5 seconds...
[12:31:00.771] INFO: Done with hot pixel readout
[12:31:12.582] INFO: PixTest:: pg_setup set to default.
[12:31:12.583] INFO: 24 hot pixels found in step 0
[12:31:13.581] INFO: Collecting data for 5 seconds...
[12:31:18.597] INFO: Done with hot pixel readout
[12:31:30.244] INFO: PixTest:: pg_setup set to default.
[12:31:30.245] INFO: 29 hot pixels found in step 1
[12:31:31.242] INFO: Collecting data for 5 seconds...
[12:31:36.259] INFO: Done with hot pixel readout
[12:31:48.599] INFO: PixTest:: pg_setup set to default.
[12:31:48.600] INFO: 18 hot pixels found in step 2
[12:31:49.596] INFO: Collecting data for 5 seconds...
[12:31:54.612] INFO: Done with hot pixel readout
[12:32:06.971] INFO: PixTest:: pg_setup set to default.
[12:32:06.972] INFO: 19 hot pixels found in step 3
[12:32:07.969] INFO: Collecting data for 5 seconds...
[12:32:12.985] INFO: Done with hot pixel readout
[12:32:25.373] INFO: PixTest:: pg_setup set to default.
[12:32:25.374] INFO: 16 hot pixels found in step 4
[12:32:26.371] INFO: Collecting data for 5 seconds...
[12:32:31.387] INFO: Done with hot pixel readout
[12:32:43.798] INFO: PixTest:: pg_setup set to default.
[12:32:43.799] INFO: 12 hot pixels found in step 5
[12:32:44.795] INFO: Collecting data for 5 seconds...
[12:32:49.811] INFO: Done with hot pixel readout
[12:33:02.213] INFO: PixTest:: pg_setup set to default.
[12:33:02.214] INFO: 14 hot pixels found in step 6
[12:33:03.217] INFO: Collecting data for 5 seconds...
[12:33:08.233] INFO: Done with hot pixel readout
[12:33:20.564] INFO: PixTest:: pg_setup set to default.

[12:33:20.565] INFO: 17 hot pixels found in step 7
[12:33:21.562] INFO: Collecting data for 5 seconds...
[12:33:26.578] INFO: Done with hot pixel readout
[12:33:38.971] INFO: PixTest:: pg_setup set to default.
[12:33:38.972] INFO: 22 hot pixels found in step 8
[12:33:39.969] INFO: Collecting data for 5 seconds...
[12:33:44.985] INFO: Done with hot pixel readout
[12:33:57.366] INFO: PixTest:: pg_setup set to default.


[12:33:57.367] INFO: 11 hot pixels found in step 9
[12:33:58.364] INFO: Collecting data for 5 seconds...
[12:34:03.380] INFO: Done with hot pixel readout
[12:34:15.818] INFO: PixTest:: pg_setup set to default.
[12:34:15.819] INFO: 14 hot pixels found in step 10
[12:34:16.816] INFO: Collecting data for 5 seconds...
[12:34:21.835] INFO: Done with hot pixel readout
[12:34:33.879] INFO: PixTest:: pg_setup set to default.
[12:34:33.880] INFO: 13 hot pixels found in step 11
[12:34:34.877] INFO: Collecting data for 5 seconds...
[12:34:39.894] INFO: Done with hot pixel readout
[12:34:51.996] INFO: PixTest:: pg_setup set to default.


[12:34:51.996] INFO: 9 hot pixels found in step 12
[12:34:52.993] INFO: Collecting data for 5 seconds...
[12:34:58.012] INFO: Done with hot pixel readout
[12:35:10.023] INFO: PixTest:: pg_setup set to default.

[12:35:10.024] INFO: 14 hot pixels found in step 13
[12:35:11.021] INFO: Collecting data for 5 seconds...
[12:35:16.038] INFO: Done with hot pixel readout
[12:35:28.266] INFO: PixTest:: pg_setup set to default.
[12:35:28.267] INFO: 5 hot pixels found in step 14
[12:35:28.307] INFO: 5 hot pixels could not be trimmed and have been masked.
[12:35:28.311] INFO: PixTest::trimHotPixels() done
[12:35:28.311] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C0.dat
[12:35:28.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C1.dat
[12:35:28.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C2.dat
[12:35:28.354] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C3.dat
[12:35:28.361] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C4.dat
[12:35:28.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C5.dat
[12:35:28.372] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C6.dat
[12:35:28.406] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C7.dat
[12:35:28.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C8.dat
[12:35:28.422] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C9.dat
[12:35:28.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C10.dat
[12:35:28.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C11.dat
[12:35:28.440] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C12.dat
[12:35:28.445] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C13.dat
[12:35:28.450] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C14.dat
[12:35:28.455] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C15.dat
[12:35:28.461] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//defaultMaskFile.dat
[12:35:28.471] INFO: enter test to run
[12:36:21.931] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:36:21.931] INFO: running: highrate
[12:36:21.936] INFO: ----------------------------------------------------------------------
[12:36:21.936] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:36:21.936] INFO: ----------------------------------------------------------------------
[12:36:21.936] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:36:21.936] INFO: edge/corner pixel THR is adjusted
[12:36:21.936] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:36:22.894] INFO: Collecting data for 1 seconds...
[12:36:23.898] INFO: Done with hot pixel readout
[12:36:28.104] INFO: PixTest:: pg_setup set to default.
[12:36:28.105] INFO: 0 hot pixels found in step 0
[12:36:28.110] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:36:28.196] INFO: PixTest::trimHotPixels() done
[12:36:28.196] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C0.dat
[12:36:28.208] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C1.dat
[12:36:28.216] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C2.dat
[12:36:28.221] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C3.dat
[12:36:28.226] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C4.dat
[12:36:28.231] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C5.dat
[12:36:28.237] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C6.dat
[12:36:28.242] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C7.dat
[12:36:28.247] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C8.dat
[12:36:28.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C9.dat
[12:36:28.257] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C10.dat
[12:36:28.262] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C11.dat
[12:36:28.268] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C12.dat
[12:36:28.273] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C13.dat
[12:36:28.278] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C14.dat
[12:36:28.283] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//trimParameters35_C15.dat
[12:36:28.288] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-G-NU_FPIXTest-17C-FNAL-160428-0957_2016-04-28_09h57m_1461855468/000_FPIXTest_p17//defaultMaskFile.dat
[12:36:28.298] INFO: enter test to run
[12:36:55.035] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:36:55.035] INFO: running: xray
[12:36:55.052] INFO: ----------------------------------------------------------------------
[12:36:55.052] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:36:55.052] INFO: ----------------------------------------------------------------------
[12:36:56.015] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:37:06.874] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:37:36.463] INFO: Resuming triggers.
[12:37:47.326] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:38:16.951] INFO: Resuming triggers.
[12:38:27.817] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:38:57.389] INFO: Resuming triggers.
[12:39:08.254] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:39:38.381] INFO: Resuming triggers.
[12:39:49.244] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:40:19.323] INFO: Resuming triggers.
[12:40:30.188] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[12:41:00.372] INFO: Resuming triggers.
[12:41:11.236] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[12:41:40.758] INFO: Resuming triggers.
[12:41:51.627] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[12:42:21.124] INFO: Resuming triggers.
[12:42:31.988] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[12:43:01.550] INFO: Resuming triggers.
[12:43:04.114] INFO: data taking finished, elapsed time: 100 seconds.
[12:43:11.420] INFO: PixTest:: pg_setup set to default.
[12:43:11.423] INFO: PixTestXray::doPhRun() done
[12:43:11.560] INFO: enter test to run
[12:44:22.248] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:44:22.248] INFO: running: xray
[12:44:22.249] INFO: ----------------------------------------------------------------------
[12:44:22.249] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:44:22.249] INFO: ----------------------------------------------------------------------
[12:44:23.235] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:44:29.640] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:44:59.719] INFO: Resuming triggers.
[12:45:06.133] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:45:36.764] INFO: Resuming triggers.
[12:45:43.178] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[12:46:13.493] INFO: Resuming triggers.
[12:46:19.904] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[12:46:49.940] INFO: Resuming triggers.
[12:46:56.355] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[12:47:26.405] INFO: Resuming triggers.
[12:47:32.814] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[12:48:02.827] INFO: Resuming triggers.
[12:48:09.241] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[12:48:39.347] INFO: Resuming triggers.
[12:48:45.757] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[12:49:15.775] INFO: Resuming triggers.
[12:49:22.191] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:49:52.293] INFO: Resuming triggers.
[12:49:58.704] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[12:50:29.479] INFO: Resuming triggers.
[12:50:35.891] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:51:06.866] INFO: Resuming triggers.
[12:51:13.281] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:51:44.283] INFO: Resuming triggers.
[12:51:50.693] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[12:52:20.599] INFO: Resuming triggers.
[12:52:27.013] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[12:52:57.069] INFO: Resuming triggers.
[12:53:03.483] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:53:33.571] INFO: Resuming triggers.
[12:53:37.727] INFO: data taking finished, elapsed time: 100 seconds.
[12:53:57.465] INFO: PixTest:: pg_setup set to default.
[12:53:57.468] INFO: PixTestXray::doPhRun() done
[12:53:57.617] INFO: enter test to run
[12:54:24.603] INFO: test: HighRate no parameter change
[12:54:24.603] INFO: running: highrate
[12:54:24.605] INFO: ----------------------------------------------------------------------
[12:54:24.605] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:54:24.605] INFO: ----------------------------------------------------------------------
[12:54:24.744] INFO: Expecting 768 events.
[12:54:25.887] INFO: 768 events read in total (427ms).
[12:54:25.893] INFO: Test took 1282ms.
[12:54:26.691] INFO: Expecting 41600 events.
[12:54:29.893] INFO: 41600 events read in total (2676ms).
[12:54:29.894] INFO: Test took 3992ms.
[12:54:29.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:30.651] INFO: Expecting 41600 events.
[12:54:33.914] INFO: 41600 events read in total (2736ms).
[12:54:33.915] INFO: Test took 3962ms.
[12:54:33.954] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:34.669] INFO: Expecting 41600 events.
[12:54:37.947] INFO: 41600 events read in total (2751ms).
[12:54:37.948] INFO: Test took 3976ms.
[12:54:37.987] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:38.701] INFO: Expecting 41600 events.
[12:54:41.989] INFO: 41600 events read in total (2762ms).
[12:54:41.990] INFO: Test took 3984ms.
[12:54:42.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:42.741] INFO: Expecting 41600 events.
[12:54:46.035] INFO: 41600 events read in total (2767ms).
[12:54:46.036] INFO: Test took 3987ms.
[12:54:46.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:46.790] INFO: Expecting 41600 events.
[12:54:50.090] INFO: 41600 events read in total (2773ms).
[12:54:50.091] INFO: Test took 3998ms.
[12:54:50.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:50.842] INFO: Expecting 41600 events.
[12:54:54.121] INFO: 41600 events read in total (2752ms).
[12:54:54.122] INFO: Test took 3972ms.
[12:54:54.161] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:54.873] INFO: Expecting 41600 events.
[12:54:58.169] INFO: 41600 events read in total (2769ms).
[12:54:58.170] INFO: Test took 3991ms.
[12:54:58.209] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:58.927] INFO: Expecting 41600 events.
[12:55:02.234] INFO: 41600 events read in total (2781ms).
[12:55:02.235] INFO: Test took 4008ms.
[12:55:02.274] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:02.986] INFO: Expecting 41600 events.
[12:55:06.280] INFO: 41600 events read in total (2767ms).
[12:55:06.281] INFO: Test took 3987ms.
[12:55:06.320] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:07.033] INFO: Expecting 41600 events.
[12:55:10.334] INFO: 41600 events read in total (2774ms).
[12:55:10.335] INFO: Test took 3995ms.
[12:55:10.373] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:11.087] INFO: Expecting 41600 events.
[12:55:14.391] INFO: 41600 events read in total (2777ms).
[12:55:14.392] INFO: Test took 4000ms.
[12:55:14.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:15.145] INFO: Expecting 41600 events.
[12:55:18.436] INFO: 41600 events read in total (2764ms).
[12:55:18.437] INFO: Test took 3986ms.
[12:55:18.475] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:19.191] INFO: Expecting 41600 events.
[12:55:22.482] INFO: 41600 events read in total (2765ms).
[12:55:22.483] INFO: Test took 3987ms.
[12:55:22.522] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:23.239] INFO: Expecting 41600 events.
[12:55:26.536] INFO: 41600 events read in total (2770ms).
[12:55:26.537] INFO: Test took 3996ms.
[12:55:26.576] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:27.293] INFO: Expecting 41600 events.
[12:55:30.580] INFO: 41600 events read in total (2760ms).
[12:55:30.581] INFO: Test took 3987ms.
[12:55:30.620] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:31.335] INFO: Expecting 41600 events.
[12:55:34.609] INFO: 41600 events read in total (2747ms).
[12:55:34.610] INFO: Test took 3970ms.
[12:55:34.648] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:35.361] INFO: Expecting 41600 events.
[12:55:38.655] INFO: 41600 events read in total (2767ms).
[12:55:38.656] INFO: Test took 3988ms.
[12:55:38.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:39.410] INFO: Expecting 41600 events.
[12:55:42.659] INFO: 41600 events read in total (2722ms).
[12:55:42.660] INFO: Test took 3946ms.
[12:55:42.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:43.411] INFO: Expecting 41600 events.
[12:55:46.459] INFO: 41600 events read in total (2521ms).
[12:55:46.460] INFO: Test took 3742ms.
[12:55:46.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:46.848] INFO: enter test to run
[12:56:39.362] INFO: test: HighRate no parameter change
[12:56:39.363] INFO: running: highrate
[12:56:39.364] INFO: ----------------------------------------------------------------------
[12:56:39.364] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:56:39.364] INFO: ----------------------------------------------------------------------
[12:56:40.022] INFO: Expecting 208000 events.
[12:56:52.304] INFO: 208000 events read in total (11756ms).
[12:56:52.308] INFO: Test took 12933ms.
[12:56:52.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:52.743] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0
[12:56:52.743] INFO: number of red-efficiency pixels: 67 62 105 186 203 225 179 134 91 122 150 94 98 76 30 27
[12:56:52.743] INFO: number of X-ray hits detected: 71263 50282 85071 129787 141527 143323 139476 97817 83932 111493 110914 92707 96462 60778 26726 28351
[12:56:52.743] 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:56:52.743] INFO: number of Vcal hits detected: 207932 207937 207894 207810 207791 207719 207818 207859 207909 207876 207846 207904 207900 207924 207970 207973
[12:56:52.743] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[12:56:52.743] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[12:56:52.743] INFO: X-ray hit rate [MHz/cm2]: 20.9 14.7 24.9 38.0 41.5 42.0 40.9 28.7 24.6 32.7 32.5 27.2 28.3 17.8 7.8 8.3
[12:56:52.743] INFO: PixTestHighRate::doXPixelAlive() done
[12:56:52.788] INFO: PixTest:: pg_setup set to default.
[12:56:52.803] INFO: enter test to run
[12:57:20.610] INFO: test: HighRate no parameter change
[12:57:20.610] INFO: running: highrate
[12:57:20.611] INFO: ----------------------------------------------------------------------
[12:57:20.611] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:57:20.611] INFO: ----------------------------------------------------------------------
[12:57:21.228] INFO: Expecting 208000 events.
[12:57:35.242] INFO: 208000 events read in total (13487ms).
[12:57:35.247] INFO: Test took 14627ms.
[12:57:35.581] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:35.892] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0
[12:57:35.892] INFO: number of red-efficiency pixels: 168 148 316 609 676 780 565 451 230 361 432 274 292 197 80 77
[12:57:35.892] INFO: number of X-ray hits detected: 137564 97992 164816 249936 273351 277518 267339 189904 162721 215454 214849 179069 186068 117001 51974 54998
[12:57:35.892] 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:35.893] INFO: number of Vcal hits detected: 207824 207847 207643 207326 207244 207054 207370 207506 207760 207627 207535 207718 207695 207789 207917 207922
[12:57:35.893] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.6 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[12:57:35.893] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.6 99.5 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[12:57:35.893] INFO: X-ray hit rate [MHz/cm2]: 40.3 28.7 48.3 73.3 80.1 81.3 78.4 55.7 47.7 63.2 63.0 52.5 54.5 34.3 15.2 16.1
[12:57:35.893] INFO: PixTestHighRate::doXPixelAlive() done
[12:57:35.940] INFO: PixTest:: pg_setup set to default.
[12:57:35.956] INFO: enter test to run
[12:57:53.234] INFO: test: HighRate no parameter change
[12:57:53.234] INFO: running: highrate
[12:57:53.235] INFO: ----------------------------------------------------------------------
[12:57:53.235] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:57:53.235] INFO: ----------------------------------------------------------------------
[12:57:53.850] INFO: Expecting 208000 events.
[12:58:09.832] INFO: 208000 events read in total (15455ms).
[12:58:09.840] INFO: Test took 16596ms.
[12:58:10.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:10.696] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0
[12:58:10.696] INFO: number of red-efficiency pixels: 395 306 778 1457 1384 1709 1250 967 432 724 1049 533 571 492 122 90
[12:58:10.696] INFO: number of X-ray hits detected: 202708 143883 243479 369472 402712 409247 394827 279370 241613 319946 317895 265691 274700 174093 76751 82505
[12:58:10.696] 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:10.696] INFO: number of Vcal hits detected: 207549 207664 206894 206067 206154 205413 206376 206666 207535 207177 206727 207402 207371 207383 207873 207909
[12:58:10.696] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.5 99.2 99.2 98.9 99.3 99.4 99.8 99.6 99.4 99.7 99.7 99.7 99.9 100.0
[12:58:10.696] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.5 99.1 99.1 98.8 99.2 99.4 99.8 99.6 99.4 99.7 99.7 99.7 99.9 100.0
[12:58:10.696] INFO: X-ray hit rate [MHz/cm2]: 59.4 42.2 71.4 108.3 118.0 120.0 115.7 81.9 70.8 93.8 93.2 77.9 80.5 51.0 22.5 24.2
[12:58:10.696] INFO: PixTestHighRate::doXPixelAlive() done
[12:58:10.747] INFO: PixTest:: pg_setup set to default.
[12:58:10.760] INFO: enter test to run
[12:58:16.586] INFO: test: exit no parameter change
[12:58:16.925] QUIET: Connection to board 33 closed.
[12:58:16.926] INFO: pXar: this is the end, my friend