[16:57:47.619] INFO: *** Welcome to pxar ***
[16:57:47.619] INFO: *** Today: 2016/07/15
[16:57:47.636] INFO: *** Version: v1.9.0-814-g7497
[16:57:47.636] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//dacParameters35_C15.dat
[16:57:47.637] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:57:47.637] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//defaultMaskFile.dat
[16:57:47.637] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C15.dat
[16:57:47.712] INFO: clk: 4
[16:57:47.712] INFO: ctr: 4
[16:57:47.712] INFO: sda: 19
[16:57:47.712] INFO: tin: 9
[16:57:47.712] INFO: level: 15
[16:57:47.712] INFO: triggerdelay: 0
[16:57:47.712] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:57:47.712] INFO: Log level: INFO
[16:57:47.729] QUIET: Connection to board DTB_WREKRL opened.
[16:57:47.732] 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:57:47.734] INFO: RPC call hashes of host and DTB match: 398089610
[16:57:49.269] INFO: DUT info:
[16:57:49.269] INFO: The DUT currently contains the following objects:
[16:57:49.269] INFO: 2 TBM Cores tbm08c (2 ON)
[16:57:49.269] INFO: TBM Core alpha (0): 7 registers set
[16:57:49.270] INFO: TBM Core beta (1): 7 registers set
[16:57:49.270] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:57:49.270] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.270] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:57:49.688] INFO: enter 'restricted' command line mode
[16:57:49.688] INFO: enter test to run
[16:57:59.486] INFO: test: PixelAlive no parameter change
[16:57:59.486] INFO: running: pixelalive
[16:57:59.494] INFO: ----------------------------------------------------------------------
[16:57:59.494] 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:57:59.494] INFO: ----------------------------------------------------------------------
[16:57:59.826] INFO: Expecting 41600 events.
[16:58:04.101] INFO: 41600 events read in total (3557ms).
[16:58:04.259] INFO: Test took 4763ms.
[16:58:04.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:58:04.531] INFO: PixTestAlive::aliveTest() done
[16:58:04.531] INFO: number of dead pixels (per ROC): 0 0 0 0 0 23 53 126 3 0 0 0 0 0 0 0
[16:58:04.560] INFO: enter test to run
[16:58:28.093] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:58:28.094] INFO: running: highrate
[16:58:28.094] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:58:28.364] INFO: ----------------------------------------------------------------------
[16:58:28.364] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:58:28.364] INFO: ----------------------------------------------------------------------
[16:58:28.364] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:58:28.364] INFO: edge/corner pixel THR is adjusted
[16:58:28.364] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:58:29.322] INFO: Collecting data for 5 seconds...
[16:58:34.341] INFO: Done with hot pixel readout
[16:58:45.985] INFO: PixTest:: pg_setup set to default.
[16:58:45.986] INFO: 35 hot pixels found in step 0
[16:58:46.979] INFO: Collecting data for 5 seconds...
[16:58:51.998] INFO: Done with hot pixel readout
[16:59:03.452] INFO: PixTest:: pg_setup set to default.
[16:59:03.452] INFO: 18 hot pixels found in step 1
[16:59:04.446] INFO: Collecting data for 5 seconds...
[16:59:09.464] INFO: Done with hot pixel readout
[16:59:20.608] INFO: PixTest:: pg_setup set to default.
[16:59:20.609] INFO: 16 hot pixels found in step 2
[16:59:21.608] INFO: Collecting data for 5 seconds...
[16:59:26.627] INFO: Done with hot pixel readout
[16:59:38.163] INFO: PixTest:: pg_setup set to default.
[16:59:38.164] INFO: 19 hot pixels found in step 3
[16:59:39.156] INFO: Collecting data for 5 seconds...
[16:59:44.173] INFO: Done with hot pixel readout
[16:59:54.997] INFO: PixTest:: pg_setup set to default.
[16:59:54.998] INFO: 17 hot pixels found in step 4
[16:59:55.997] INFO: Collecting data for 5 seconds...
[17:00:01.016] INFO: Done with hot pixel readout
[17:00:12.494] INFO: PixTest:: pg_setup set to default.
[17:00:12.495] INFO: 10 hot pixels found in step 5
[17:00:13.486] INFO: Collecting data for 5 seconds...
[17:00:18.502] INFO: Done with hot pixel readout
[17:00:29.809] INFO: PixTest:: pg_setup set to default.


