[16:37:36.446] INFO: *** Welcome to pxar ***
[16:37:36.446] INFO: *** Today: 2016/07/13
[16:37:36.466] INFO: *** Version: v1.9.0-814-g7497
[16:37:36.466] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//dacParameters35_C15.dat
[16:37:36.467] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:37:36.467] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//defaultMaskFile.dat
[16:37:36.467] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C15.dat
[16:37:36.535] INFO: clk: 4
[16:37:36.535] INFO: ctr: 4
[16:37:36.535] INFO: sda: 19
[16:37:36.535] INFO: tin: 9
[16:37:36.535] INFO: level: 15
[16:37:36.535] INFO: triggerdelay: 0
[16:37:36.536] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:37:36.536] INFO: Log level: INFO
[16:37:36.554] QUIET: Connection to board DTB_WREKRL opened.
[16:37:36.557] 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:
------------------------------------------------------
[16:37:36.560] INFO: RPC call hashes of host and DTB match: 398089610
[16:37:38.090] INFO: DUT info:
[16:37:38.090] INFO: The DUT currently contains the following objects:
[16:37:38.090] INFO: 2 TBM Cores tbm08c (2 ON)
[16:37:38.090] INFO: TBM Core alpha (0): 7 registers set
[16:37:38.090] INFO: TBM Core beta (1): 7 registers set
[16:37:38.090] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:37:38.090] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.090] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:38.494] INFO: enter 'restricted' command line mode
[16:37:38.494] INFO: enter test to run
[16:37:41.391] INFO: test: PixelAlive no parameter change
[16:37:41.391] INFO: running: pixelalive
[16:37:41.400] INFO: ----------------------------------------------------------------------
[16:37:41.400] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:37:41.400] INFO: ----------------------------------------------------------------------
[16:37:41.718] INFO: Expecting 41600 events.
[16:37:46.033] INFO: 41600 events read in total (3596ms).
[16:37:46.199] INFO: Test took 4797ms.
[16:37:46.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:37:46.481] INFO: PixTestAlive::aliveTest() done
[16:37:46.481] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[16:37:46.513] INFO: enter test to run
[16:38:27.183] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:38:27.183] INFO: running: highrate
[16:38:27.194] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:38:27.381] INFO: ----------------------------------------------------------------------
[16:38:27.381] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:38:27.381] INFO: ----------------------------------------------------------------------
[16:38:27.381] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:38:27.381] INFO: edge/corner pixel THR is adjusted
[16:38:27.381] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:38:28.341] INFO: Collecting data for 5 seconds...
[16:38:33.357] INFO: Done with hot pixel readout
[16:38:45.518] INFO: PixTest:: pg_setup set to default.
[16:38:45.519] INFO: 18 hot pixels found in step 0
[16:38:46.535] INFO: Collecting data for 5 seconds...
[16:38:51.553] INFO: Done with hot pixel readout
[16:39:03.419] INFO: PixTest:: pg_setup set to default.
[16:39:03.420] INFO: 12 hot pixels found in step 1
[16:39:04.410] INFO: Collecting data for 5 seconds...
[16:39:09.428] INFO: Done with hot pixel readout
[16:39:21.015] INFO: PixTest:: pg_setup set to default.
[16:39:21.016] INFO: 11 hot pixels found in step 2
[16:39:22.006] INFO: Collecting data for 5 seconds...
[16:39:27.025] INFO: Done with hot pixel readout
[16:39:38.978] INFO: PixTest:: pg_setup set to default.
[16:39:38.979] INFO: 12 hot pixels found in step 3
[16:39:39.970] INFO: Collecting data for 5 seconds...
[16:39:44.988] INFO: Done with hot pixel readout
[16:39:56.696] INFO: PixTest:: pg_setup set to default.
[16:39:56.697] INFO: 7 hot pixels found in step 4
[16:39:57.687] INFO: Collecting data for 5 seconds...
[16:40:02.706] INFO: Done with hot pixel readout
[16:40:14.146] INFO: PixTest:: pg_setup set to default.
[16:40:14.147] INFO: 7 hot pixels found in step 5
[16:40:15.138] INFO: Collecting data for 5 seconds...
[16:40:20.155] INFO: Done with hot pixel readout
[16:40:31.781] INFO: PixTest:: pg_setup set to default.
[16:40:31.782] INFO: 6 hot pixels found in step 6
[16:40:32.772] INFO: Collecting data for 5 seconds...
[16:40:37.790] INFO: Done with hot pixel readout
[16:40:49.818] INFO: PixTest:: pg_setup set to default.


