[14:25:29.082] INFO: *** Welcome to pxar ***
[14:25:29.082] INFO: *** Today: 2016/08/23
[14:25:29.099] INFO: *** Version: v1.9.0-818-g96727
[14:25:29.099] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//dacParameters35_C15.dat
[14:25:29.100] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:25:29.100] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//defaultMaskFile.dat
[14:25:29.100] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C15.dat
[14:25:29.174] INFO: clk: 4
[14:25:29.174] INFO: ctr: 4
[14:25:29.174] INFO: sda: 19
[14:25:29.174] INFO: tin: 9
[14:25:29.174] INFO: level: 15
[14:25:29.174] INFO: triggerdelay: 0
[14:25:29.174] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:25:29.174] INFO: Log level: INFO
[14:25:29.193] QUIET: Connection to board DTB_WREKRL opened.
[14:25:29.196] 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:
------------------------------------------------------
[14:25:29.199] INFO: RPC call hashes of host and DTB match: 398089610
[14:25:30.730] INFO: DUT info:
[14:25:30.731] INFO: The DUT currently contains the following objects:
[14:25:30.731] INFO: 2 TBM Cores tbm08c (2 ON)
[14:25:30.731] INFO: TBM Core alpha (0): 7 registers set
[14:25:30.731] INFO: TBM Core beta (1): 7 registers set
[14:25:30.731] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:25:30.731] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:30.731] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:31.135] INFO: enter 'restricted' command line mode
[14:25:31.135] INFO: enter test to run
[14:25:36.823] INFO: test: PixelAlive no parameter change
[14:25:36.823] INFO: running: pixelalive
[14:25:36.832] INFO: ----------------------------------------------------------------------
[14:25:36.832] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:25:36.832] INFO: ----------------------------------------------------------------------
[14:25:37.147] INFO: Expecting 41600 events.
[14:25:41.497] INFO: 41600 events read in total (3631ms).
[14:25:41.646] INFO: Test took 4811ms.
[14:25:41.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:41.941] INFO: PixTestAlive::aliveTest() done
[14:25:41.941] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[14:25:41.973] INFO: enter test to run
[14:26:06.511] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:26:06.511] INFO: running: highrate
[14:26:06.540] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:26:06.858] INFO: ----------------------------------------------------------------------
[14:26:06.858] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:26:06.858] INFO: ----------------------------------------------------------------------
[14:26:06.858] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:26:06.858] INFO: edge/corner pixel THR is adjusted
[14:26:06.858] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:26:07.846] INFO: Collecting data for 5 seconds...
[14:26:12.864] INFO: Done with hot pixel readout
[14:26:24.112] INFO: PixTest:: pg_setup set to default.
[14:26:24.113] INFO: 6 hot pixels found in step 0
[14:26:25.101] INFO: Collecting data for 5 seconds...
[14:26:30.117] INFO: Done with hot pixel readout
[14:26:41.348] INFO: PixTest:: pg_setup set to default.
[14:26:41.349] INFO: 6 hot pixels found in step 1
[14:26:42.337] INFO: Collecting data for 5 seconds...
[14:26:47.354] INFO: Done with hot pixel readout
[14:26:58.583] INFO: PixTest:: pg_setup set to default.
[14:26:58.584] INFO: 5 hot pixels found in step 2
[14:26:59.572] INFO: Collecting data for 5 seconds...
[14:27:04.589] INFO: Done with hot pixel readout
[14:27:15.801] INFO: PixTest:: pg_setup set to default.
[14:27:15.801] INFO: 4 hot pixels found in step 3
[14:27:16.789] INFO: Collecting data for 5 seconds...
[14:27:21.806] INFO: Done with hot pixel readout
[14:27:33.031] INFO: PixTest:: pg_setup set to default.
[14:27:33.032] INFO: 4 hot pixels found in step 4
[14:27:34.019] INFO: Collecting data for 5 seconds...
[14:27:39.036] INFO: Done with hot pixel readout
[14:27:50.263] INFO: PixTest:: pg_setup set to default.
[14:27:50.264] INFO: 1 hot pixels found in step 5
[14:27:51.252] INFO: Collecting data for 5 seconds...
[14:27:56.268] INFO: Done with hot pixel readout
[14:28:07.498] INFO: PixTest:: pg_setup set to default.
[14:28:07.499] INFO: 5 hot pixels found in step 6
[14:28:08.488] INFO: Collecting data for 5 seconds...
[14:28:13.504] INFO: Done with hot pixel readout
[14:28:24.754] INFO: PixTest:: pg_setup set to default.
[14:28:24.754] INFO: 3 hot pixels found in step 7
[14:28:25.742] INFO: Collecting data for 5 seconds...
[14:28:30.759] INFO: Done with hot pixel readout
[14:28:41.934] INFO: PixTest:: pg_setup set to default.