[17:00:29.810] INFO: 8 hot pixels found in step 6
[17:00:30.801] INFO: Collecting data for 5 seconds...
[17:00:35.816] INFO: Done with hot pixel readout
[17:00:46.530] INFO: PixTest:: pg_setup set to default.


[17:00:46.531] INFO: 8 hot pixels found in step 7
[17:00:47.526] INFO: Collecting data for 5 seconds...
[17:00:52.543] INFO: Done with hot pixel readout
[17:01:03.651] INFO: PixTest:: pg_setup set to default.



[17:01:03.652] INFO: 6 hot pixels found in step 8
[17:01:04.646] INFO: Collecting data for 5 seconds...
[17:01:09.663] INFO: Done with hot pixel readout
[17:01:20.623] INFO: PixTest:: pg_setup set to default.


[17:01:20.624] INFO: 4 hot pixels found in step 9
[17:01:21.615] INFO: Collecting data for 5 seconds...
[17:01:26.632] INFO: Done with hot pixel readout
[17:01:37.323] INFO: PixTest:: pg_setup set to default.


[17:01:37.324] INFO: 6 hot pixels found in step 10
[17:01:38.316] INFO: Collecting data for 5 seconds...
[17:01:43.333] INFO: Done with hot pixel readout
[17:01:54.665] INFO: PixTest:: pg_setup set to default.

[17:01:54.666] INFO: 5 hot pixels found in step 11
[17:01:55.658] INFO: Collecting data for 5 seconds...
[17:02:00.675] INFO: Done with hot pixel readout
[17:02:11.644] INFO: PixTest:: pg_setup set to default.


[17:02:11.644] INFO: 4 hot pixels found in step 12
[17:02:12.636] INFO: Collecting data for 5 seconds...
[17:02:17.652] INFO: Done with hot pixel readout
[17:02:28.638] INFO: PixTest:: pg_setup set to default.