[16:40:49.819] INFO: 8 hot pixels found in step 7
[16:40:50.809] INFO: Collecting data for 5 seconds...
[16:40:55.828] INFO: Done with hot pixel readout
[16:41:08.204] INFO: PixTest:: pg_setup set to default.

[16:41:08.205] INFO: 4 hot pixels found in step 8
[16:41:09.195] INFO: Collecting data for 5 seconds...
[16:41:14.213] INFO: Done with hot pixel readout
[16:41:26.705] INFO: PixTest:: pg_setup set to default.
[16:41:26.705] INFO: 6 hot pixels found in step 9
[16:41:27.696] INFO: Collecting data for 5 seconds...
[16:41:32.715] INFO: Done with hot pixel readout
[16:41:44.704] INFO: PixTest:: pg_setup set to default.

[16:41:44.705] INFO: 8 hot pixels found in step 10
[16:41:45.696] INFO: Collecting data for 5 seconds...
[16:41:50.715] INFO: Done with hot pixel readout
[16:42:02.667] INFO: PixTest:: pg_setup set to default.

[16:42:02.668] INFO: 8 hot pixels found in step 11
[16:42:03.658] INFO: Collecting data for 5 seconds...
[16:42:08.679] INFO: Done with hot pixel readout
[16:42:20.874] INFO: PixTest:: pg_setup set to default.
[16:42:20.875] INFO: 5 hot pixels found in step 12
[16:42:21.866] INFO: Collecting data for 5 seconds...
[16:42:26.884] INFO: Done with hot pixel readout
[16:42:39.048] INFO: PixTest:: pg_setup set to default.
[16:42:39.049] INFO: 5 hot pixels found in step 13
[16:42:40.039] INFO: Collecting data for 5 seconds...
[16:42:45.058] INFO: Done with hot pixel readout
[16:42:56.964] INFO: PixTest:: pg_setup set to default.
[16:42:56.965] INFO: 2 hot pixels found in step 14
[16:42:56.998] INFO: 2 hot pixels could not be trimmed and have been masked.
[16:42:56.002] INFO: PixTest::trimHotPixels() done
[16:42:57.005] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C0.dat
[16:42:57.011] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C1.dat
[16:42:57.017] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C2.dat
[16:42:57.022] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C3.dat
[16:42:57.028] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C4.dat
[16:42:57.033] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C5.dat
[16:42:57.038] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C6.dat
[16:42:57.043] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C7.dat
[16:42:57.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C8.dat
[16:42:57.054] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C9.dat
[16:42:57.059] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C10.dat
[16:42:57.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C11.dat
[16:42:57.070] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C12.dat
[16:42:57.075] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C13.dat
[16:42:57.081] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C14.dat
[16:42:57.086] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C15.dat
[16:42:57.091] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//defaultMaskFile.dat
[16:42:57.102] INFO: enter test to run
[16:45:07.844] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:45:07.844] INFO: running: highrate
[16:45:07.849] INFO: ----------------------------------------------------------------------
[16:45:07.849] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:45:07.849] INFO: ----------------------------------------------------------------------
[16:45:07.849] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:45:07.849] INFO: edge/corner pixel THR is adjusted
[16:45:07.849] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:45:08.811] INFO: Collecting data for 1 seconds...
[16:45:09.814] INFO: Done with hot pixel readout
[16:45:13.891] INFO: PixTest:: pg_setup set to default.
[16:45:13.891] INFO: 0 hot pixels found in step 0
[16:45:13.896] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:45:13.981] INFO: PixTest::trimHotPixels() done
[16:45:13.981] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C0.dat
[16:45:13.993] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C1.dat
[16:45:13.999] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C2.dat
[16:45:14.004] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C3.dat
[16:45:14.009] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C4.dat
[16:45:14.015] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C5.dat
[16:45:14.020] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C6.dat
[16:45:14.025] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C7.dat
[16:45:14.030] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C8.dat
[16:45:14.036] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C9.dat
[16:45:14.041] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C10.dat
[16:45:14.046] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C11.dat
[16:45:14.051] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C12.dat
[16:45:14.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C13.dat
[16:45:14.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C14.dat
[16:45:14.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//trimParameters35_C15.dat
[16:45:14.074] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-20_FPIXTest-17C-FNAL-160630-0856_2016-06-30_13h49m_1467312578/000_FPIXTest_p17//defaultMaskFile.dat
[16:45:14.084] INFO: enter test to run
[16:49:56.338] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:49:56.338] INFO: running: xray
[16:49:56.340] INFO: ----------------------------------------------------------------------
[16:49:56.340] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:49:56.340] INFO: ----------------------------------------------------------------------
[16:49:57.303] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:50:08.438] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:50:37.692] INFO: Resuming triggers.
[16:50:48.831] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:51:18.536] INFO: Resuming triggers.
[16:51:29.672] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:51:58.853] INFO: Resuming triggers.
[16:52:09.985] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:52:39.698] INFO: Resuming triggers.
[16:52:50.831] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[16:53:21.433] INFO: Resuming triggers.
[16:53:32.567] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[16:54:02.510] INFO: Resuming triggers.
[16:54:13.639] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[16:54:43.192] INFO: Resuming triggers.
[16:54:54.323] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[16:55:23.617] INFO: Resuming triggers.
[16:55:34.753] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[16:56:04.127] INFO: Resuming triggers.
[16:56:04.269] INFO: data taking finished, elapsed time: 100 seconds.
[16:56:05.167] INFO: PixTest:: pg_setup set to default.
[16:56:05.170] INFO: PixTestXray::doPhRun() done
[16:56:05.329] INFO: enter test to run
[16:56:40.639] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:56:40.639] INFO: running: xray
[16:56:40.640] INFO: ----------------------------------------------------------------------
[16:56:40.640] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:56:40.640] INFO: ----------------------------------------------------------------------
[16:56:41.623] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:56:48.050] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:57:18.136] INFO: Resuming triggers.
[16:57:24.562] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[16:57:54.548] INFO: Resuming triggers.
[16:58:00.978] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[16:58:31.009] INFO: Resuming triggers.
[16:58:37.438] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[16:59:07.502] INFO: Resuming triggers.
[16:59:13.933] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[16:59:43.997] INFO: Resuming triggers.
[16:59:50.428] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[17:00:20.376] INFO: Resuming triggers.
[17:00:26.809] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[17:00:56.823] INFO: Resuming triggers.
[17:01:03.253] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[17:01:33.264] INFO: Resuming triggers.
[17:01:39.691] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[17:02:09.705] INFO: Resuming triggers.
[17:02:16.136] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[17:02:46.758] INFO: Resuming triggers.
[17:02:53.181] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[17:03:23.659] INFO: Resuming triggers.
[17:03:30.088] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[17:04:00.573] INFO: Resuming triggers.
[17:04:06.000] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[17:04:37.692] INFO: Resuming triggers.
[17:04:44.115] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[17:05:15.340] INFO: Resuming triggers.
[17:05:21.761] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[17:05:52.480] INFO: Resuming triggers.
[17:05:56.391] INFO: data taking finished, elapsed time: 100 seconds.
[17:06:15.033] INFO: PixTest:: pg_setup set to default.
[17:06:15.036] INFO: PixTestXray::doPhRun() done
[17:06:15.184] INFO: enter test to run
[17:06:55.899] INFO: test: HighRate no parameter change
[17:06:55.899] INFO: running: highrate
[17:06:55.918] INFO: ----------------------------------------------------------------------
[17:06:55.918] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:06:55.918] INFO: ----------------------------------------------------------------------
[17:06:56.074] INFO: Expecting 768 events.
[17:06:57.209] INFO: 768 events read in total (419ms).
[17:06:57.209] INFO: Test took 1270ms.
[17:06:58.012] INFO: Expecting 41600 events.
[17:07:01.093] INFO: 41600 events read in total (2554ms).
[17:07:01.095] INFO: Test took 3853ms.
[17:07:01.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:01.853] INFO: Expecting 41600 events.
[17:07:05.003] INFO: 41600 events read in total (2623ms).
[17:07:05.004] INFO: Test took 3855ms.
[17:07:05.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:05.763] INFO: Expecting 41600 events.
[17:07:09.012] INFO: 41600 events read in total (2722ms).
[17:07:09.013] INFO: Test took 3952ms.
[17:07:09.049] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:09.769] INFO: Expecting 41600 events.
[17:07:13.032] INFO: 41600 events read in total (2736ms).
[17:07:13.033] INFO: Test took 3966ms.
[17:07:13.070] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:13.787] INFO: Expecting 41600 events.
[17:07:17.056] INFO: 41600 events read in total (2742ms).
[17:07:17.057] INFO: Test took 3969ms.
[17:07:17.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:17.816] INFO: Expecting 41600 events.
[17:07:21.084] INFO: 41600 events read in total (2741ms).
[17:07:21.085] INFO: Test took 3972ms.
[17:07:21.121] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:21.839] INFO: Expecting 41600 events.
[17:07:25.095] INFO: 41600 events read in total (2729ms).
[17:07:25.096] INFO: Test took 3956ms.
[17:07:25.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:25.853] INFO: Expecting 41600 events.
[17:07:29.137] INFO: 41600 events read in total (2757ms).
[17:07:29.139] INFO: Test took 3988ms.
[17:07:29.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:29.895] INFO: Expecting 41600 events.
[17:07:33.179] INFO: 41600 events read in total (2757ms).
[17:07:33.180] INFO: Test took 3987ms.
[17:07:33.217] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:33.933] INFO: Expecting 41600 events.
[17:07:37.217] INFO: 41600 events read in total (2757ms).
[17:07:37.218] INFO: Test took 3983ms.
[17:07:37.254] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:37.974] INFO: Expecting 41600 events.
[17:07:41.258] INFO: 41600 events read in total (2757ms).
[17:07:41.259] INFO: Test took 3986ms.
[17:07:41.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:42.016] INFO: Expecting 41600 events.
[17:07:45.288] INFO: 41600 events read in total (2745ms).
[17:07:45.289] INFO: Test took 3974ms.
[17:07:45.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:46.044] INFO: Expecting 41600 events.
[17:07:49.322] INFO: 41600 events read in total (2752ms).
[17:07:49.323] INFO: Test took 3979ms.
[17:07:49.360] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:50.078] INFO: Expecting 41600 events.
[17:07:53.353] INFO: 41600 events read in total (2748ms).
[17:07:53.354] INFO: Test took 3975ms.
[17:07:53.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:54.109] INFO: Expecting 41600 events.
[17:07:57.396] INFO: 41600 events read in total (2760ms).
[17:07:57.398] INFO: Test took 3989ms.
[17:07:57.434] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:58.153] INFO: Expecting 41600 events.
[17:08:01.429] INFO: 41600 events read in total (2749ms).
[17:08:01.429] INFO: Test took 3976ms.
[17:08:01.465] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:02.184] INFO: Expecting 41600 events.
[17:08:05.450] INFO: 41600 events read in total (2739ms).
[17:08:05.451] INFO: Test took 3967ms.
[17:08:05.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:06.207] INFO: Expecting 41600 events.
[17:08:09.484] INFO: 41600 events read in total (2750ms).
[17:08:09.485] INFO: Test took 3978ms.
[17:08:09.522] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:10.244] INFO: Expecting 41600 events.
[17:08:13.489] INFO: 41600 events read in total (2718ms).
[17:08:13.490] INFO: Test took 3950ms.
[17:08:13.526] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:14.248] INFO: Expecting 41600 events.
[17:08:17.313] INFO: 41600 events read in total (2539ms).
[17:08:17.314] INFO: Test took 3768ms.
[17:08:17.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:17.703] INFO: enter test to run
[17:09:48.802] INFO: test: HighRate no parameter change
[17:09:48.802] INFO: running: highrate
[17:09:48.803] INFO: ----------------------------------------------------------------------
[17:09:48.803] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:09:48.803] INFO: ----------------------------------------------------------------------
[17:09:49.412] INFO: Expecting 208000 events.
[17:10:01.035] INFO: 208000 events read in total (11096ms).
[17:10:01.038] INFO: Test took 12228ms.
[17:10:01.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:10:01.456] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[17:10:01.456] INFO: number of red-efficiency pixels: 69 38 77 130 177 126 165 103 101 167 168 123 118 63 24 28
[17:10:01.456] INFO: number of X-ray hits detected: 58352 39574 67017 104972 116998 115025 122874 93180 92861 117774 117085 98940 99648 61266 22852 25887
[17:10:01.457] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:10:01.457] INFO: number of Vcal hits detected: 207881 207962 207921 207867 207818 207872 207832 207896 207875 207824 207827 207875 207880 207935 207976 207874
[17:10:01.457] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[17:10:01.457] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9
[17:10:01.457] INFO: X-ray hit rate [MHz/cm2]: 17.1 11.6 19.6 30.8 34.3 33.7 36.0 27.3 27.2 34.5 34.3 29.0 29.2 18.0 6.7 7.6
[17:10:01.457] INFO: PixTestHighRate::doXPixelAlive() done
[17:10:01.508] INFO: PixTest:: pg_setup set to default.
[17:10:01.518] INFO: enter test to run
[17:10:59.449] INFO: test: HighRate no parameter change
[17:10:59.449] INFO: running: highrate
[17:10:59.451] INFO: ----------------------------------------------------------------------
[17:10:59.451] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:10:59.451] INFO: ----------------------------------------------------------------------
[17:11:00.068] INFO: Expecting 208000 events.
[17:11:13.494] INFO: 208000 events read in total (12900ms).
[17:11:13.499] INFO: Test took 14038ms.
[17:11:13.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:11:14.128] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[17:11:14.128] INFO: number of red-efficiency pixels: 137 111 268 339 568 423 596 293 262 596 529 427 413 213 45 56
[17:11:14.128] INFO: number of X-ray hits detected: 118737 79692 134988 212434 235562 234107 249837 189003 188319 238056 237641 200672 202516 124257 46235 53162
[17:11:14.128] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:11:14.128] INFO: number of Vcal hits detected: 207810 207884 207717 207637 207366 207535 207339 207683 207678 207337 207414 207536 207559 207767 207955 207845
[17:11:14.128] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.9 99.9 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[17:11:14.128] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.8 99.7 99.7 99.8 99.8 99.9 100.0 99.9
[17:11:14.128] INFO: X-ray hit rate [MHz/cm2]: 34.8 23.4 39.6 62.3 69.0 68.6 73.2 55.4 55.2 69.8 69.7 58.8 59.4 36.4 13.6 15.6
[17:11:14.128] INFO: PixTestHighRate::doXPixelAlive() done
[17:11:14.178] INFO: PixTest:: pg_setup set to default.
[17:11:14.192] INFO: enter test to run
[17:11:29.041] INFO: test: HighRate no parameter change
[17:11:29.041] INFO: running: highrate
[17:11:29.042] INFO: ----------------------------------------------------------------------
[17:11:29.042] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:11:29.042] INFO: ----------------------------------------------------------------------
[17:11:29.660] INFO: Expecting 208000 events.
[17:11:45.298] INFO: 208000 events read in total (15111ms).
[17:11:45.305] INFO: Test took 16253ms.
[17:11:45.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:11:46.171] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[17:11:46.171] INFO: number of red-efficiency pixels: 287 211 637 782 1331 1000 1436 695 587 1372 1370 1063 963 499 78 71
[17:11:46.171] INFO: number of X-ray hits detected: 180701 121397 204759 321338 357126 353888 377411 286912 284830 362417 358368 305139 308044 188936 70739 80950
[17:11:46.171] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:11:46.171] INFO: number of Vcal hits detected: 207635 207771 207130 207095 206204 206729 206027 207140 207218 206139 206146 206617 206819 207360 207920 207829
[17:11:46.171] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.6 99.6 99.2 99.4 99.1 99.6 99.7 99.2 99.2 99.4 99.5 99.7 100.0 100.0
[17:11:46.171] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.6 99.1 99.4 99.1 99.6 99.6 99.1 99.1 99.3 99.4 99.7 100.0 99.9
[17:11:46.171] INFO: X-ray hit rate [MHz/cm2]: 53.0 35.6 60.0 94.2 104.7 103.7 110.6 84.1 83.5 106.2 105.0 89.4 90.3 55.4 20.7 23.7
[17:11:46.171] INFO: PixTestHighRate::doXPixelAlive() done
[17:11:46.215] INFO: PixTest:: pg_setup set to default.
[17:11:46.226] INFO: enter test to run
[17:12:21.417] INFO: test: exit no parameter change
[17:12:21.677] QUIET: Connection to board 33 closed.
[17:12:21.688] INFO: pXar: this is the end, my friend