[14:28:41.935] INFO: 3 hot pixels found in step 8
[14:28:42.922] INFO: Collecting data for 5 seconds...
[14:28:47.939] INFO: Done with hot pixel readout
[14:28:59.145] INFO: PixTest:: pg_setup set to default.


[14:28:59.146] INFO: 4 hot pixels found in step 9
[14:29:00.133] INFO: Collecting data for 5 seconds...
[14:29:05.150] INFO: Done with hot pixel readout
[14:29:16.366] INFO: PixTest:: pg_setup set to default.

[14:29:16.367] INFO: 2 hot pixels found in step 10
[14:29:17.356] INFO: Collecting data for 5 seconds...
[14:29:22.373] INFO: Done with hot pixel readout
[14:29:33.503] INFO: PixTest:: pg_setup set to default.
[14:29:33.504] INFO: 1 hot pixels found in step 11
[14:29:34.492] INFO: Collecting data for 5 seconds...
[14:29:39.507] INFO: Done with hot pixel readout
[14:29:47.923] INFO: PixTest:: pg_setup set to default.

[14:29:47.924] INFO: 2 hot pixels found in step 12
[14:29:48.911] INFO: Collecting data for 5 seconds...
[14:29:53.927] INFO: Done with hot pixel readout
[14:30:04.940] INFO: PixTest:: pg_setup set to default.
[14:30:04.941] INFO: 0 hot pixels found in step 13
[14:30:04.973] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:30:05.055] INFO: PixTest::trimHotPixels() done
[14:30:05.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C0.dat
[14:30:05.067] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C1.dat
[14:30:05.072] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C2.dat
[14:30:05.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C3.dat
[14:30:05.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C4.dat
[14:30:05.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C5.dat
[14:30:05.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C6.dat
[14:30:05.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C7.dat
[14:30:05.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C8.dat
[14:30:05.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C9.dat
[14:30:05.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C10.dat
[14:30:05.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C11.dat
[14:30:05.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C12.dat
[14:30:05.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C13.dat
[14:30:05.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C14.dat
[14:30:05.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C15.dat
[14:30:05.146] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//defaultMaskFile.dat
[14:30:05.165] INFO: enter test to run
[14:30:25.469] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:30:25.469] INFO: running: highrate
[14:30:25.473] INFO: ----------------------------------------------------------------------
[14:30:25.473] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:30:25.473] INFO: ----------------------------------------------------------------------
[14:30:25.473] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:30:25.473] INFO: edge/corner pixel THR is adjusted
[14:30:25.473] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:30:26.430] INFO: Collecting data for 1 seconds...
[14:30:27.434] INFO: Done with hot pixel readout
[14:30:30.966] INFO: PixTest:: pg_setup set to default.
[14:30:30.966] INFO: 0 hot pixels found in step 0
[14:30:30.972] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:30:31.065] INFO: PixTest::trimHotPixels() done
[14:30:31.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C0.dat
[14:30:31.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C1.dat
[14:30:31.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C2.dat
[14:30:31.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C3.dat
[14:30:31.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C4.dat
[14:30:31.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C5.dat
[14:30:31.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C6.dat
[14:30:31.105] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C7.dat
[14:30:31.110] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C8.dat
[14:30:31.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C9.dat
[14:30:31.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C10.dat
[14:30:31.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C11.dat
[14:30:31.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C12.dat
[14:30:31.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C13.dat
[14:30:31.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C14.dat
[14:30:31.147] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//trimParameters35_C15.dat
[14:30:31.152] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-34_FPIXTest-17C-FNAL-160822-1256-150V_2016-08-22_12h57m_1471888628/000_FPIXTest_p17//defaultMaskFile.dat
[14:30:31.162] INFO: enter test to run
[14:31:08.244] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:31:08.244] INFO: running: xray
[14:31:08.246] INFO: ----------------------------------------------------------------------
[14:31:08.246] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:31:08.246] INFO: ----------------------------------------------------------------------
[14:31:09.222] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:31:21.192] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:31:48.998] INFO: Resuming triggers.
[14:32:00.969] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:32:25.705] INFO: Resuming triggers.
[14:32:37.673] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:33:06.097] INFO: Resuming triggers.
[14:33:18.069] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:33:45.618] INFO: Resuming triggers.
[14:33:57.593] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:34:24.850] INFO: Resuming triggers.
[14:34:36.823] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:35:06.317] INFO: Resuming triggers.
[14:35:18.288] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:35:47.885] INFO: Resuming triggers.
[14:35:59.859] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:36:27.322] INFO: Resuming triggers.
[14:36:31.913] INFO: data taking finished, elapsed time: 100 seconds.
[14:36:43.625] INFO: PixTest:: pg_setup set to default.
[14:36:43.629] INFO: PixTestXray::doPhRun() done
[14:36:43.888] INFO: enter test to run
[14:37:04.650] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:37:04.650] INFO: running: xray
[14:37:04.651] INFO: ----------------------------------------------------------------------
[14:37:04.651] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:37:04.652] INFO: ----------------------------------------------------------------------
[14:37:05.615] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:37:12.768] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:37:43.776] INFO: Resuming triggers.
[14:37:50.930] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:38:21.301] INFO: Resuming triggers.
[14:38:28.450] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:38:58.563] INFO: Resuming triggers.
[14:39:05.720] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:39:35.730] INFO: Resuming triggers.
[14:39:42.888] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:40:13.174] INFO: Resuming triggers.
[14:40:20.327] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[14:40:47.984] INFO: Resuming triggers.
[14:40:55.140] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:41:25.652] INFO: Resuming triggers.
[14:41:32.810] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:42:02.975] INFO: Resuming triggers.
[14:42:10.135] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[14:42:40.537] INFO: Resuming triggers.
[14:42:47.694] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:43:17.834] INFO: Resuming triggers.
[14:43:24.990] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:43:55.141] INFO: Resuming triggers.
[14:44:02.296] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:44:32.480] INFO: Resuming triggers.
[14:44:39.639] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:45:06.313] INFO: Resuming triggers.
[14:45:13.465] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:45:42.499] INFO: Resuming triggers.
[14:45:42.666] INFO: data taking finished, elapsed time: 100 seconds.
[14:45:43.762] INFO: PixTest:: pg_setup set to default.
[14:45:43.765] INFO: PixTestXray::doPhRun() done
[14:45:43.922] INFO: enter test to run
[14:46:10.199] INFO: test: HighRate no parameter change
[14:46:10.199] INFO: running: highrate
[14:46:10.583] INFO: ----------------------------------------------------------------------
[14:46:10.583] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:46:10.583] INFO: ----------------------------------------------------------------------
[14:46:10.807] INFO: Expecting 768 events.
[14:46:11.942] INFO: 768 events read in total (419ms).
[14:46:11.942] INFO: Test took 1280ms.
[14:46:12.745] INFO: Expecting 41600 events.
[14:46:15.522] INFO: 41600 events read in total (2251ms).
[14:46:15.524] INFO: Test took 3560ms.
[14:46:15.556] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:16.288] INFO: Expecting 41600 events.
[14:46:19.065] INFO: 41600 events read in total (2251ms).
[14:46:19.066] INFO: Test took 3494ms.
[14:46:19.100] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:19.828] INFO: Expecting 41600 events.
[14:46:22.636] INFO: 41600 events read in total (2281ms).
[14:46:22.637] INFO: Test took 3521ms.
[14:46:22.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:23.398] INFO: Expecting 41600 events.
[14:46:26.204] INFO: 41600 events read in total (2279ms).
[14:46:26.205] INFO: Test took 3517ms.
[14:46:26.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:26.967] INFO: Expecting 41600 events.
[14:46:29.783] INFO: 41600 events read in total (2290ms).
[14:46:29.784] INFO: Test took 3528ms.
[14:46:29.817] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:30.546] INFO: Expecting 41600 events.
[14:46:33.350] INFO: 41600 events read in total (2277ms).
[14:46:33.352] INFO: Test took 3518ms.
[14:46:33.384] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:34.113] INFO: Expecting 41600 events.
[14:46:36.925] INFO: 41600 events read in total (2285ms).
[14:46:36.926] INFO: Test took 3523ms.
[14:46:36.959] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:37.687] INFO: Expecting 41600 events.
[14:46:40.925] INFO: 41600 events read in total (2713ms).
[14:46:40.926] INFO: Test took 3949ms.
[14:46:40.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:41.679] INFO: Expecting 41600 events.
[14:46:44.755] INFO: 41600 events read in total (2549ms).
[14:46:44.756] INFO: Test took 3782ms.
[14:46:44.790] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:45.503] INFO: Expecting 41600 events.
[14:46:48.420] INFO: 41600 events read in total (2390ms).
[14:46:48.420] INFO: Test took 3612ms.
[14:46:48.452] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:49.181] INFO: Expecting 41600 events.
[14:46:52.279] INFO: 41600 events read in total (2571ms).
[14:46:52.280] INFO: Test took 3810ms.
[14:46:52.311] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:53.033] INFO: Expecting 41600 events.
[14:46:55.864] INFO: 41600 events read in total (2304ms).
[14:46:55.866] INFO: Test took 3539ms.
[14:46:55.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:56.627] INFO: Expecting 41600 events.
[14:46:59.462] INFO: 41600 events read in total (2308ms).
[14:46:59.463] INFO: Test took 3546ms.
[14:46:59.496] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:00.224] INFO: Expecting 41600 events.
[14:47:03.094] INFO: 41600 events read in total (2343ms).
[14:47:03.094] INFO: Test took 3581ms.
[14:47:03.127] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:03.857] INFO: Expecting 41600 events.
[14:47:06.679] INFO: 41600 events read in total (2295ms).
[14:47:06.680] INFO: Test took 3536ms.
[14:47:06.713] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:07.442] INFO: Expecting 41600 events.
[14:47:10.298] INFO: 41600 events read in total (2330ms).
[14:47:10.299] INFO: Test took 3569ms.
[14:47:10.332] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:11.060] INFO: Expecting 41600 events.
[14:47:14.257] INFO: 41600 events read in total (2670ms).
[14:47:14.258] INFO: Test took 3909ms.
[14:47:14.291] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:15.020] INFO: Expecting 41600 events.
[14:47:18.263] INFO: 41600 events read in total (2716ms).
[14:47:18.264] INFO: Test took 3955ms.
[14:47:18.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:19.026] INFO: Expecting 41600 events.
[14:47:22.212] INFO: 41600 events read in total (2659ms).
[14:47:22.213] INFO: Test took 3902ms.
[14:47:22.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:22.974] INFO: Expecting 41600 events.
[14:47:26.058] INFO: 41600 events read in total (2557ms).
[14:47:26.059] INFO: Test took 3796ms.
[14:47:26.089] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:26.456] INFO: enter test to run
[14:47:34.126] INFO: test: HighRate no parameter change
[14:47:34.126] INFO: running: highrate
[14:47:34.127] INFO: ----------------------------------------------------------------------
[14:47:34.127] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:47:34.127] INFO: ----------------------------------------------------------------------
[14:47:34.744] INFO: Expecting 208000 events.
[14:47:45.979] INFO: 208000 events read in total (10708ms).
[14:47:45.983] INFO: Test took 11850ms.
[14:47:46.122] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:46.372] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[14:47:46.372] INFO: number of red-efficiency pixels: 83 49 75 100 99 128 136 95 71 117 124 83 91 62 25 28
[14:47:46.372] INFO: number of X-ray hits detected: 62803 40372 62426 91771 97947 100201 98890 71205 66888 89152 86543 73941 78651 47872 19459 22576
[14:47:46.372] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:47:46.372] INFO: number of Vcal hits detected: 207917 207950 207923 207897 207896 207870 207860 207904 207929 207880 207873 207916 207909 207936 207975 207923
[14:47:46.372] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:47:46.372] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:47:46.372] INFO: X-ray hit rate [MHz/cm2]: 18.4 11.8 18.3 26.9 28.7 29.4 29.0 20.9 19.6 26.1 25.4 21.7 23.1 14.0 5.7 6.6
[14:47:46.372] INFO: PixTestHighRate::doXPixelAlive() done
[14:47:46.418] INFO: PixTest:: pg_setup set to default.
[14:47:46.433] INFO: enter test to run
[14:48:18.734] INFO: test: HighRate no parameter change
[14:48:18.734] INFO: running: highrate
[14:48:18.735] INFO: ----------------------------------------------------------------------
[14:48:18.735] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:48:18.735] INFO: ----------------------------------------------------------------------
[14:48:19.356] INFO: Expecting 208000 events.
[14:48:32.045] INFO: 208000 events read in total (12162ms).
[14:48:32.051] INFO: Test took 13307ms.
[14:48:32.325] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:32.618] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[14:48:32.618] INFO: number of red-efficiency pixels: 181 105 286 303 339 388 408 228 199 307 353 288 213 170 49 52
[14:48:32.618] INFO: number of X-ray hits detected: 130451 84536 129737 191936 204641 208863 206548 148364 140711 184751 179498 152084 163179 99837 40689 47454
[14:48:32.618] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:48:32.618] INFO: number of Vcal hits detected: 207806 207889 207685 207679 207636 207584 207560 207756 207789 207677 207631 207703 207780 207816 207950 207899
[14:48:32.618] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[14:48:32.618] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:48:32.618] INFO: X-ray hit rate [MHz/cm2]: 38.2 24.8 38.0 56.3 60.0 61.2 60.5 43.5 41.2 54.2 52.6 44.6 47.8 29.3 11.9 13.9
[14:48:32.618] INFO: PixTestHighRate::doXPixelAlive() done
[14:48:32.665] INFO: PixTest:: pg_setup set to default.
[14:48:32.678] INFO: enter test to run
[14:48:49.950] INFO: test: HighRate no parameter change
[14:48:49.950] INFO: running: highrate
[14:48:49.951] INFO: ----------------------------------------------------------------------
[14:48:49.951] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:48:49.951] INFO: ----------------------------------------------------------------------
[14:48:50.571] INFO: Expecting 208000 events.
[14:49:05.312] INFO: 208000 events read in total (14214ms).
[14:49:05.319] INFO: Test took 15359ms.
[14:49:05.708] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:06.043] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[14:49:06.043] INFO: number of red-efficiency pixels: 368 252 618 639 812 855 986 470 411 702 853 604 535 394 84 81
[14:49:06.043] INFO: number of X-ray hits detected: 195251 127017 194412 286492 305115 311369 309167 222215 211151 277901 268493 228313 244496 149431 61517 71444
[14:49:06.043] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:49:06.043] INFO: number of Vcal hits detected: 207576 207734 207196 207268 207047 206995 206797 207470 207543 207198 207037 207316 207414 207539 207913 207869
[14:49:06.043] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.7 99.6 99.6 99.5 99.8 99.8 99.7 99.6 99.7 99.7 99.8 100.0 100.0
[14:49:06.043] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.6 99.5 99.5 99.4 99.7 99.8 99.6 99.5 99.7 99.7 99.8 100.0 99.9
[14:49:06.043] INFO: X-ray hit rate [MHz/cm2]: 57.2 37.2 57.0 84.0 89.4 91.3 90.6 65.1 61.9 81.5 78.7 66.9 71.7 43.8 18.0 20.9
[14:49:06.043] INFO: PixTestHighRate::doXPixelAlive() done
[14:49:06.089] INFO: PixTest:: pg_setup set to default.
[14:49:06.101] INFO: enter test to run
[14:49:10.261] INFO: test: exit no parameter change
[14:49:10.865] QUIET: Connection to board 33 closed.
[14:49:10.962] INFO: pXar: this is the end, my friend