[17:02:28.639] INFO: 1 hot pixels found in step 13
[17:02:28.674] INFO: 1 hot pixels could not be trimmed and have been masked.
[17:02:28.677] INFO: PixTest::trimHotPixels() done
[17:02:28.678] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C0.dat
[17:02:28.683] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C1.dat
[17:02:28.690] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C2.dat
[17:02:28.696] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C3.dat
[17:02:28.702] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C4.dat
[17:02:28.707] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C5.dat
[17:02:28.713] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C6.dat
[17:02:28.718] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C7.dat
[17:02:28.723] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C8.dat
[17:02:28.729] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C9.dat
[17:02:28.735] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C10.dat
[17:02:28.741] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C11.dat
[17:02:28.746] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C12.dat
[17:02:28.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C13.dat
[17:02:28.757] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C14.dat
[17:02:28.763] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C15.dat
[17:02:28.768] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//defaultMaskFile.dat
[17:02:28.778] INFO: enter test to run
[17:03:44.652] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[17:03:44.652] INFO: running: highrate
[17:03:44.656] INFO: ----------------------------------------------------------------------
[17:03:44.656] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[17:03:44.656] INFO: ----------------------------------------------------------------------
[17:03:44.656] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[17:03:44.656] INFO: edge/corner pixel THR is adjusted
[17:03:44.657] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:03:45.613] INFO: Collecting data for 1 seconds...
[17:03:46.617] INFO: Done with hot pixel readout
[17:03:50.471] INFO: PixTest:: pg_setup set to default.
[17:03:50.471] INFO: 0 hot pixels found in step 0
[17:03:50.477] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:03:50.573] INFO: PixTest::trimHotPixels() done
[17:03:50.573] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C0.dat
[17:03:50.635] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C1.dat
[17:03:50.641] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C2.dat
[17:03:50.648] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C3.dat
[17:03:50.654] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C4.dat
[17:03:50.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C5.dat
[17:03:50.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C6.dat
[17:03:50.670] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C7.dat
[17:03:50.676] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C8.dat
[17:03:50.681] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C9.dat
[17:03:50.686] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C10.dat
[17:03:50.692] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C11.dat
[17:03:50.697] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C12.dat
[17:03:50.703] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C13.dat
[17:03:50.708] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C14.dat
[17:03:50.713] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C15.dat
[17:03:50.719] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-19_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//defaultMaskFile.dat
[17:03:50.730] INFO: enter test to run
[17:07:28.890] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[17:07:28.890] INFO: running: xray
[17:07:28.929] INFO: ----------------------------------------------------------------------
[17:07:28.929] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:07:28.929] INFO: ----------------------------------------------------------------------
[17:07:29.950] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:07:41.609] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[17:08:08.567] INFO: Resuming triggers.
[17:08:20.227] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[17:08:47.387] INFO: Resuming triggers.
[17:08:59.048] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[17:09:26.094] INFO: Resuming triggers.
[17:09:37.756] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[17:10:05.412] INFO: Resuming triggers.
[17:10:17.071] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[17:10:44.533] INFO: Resuming triggers.
[17:10:56.196] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[17:11:23.798] INFO: Resuming triggers.
[17:11:35.458] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[17:12:02.995] INFO: Resuming triggers.
[17:12:14.655] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[17:12:42.102] INFO: Resuming triggers.
[17:12:49.150] INFO: data taking finished, elapsed time: 100 seconds.
[17:13:06.029] INFO: PixTest:: pg_setup set to default.
[17:13:06.032] INFO: PixTestXray::doPhRun() done
[17:13:06.584] INFO: enter test to run
[17:15:22.743] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:15:22.743] INFO: running: xray
[17:15:22.744] INFO: ----------------------------------------------------------------------
[17:15:22.744] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:15:22.744] INFO: ----------------------------------------------------------------------
[17:15:23.707] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:15:30.696] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[17:16:01.165] INFO: Resuming triggers.
[17:16:08.154] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[17:16:37.381] INFO: Resuming triggers.
[17:16:44.371] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[17:17:14.392] INFO: Resuming triggers.
[17:17:21.381] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[17:17:50.662] INFO: Resuming triggers.
[17:17:57.649] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[17:18:27.693] INFO: Resuming triggers.
[17:18:34.683] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[17:19:05.912] INFO: Resuming triggers.
[17:19:12.902] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[17:19:43.164] INFO: Resuming triggers.
[17:19:50.152] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[17:20:19.215] INFO: Resuming triggers.
[17:20:26.203] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[17:20:55.312] INFO: Resuming triggers.
[17:21:02.304] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[17:21:31.632] INFO: Resuming triggers.
[17:21:38.624] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[17:22:08.299] INFO: Resuming triggers.
[17:22:15.290] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[17:22:44.451] INFO: Resuming triggers.
[17:22:51.444] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[17:23:20.999] INFO: Resuming triggers.
[17:23:27.988] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[17:23:58.263] INFO: Resuming triggers.
[17:24:00.741] INFO: data taking finished, elapsed time: 100 seconds.
[17:24:11.596] INFO: PixTest:: pg_setup set to default.
[17:24:11.599] INFO: PixTestXray::doPhRun() done
[17:24:11.849] INFO: enter test to run
[17:31:18.649] INFO: test: HighRate no parameter change
[17:31:18.649] INFO: running: highrate
[17:31:18.677] INFO: ----------------------------------------------------------------------
[17:31:18.677] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:31:18.677] INFO: ----------------------------------------------------------------------
[17:31:18.832] INFO: Expecting 768 events.
[17:31:19.966] INFO: 768 events read in total (418ms).
[17:31:19.967] INFO: Test took 1269ms.
[17:31:20.771] INFO: Expecting 41600 events.
[17:31:23.831] INFO: 41600 events read in total (2534ms).
[17:31:23.832] INFO: Test took 3840ms.
[17:31:23.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:24.592] INFO: Expecting 41600 events.
[17:31:27.860] INFO: 41600 events read in total (2742ms).
[17:31:27.861] INFO: Test took 3980ms.
[17:31:27.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:28.616] INFO: Expecting 41600 events.
[17:31:31.861] INFO: 41600 events read in total (2719ms).
[17:31:31.862] INFO: Test took 3950ms.
[17:31:31.896] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:32.622] INFO: Expecting 41600 events.
[17:31:35.883] INFO: 41600 events read in total (2734ms).
[17:31:35.883] INFO: Test took 3970ms.
[17:31:35.918] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:36.638] INFO: Expecting 41600 events.
[17:31:39.952] INFO: 41600 events read in total (2788ms).
[17:31:39.953] INFO: Test took 4017ms.
[17:31:39.987] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:40.699] INFO: Expecting 41600 events.
[17:31:44.043] INFO: 41600 events read in total (2818ms).
[17:31:44.044] INFO: Test took 4040ms.
[17:31:44.079] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:44.797] INFO: Expecting 41600 events.
[17:31:48.144] INFO: 41600 events read in total (2820ms).
[17:31:48.145] INFO: Test took 4049ms.
[17:31:48.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:48.906] INFO: Expecting 41600 events.
[17:31:52.273] INFO: 41600 events read in total (2841ms).
[17:31:52.274] INFO: Test took 4076ms.
[17:31:52.311] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:53.022] INFO: Expecting 41600 events.
[17:31:56.339] INFO: 41600 events read in total (2790ms).
[17:31:56.340] INFO: Test took 4012ms.
[17:31:56.373] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:57.096] INFO: Expecting 41600 events.
[17:32:00.313] INFO: 41600 events read in total (2690ms).
[17:32:00.314] INFO: Test took 3924ms.
[17:32:00.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:01.073] INFO: Expecting 41600 events.
[17:32:04.334] INFO: 41600 events read in total (2734ms).
[17:32:04.335] INFO: Test took 3970ms.
[17:32:04.369] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:05.094] INFO: Expecting 41600 events.
[17:32:08.399] INFO: 41600 events read in total (2778ms).
[17:32:08.400] INFO: Test took 4013ms.
[17:32:08.433] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:09.156] INFO: Expecting 41600 events.
[17:32:12.373] INFO: 41600 events read in total (2690ms).
[17:32:12.374] INFO: Test took 3923ms.
[17:32:12.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:13.133] INFO: Expecting 41600 events.
[17:32:16.353] INFO: 41600 events read in total (2693ms).
[17:32:16.354] INFO: Test took 3929ms.
[17:32:16.386] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:17.110] INFO: Expecting 41600 events.
[17:32:20.341] INFO: 41600 events read in total (2704ms).
[17:32:20.342] INFO: Test took 3938ms.
[17:32:20.375] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:21.101] INFO: Expecting 41600 events.
[17:32:24.326] INFO: 41600 events read in total (2699ms).
[17:32:24.327] INFO: Test took 3934ms.
[17:32:24.360] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:25.089] INFO: Expecting 41600 events.
[17:32:28.307] INFO: 41600 events read in total (2691ms).
[17:32:28.308] INFO: Test took 3930ms.
[17:32:28.341] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:29.068] INFO: Expecting 41600 events.
[17:32:32.290] INFO: 41600 events read in total (2695ms).
[17:32:32.291] INFO: Test took 3932ms.
[17:32:32.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:33.049] INFO: Expecting 41600 events.
[17:32:36.248] INFO: 41600 events read in total (2672ms).
[17:32:36.249] INFO: Test took 3908ms.
[17:32:36.281] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:37.005] INFO: Expecting 41600 events.
[17:32:40.088] INFO: 41600 events read in total (2556ms).
[17:32:40.089] INFO: Test took 3790ms.
[17:32:40.121] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:40.487] INFO: enter test to run
[17:33:01.328] INFO: test: HighRate no parameter change
[17:33:01.328] INFO: running: highrate
[17:33:01.329] INFO: ----------------------------------------------------------------------
[17:33:01.329] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:33:01.329] INFO: ----------------------------------------------------------------------
[17:33:01.944] INFO: Expecting 208000 events.
[17:33:13.780] INFO: 208000 events read in total (11309ms).
[17:33:13.784] INFO: Test took 12444ms.
[17:33:13.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:14.172] INFO: number of dead pixels (per ROC): 0 0 0 0 0 23 53 126 3 0 0 0 0 0 0 0
[17:33:14.172] INFO: number of red-efficiency pixels: 83 47 85 105 119 162 223 257 91 128 131 118 89 74 42 33
[17:33:14.172] INFO: number of X-ray hits detected: 66602 39905 60330 91017 91622 95778 108383 80013 73834 104189 99903 91040 91078 57672 22960 26955
[17:33:14.172] 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:33:14.172] INFO: number of Vcal hits detected: 207916 207952 207912 207894 207879 206709 205179 201557 207762 207870 207865 207876 207910 207925 207958 207966
[17:33:14.172] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[17:33:14.172] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.4 98.6 96.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[17:33:14.172] INFO: X-ray hit rate [MHz/cm2]: 19.5 11.7 17.7 26.7 26.9 28.1 31.8 23.5 21.6 30.5 29.3 26.7 26.7 16.9 6.7 7.9
[17:33:14.172] INFO: PixTestHighRate::doXPixelAlive() done
[17:33:14.222] INFO: PixTest:: pg_setup set to default.
[17:33:14.236] INFO: enter test to run
[17:33:56.408] INFO: test: HighRate no parameter change
[17:33:56.408] INFO: running: highrate
[17:33:56.409] INFO: ----------------------------------------------------------------------
[17:33:56.409] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:33:56.409] INFO: ----------------------------------------------------------------------
[17:33:57.026] INFO: Expecting 208000 events.
[17:34:10.421] INFO: 208000 events read in total (12868ms).
[17:34:10.426] INFO: Test took 14008ms.
[17:34:10.712] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:34:11.007] INFO: number of dead pixels (per ROC): 0 0 0 0 0 23 53 126 3 0 0 0 0 0 0 0
[17:34:11.007] INFO: number of red-efficiency pixels: 255 130 257 311 310 394 533 376 288 445 429 296 291 246 64 78
[17:34:11.008] INFO: number of X-ray hits detected: 136542 81575 122222 185775 184803 196309 212820 153285 150063 212565 203074 184496 186318 118381 46792 55820
[17:34:11.008] 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:34:11.008] INFO: number of Vcal hits detected: 207725 207866 207728 207674 207664 206452 204833 201430 207550 207509 207532 207673 207693 207742 207936 207922
[17:34:11.008] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.9 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[17:34:11.008] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.3 98.5 96.8 99.8 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[17:34:11.008] INFO: X-ray hit rate [MHz/cm2]: 40.0 23.9 35.8 54.5 54.2 57.5 62.4 44.9 44.0 62.3 59.5 54.1 54.6 34.7 13.7 16.4
[17:34:11.008] INFO: PixTestHighRate::doXPixelAlive() done
[17:34:11.059] INFO: PixTest:: pg_setup set to default.
[17:34:11.078] INFO: enter test to run
[17:34:25.343] INFO: test: HighRate no parameter change
[17:34:25.343] INFO: running: highrate
[17:34:25.344] INFO: ----------------------------------------------------------------------
[17:34:25.344] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:34:25.344] INFO: ----------------------------------------------------------------------
[17:34:25.963] INFO: Expecting 208000 events.
[17:34:41.085] INFO: 208000 events read in total (14595ms).
[17:34:41.092] INFO: Test took 15738ms.
[17:34:41.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:34:41.854] INFO: number of dead pixels (per ROC): 0 0 0 0 0 23 53 126 3 0 0 0 0 0 0 0
[17:34:41.854] INFO: number of red-efficiency pixels: 536 267 549 729 612 882 1062 633 498 1061 1013 668 605 532 98 110
[17:34:41.854] INFO: number of X-ray hits detected: 204303 123275 183686 278027 276619 294403 315367 224715 224158 318274 304351 277859 279881 176871 70977 83301
[17:34:41.854] 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:34:41.854] INFO: number of Vcal hits detected: 207358 207696 207331 207143 207308 205805 204128 201115 207283 206696 206741 207198 207309 207357 207900 207885
[17:34:41.854] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.6 99.7 99.5 99.5 99.7 99.8 99.4 99.5 99.7 99.7 99.7 100.0 99.9
[17:34:41.854] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.6 99.7 98.9 98.1 96.7 99.7 99.4 99.4 99.6 99.7 99.7 100.0 99.9
[17:34:41.854] INFO: X-ray hit rate [MHz/cm2]: 59.9 36.1 53.8 81.5 81.1 86.3 92.4 65.9 65.7 93.3 89.2 81.4 82.0 51.8 20.8 24.4
[17:34:41.854] INFO: PixTestHighRate::doXPixelAlive() done
[17:34:41.903] INFO: PixTest:: pg_setup set to default.
[17:34:41.921] INFO: enter test to run
[17:36:05.839] INFO: test: exit no parameter change
[17:36:06.212] QUIET: Connection to board 33 closed.
[17:36:06.272] INFO: pXar: this is the end, my friend