[12:42:28.403] INFO: *** Welcome to pxar ***
[12:42:28.403] INFO: *** Today: 2016/07/07
[12:42:28.423] INFO: *** Version: v1.9.0-814-g7497
[12:42:28.423] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//dacParameters35_C15.dat
[12:42:28.423] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:42:28.423] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//defaultMaskFile.dat
[12:42:28.423] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C15.dat
[12:42:28.495] INFO: clk: 4
[12:42:28.495] INFO: ctr: 4
[12:42:28.495] INFO: sda: 19
[12:42:28.495] INFO: tin: 9
[12:42:28.495] INFO: level: 15
[12:42:28.495] INFO: triggerdelay: 0
[12:42:28.495] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:42:28.495] INFO: Log level: INFO
[12:42:28.510] QUIET: Connection to board DTB_WREKRL opened.
[12:42:28.513] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[12:42:28.516] INFO: RPC call hashes of host and DTB match: 398089610
[12:42:30.059] INFO: DUT info:
[12:42:30.059] INFO: The DUT currently contains the following objects:
[12:42:30.059] INFO: 2 TBM Cores tbm08c (2 ON)
[12:42:30.059] INFO: TBM Core alpha (0): 7 registers set
[12:42:30.059] INFO: TBM Core beta (1): 7 registers set
[12:42:30.059] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:42:30.060] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.060] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:42:30.463] INFO: enter 'restricted' command line mode
[12:42:30.463] INFO: enter test to run
[12:42:40.584] INFO: test: PixelAlive no parameter change
[12:42:40.584] INFO: running: pixelalive
[12:42:40.593] INFO: ----------------------------------------------------------------------
[12:42:40.593] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:42:40.594] INFO: ----------------------------------------------------------------------
[12:42:40.917] INFO: Expecting 41600 events.
[12:42:45.297] INFO: 41600 events read in total (3661ms).
[12:42:45.466] INFO: Test took 4870ms.
[12:42:45.474] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:45.751] INFO: PixTestAlive::aliveTest() done
[12:42:45.752] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:42:45.787] INFO: enter test to run
[12:43:09.120] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:43:09.120] INFO: running: highrate
[12:43:09.121] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:43:09.282] INFO: ----------------------------------------------------------------------
[12:43:09.282] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:43:09.282] INFO: ----------------------------------------------------------------------
[12:43:09.282] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:43:09.282] INFO: edge/corner pixel THR is adjusted
[12:43:09.282] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:43:10.240] INFO: Collecting data for 5 seconds...
[12:43:15.261] INFO: Done with hot pixel readout
[12:43:27.145] INFO: PixTest:: pg_setup set to default.
[12:43:27.146] INFO: 7 hot pixels found in step 0
[12:43:28.141] INFO: Collecting data for 5 seconds...
[12:43:33.160] INFO: Done with hot pixel readout
[12:43:45.251] INFO: PixTest:: pg_setup set to default.
[12:43:45.252] INFO: 6 hot pixels found in step 1
[12:43:46.253] INFO: Collecting data for 5 seconds...
[12:43:51.272] INFO: Done with hot pixel readout
[12:44:03.589] INFO: PixTest:: pg_setup set to default.
[12:44:03.590] INFO: 6 hot pixels found in step 2
[12:44:04.588] INFO: Collecting data for 5 seconds...
[12:44:09.607] INFO: Done with hot pixel readout
[12:44:21.890] INFO: PixTest:: pg_setup set to default.
[12:44:21.891] INFO: 3 hot pixels found in step 3
[12:44:22.889] INFO: Collecting data for 5 seconds...
[12:44:27.910] INFO: Done with hot pixel readout
[12:44:40.291] INFO: PixTest:: pg_setup set to default.
[12:44:40.291] INFO: 7 hot pixels found in step 4
[12:44:41.290] INFO: Collecting data for 5 seconds...
[12:44:46.309] INFO: Done with hot pixel readout
[12:44:58.674] INFO: PixTest:: pg_setup set to default.
[12:44:58.675] INFO: 1 hot pixels found in step 5
[12:44:59.674] INFO: Collecting data for 5 seconds...
[12:45:04.694] INFO: Done with hot pixel readout
[12:45:16.758] INFO: PixTest:: pg_setup set to default.
[12:45:16.759] INFO: 4 hot pixels found in step 6
[12:45:17.758] INFO: Collecting data for 5 seconds...
[12:45:22.775] INFO: Done with hot pixel readout
[12:45:34.798] INFO: PixTest:: pg_setup set to default.
[12:45:34.798] INFO: 2 hot pixels found in step 7
[12:45:35.797] INFO: Collecting data for 5 seconds...
[12:45:40.814] INFO: Done with hot pixel readout
[12:45:52.919] INFO: PixTest:: pg_setup set to default.
[12:45:52.920] INFO: 0 hot pixels found in step 8
[12:45:52.961] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:45:52.965] INFO: PixTest::trimHotPixels() done
[12:45:52.965] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C0.dat
[12:45:52.971] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C1.dat
[12:45:52.977] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C2.dat
[12:45:52.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C3.dat
[12:45:52.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C4.dat
[12:45:52.994] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C5.dat
[12:45:52.999] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C6.dat
[12:45:53.005] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C7.dat
[12:45:53.010] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C8.dat
[12:45:53.015] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C9.dat
[12:45:53.021] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C10.dat
[12:45:53.026] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C11.dat
[12:45:53.031] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C12.dat
[12:45:53.036] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C13.dat
[12:45:53.041] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C14.dat
[12:45:53.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C15.dat
[12:45:53.052] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//defaultMaskFile.dat
[12:45:53.062] INFO: enter test to run
[12:47:35.734] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:47:35.734] INFO: running: highrate
[12:47:35.739] INFO: ----------------------------------------------------------------------
[12:47:35.739] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:47:35.739] INFO: ----------------------------------------------------------------------
[12:47:35.739] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:47:35.739] INFO: edge/corner pixel THR is adjusted
[12:47:35.739] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:47:36.697] INFO: Collecting data for 1 seconds...
[12:47:37.701] INFO: Done with hot pixel readout
[12:47:41.888] INFO: PixTest:: pg_setup set to default.
[12:47:41.889] INFO: 0 hot pixels found in step 0
[12:47:41.894] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:47:41.979] INFO: PixTest::trimHotPixels() done
[12:47:41.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C0.dat
[12:47:41.985] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C1.dat
[12:47:41.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C2.dat
[12:47:41.996] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C3.dat
[12:47:42.002] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C4.dat
[12:47:42.009] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C5.dat
[12:47:42.015] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C6.dat
[12:47:42.020] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C7.dat
[12:47:42.025] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C8.dat
[12:47:42.030] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C9.dat
[12:47:42.036] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C10.dat
[12:47:42.041] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C11.dat
[12:47:42.046] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C12.dat
[12:47:42.051] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C13.dat
[12:47:42.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C14.dat
[12:47:42.062] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C15.dat
[12:47:42.067] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-1-09_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//defaultMaskFile.dat
[12:47:42.079] INFO: enter test to run
[12:48:18.246] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:48:18.246] INFO: running: xray
[12:48:18.274] INFO: ----------------------------------------------------------------------
[12:48:18.274] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:48:18.274] INFO: ----------------------------------------------------------------------
[12:48:19.238] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:48:30.355] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:48:59.806] INFO: Resuming triggers.
[12:49:10.924] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:49:40.406] INFO: Resuming triggers.
[12:49:51.524] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:50:20.931] INFO: Resuming triggers.
[12:50:32.048] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[12:51:01.434] INFO: Resuming triggers.
[12:51:12.557] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[12:51:42.337] INFO: Resuming triggers.
[12:51:53.457] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[12:52:22.685] INFO: Resuming triggers.
[12:52:33.806] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[12:53:03.380] INFO: Resuming triggers.
[12:53:14.500] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:53:44.217] INFO: Resuming triggers.
[12:53:55.337] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[12:54:25.409] INFO: Resuming triggers.
[12:54:25.676] INFO: data taking finished, elapsed time: 100 seconds.
[12:54:26.930] INFO: PixTest:: pg_setup set to default.
[12:54:26.933] INFO: PixTestXray::doPhRun() done
[12:54:27.163] INFO: enter test to run
[12:55:06.075] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:55:06.075] INFO: running: xray
[12:55:06.076] INFO: ----------------------------------------------------------------------
[12:55:06.076] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:55:06.076] INFO: ----------------------------------------------------------------------
[12:55:07.058] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:55:13.413] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:55:44.176] INFO: Resuming triggers.
[12:55:50.537] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:56:21.618] INFO: Resuming triggers.
[12:56:27.973] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[12:56:59.574] INFO: Resuming triggers.
[12:57:05.929] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[12:57:37.611] INFO: Resuming triggers.
[12:57:43.965] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[12:58:15.101] INFO: Resuming triggers.
[12:58:21.455] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[12:58:51.680] INFO: Resuming triggers.
[12:58:58.036] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[12:59:28.288] INFO: Resuming triggers.
[12:59:34.647] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[13:00:04.901] INFO: Resuming triggers.
[13:00:11.261] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:00:41.460] INFO: Resuming triggers.
[13:00:47.820] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[13:01:17.967] INFO: Resuming triggers.
[13:01:24.329] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:01:54.399] INFO: Resuming triggers.
[13:02:00.760] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[13:02:31.021] INFO: Resuming triggers.
[13:02:37.379] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:03:07.644] INFO: Resuming triggers.
[13:03:14.006] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[13:03:44.065] INFO: Resuming triggers.
[13:03:50.426] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[13:04:20.640] INFO: Resuming triggers.
[13:04:25.617] INFO: data taking finished, elapsed time: 100 seconds.
[13:04:49.414] INFO: PixTest:: pg_setup set to default.
[13:04:49.417] INFO: PixTestXray::doPhRun() done
[13:04:49.564] INFO: enter test to run
[13:05:36.919] INFO: test: HighRate no parameter change
[13:05:36.919] INFO: running: highrate
[13:05:36.941] INFO: ----------------------------------------------------------------------
[13:05:36.941] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:05:36.941] INFO: ----------------------------------------------------------------------
[13:05:37.096] INFO: Expecting 768 events.
[13:05:38.261] INFO: 768 events read in total (449ms).
[13:05:38.262] INFO: Test took 1300ms.
[13:05:39.065] INFO: Expecting 41600 events.
[13:05:42.140] INFO: 41600 events read in total (2549ms).
[13:05:42.141] INFO: Test took 3858ms.
[13:05:42.177] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:42.897] INFO: Expecting 41600 events.
[13:05:46.177] INFO: 41600 events read in total (2754ms).
[13:05:46.178] INFO: Test took 3983ms.
[13:05:46.215] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:46.933] INFO: Expecting 41600 events.
[13:05:50.251] INFO: 41600 events read in total (2791ms).
[13:05:50.252] INFO: Test took 4018ms.
[13:05:50.290] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:51.008] INFO: Expecting 41600 events.
[13:05:54.311] INFO: 41600 events read in total (2776ms).
[13:05:54.312] INFO: Test took 4004ms.
[13:05:54.350] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:55.070] INFO: Expecting 41600 events.
[13:05:58.310] INFO: 41600 events read in total (2714ms).
[13:05:58.311] INFO: Test took 3942ms.
[13:05:58.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:59.063] INFO: Expecting 41600 events.
[13:06:02.261] INFO: 41600 events read in total (2671ms).
[13:06:02.262] INFO: Test took 3895ms.
[13:06:02.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:03.018] INFO: Expecting 41600 events.
[13:06:06.329] INFO: 41600 events read in total (2785ms).
[13:06:06.330] INFO: Test took 4011ms.
[13:06:06.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:07.085] INFO: Expecting 41600 events.
[13:06:10.369] INFO: 41600 events read in total (2757ms).
[13:06:10.369] INFO: Test took 3981ms.
[13:06:10.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:11.121] INFO: Expecting 41600 events.
[13:06:14.468] INFO: 41600 events read in total (2820ms).
[13:06:14.469] INFO: Test took 4043ms.
[13:06:14.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:15.215] INFO: Expecting 41600 events.
[13:06:18.542] INFO: 41600 events read in total (2800ms).
[13:06:18.543] INFO: Test took 4011ms.
[13:06:18.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:19.300] INFO: Expecting 41600 events.
[13:06:22.656] INFO: 41600 events read in total (2829ms).
[13:06:22.657] INFO: Test took 4057ms.
[13:06:22.695] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:23.408] INFO: Expecting 41600 events.
[13:06:26.716] INFO: 41600 events read in total (2782ms).
[13:06:26.717] INFO: Test took 4003ms.
[13:06:26.755] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:27.467] INFO: Expecting 41600 events.
[13:06:30.687] INFO: 41600 events read in total (2694ms).
[13:06:30.688] INFO: Test took 3914ms.
[13:06:30.726] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:31.443] INFO: Expecting 41600 events.
[13:06:34.860] INFO: 41600 events read in total (2890ms).
[13:06:34.861] INFO: Test took 4116ms.
[13:06:34.900] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:35.601] INFO: Expecting 41600 events.
[13:06:38.915] INFO: 41600 events read in total (2787ms).
[13:06:38.916] INFO: Test took 3996ms.
[13:06:38.955] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:39.664] INFO: Expecting 41600 events.
[13:06:42.977] INFO: 41600 events read in total (2786ms).
[13:06:42.978] INFO: Test took 4004ms.
[13:06:43.016] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:43.733] INFO: Expecting 41600 events.
[13:06:47.031] INFO: 41600 events read in total (2771ms).
[13:06:47.032] INFO: Test took 3997ms.
[13:06:47.070] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:47.785] INFO: Expecting 41600 events.
[13:06:51.150] INFO: 41600 events read in total (2838ms).
[13:06:51.151] INFO: Test took 4061ms.
[13:06:51.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:51.906] INFO: Expecting 41600 events.
[13:06:55.178] INFO: 41600 events read in total (2747ms).
[13:06:55.180] INFO: Test took 3973ms.
[13:06:55.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:55.933] INFO: Expecting 41600 events.
[13:06:59.026] INFO: 41600 events read in total (2566ms).
[13:06:59.027] INFO: Test took 3788ms.
[13:06:59.064] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:59.421] INFO: enter test to run
[13:07:04.142] INFO: test: HighRate no parameter change
[13:07:04.142] INFO: running: highrate
[13:07:04.143] INFO: ----------------------------------------------------------------------
[13:07:04.143] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:07:04.143] INFO: ----------------------------------------------------------------------
[13:07:04.763] INFO: Expecting 208000 events.
[13:07:16.862] INFO: 208000 events read in total (11572ms).
[13:07:16.865] INFO: Test took 12715ms.
[13:07:17.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:17.291] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:07:17.291] INFO: number of red-efficiency pixels: 86 48 76 99 139 142 133 120 98 144 117 120 143 70 24 30
[13:07:17.291] INFO: number of X-ray hits detected: 67253 47000 65089 110866 115833 124983 123450 93045 87701 117628 114943 99155 104031 62082 25423 27460
[13:07:17.291] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:07:17.291] INFO: number of Vcal hits detected: 207913 207952 207923 207897 207857 207854 207862 207878 207899 207855 207880 207878 207854 207928 207976 207970
[13:07:17.291] 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 99.9 100.0 100.0 100.0
[13:07:17.292] INFO: Vcal hit overall 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 99.9 100.0 100.0 100.0
[13:07:17.292] INFO: X-ray hit rate [MHz/cm2]: 19.7 13.8 19.1 32.5 34.0 36.6 36.2 27.3 25.7 34.5 33.7 29.1 30.5 18.2 7.5 8.0
[13:07:17.292] INFO: PixTestHighRate::doXPixelAlive() done
[13:07:17.338] INFO: PixTest:: pg_setup set to default.
[13:07:17.348] INFO: enter test to run
[13:07:58.462] INFO: test: HighRate no parameter change
[13:07:58.462] INFO: running: highrate
[13:07:58.464] INFO: ----------------------------------------------------------------------
[13:07:58.464] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:07:58.464] INFO: ----------------------------------------------------------------------
[13:07:59.087] INFO: Expecting 208000 events.
[13:08:13.537] INFO: 208000 events read in total (13923ms).
[13:08:13.543] INFO: Test took 15068ms.
[13:08:13.879] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:14.192] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:08:14.192] INFO: number of red-efficiency pixels: 250 103 230 399 417 524 453 348 312 397 420 401 488 231 52 66
[13:08:14.192] INFO: number of X-ray hits detected: 135993 94946 131694 224380 234624 252133 249193 188309 178179 236610 232142 200981 210707 126149 52895 55832
[13:08:14.192] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:08:14.192] INFO: number of Vcal hits detected: 207729 207892 207752 207574 207549 207393 207511 207618 207670 207574 207547 207563 207463 207751 207946 207933
[13:08:14.192] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:08:14.192] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.7 99.9 100.0 100.0
[13:08:14.192] INFO: X-ray hit rate [MHz/cm2]: 39.9 27.8 38.6 65.8 68.8 73.9 73.0 55.2 52.2 69.4 68.0 58.9 61.8 37.0 15.5 16.4
[13:08:14.192] INFO: PixTestHighRate::doXPixelAlive() done
[13:08:14.238] INFO: PixTest:: pg_setup set to default.
[13:08:14.251] INFO: enter test to run
[13:08:38.478] INFO: test: HighRate no parameter change
[13:08:38.478] INFO: running: highrate
[13:08:38.479] INFO: ----------------------------------------------------------------------
[13:08:38.479] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:08:38.479] INFO: ----------------------------------------------------------------------
[13:08:39.096] INFO: Expecting 208000 events.
[13:08:55.573] INFO: 208000 events read in total (15950ms).
[13:08:55.582] INFO: Test took 17094ms.
[13:08:56.095] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:56.463] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:08:56.463] INFO: number of red-efficiency pixels: 518 213 469 865 929 1296 1060 730 757 1018 949 936 1096 454 88 103
[13:08:56.464] INFO: number of X-ray hits detected: 204453 142857 198139 338535 353605 380069 375540 283728 267705 357509 349083 303124 318490 190065 79660 84590
[13:08:56.464] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:08:56.464] INFO: number of Vcal hits detected: 207373 207769 207412 206968 206849 206278 206622 207060 207078 206735 206831 206776 206667 207453 207908 207895
[13:08:56.464] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.8 99.6 99.5 99.3 99.4 99.6 99.6 99.5 99.5 99.5 99.4 99.8 100.0 100.0
[13:08:56.464] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.5 99.4 99.2 99.3 99.5 99.6 99.4 99.4 99.4 99.4 99.7 100.0 99.9
[13:08:56.464] INFO: X-ray hit rate [MHz/cm2]: 59.9 41.9 58.1 99.2 103.6 111.4 110.1 83.2 78.5 104.8 102.3 88.8 93.4 55.7 23.3 24.8
[13:08:56.464] INFO: PixTestHighRate::doXPixelAlive() done
[13:08:56.511] INFO: PixTest:: pg_setup set to default.
[13:08:56.530] INFO: enter test to run
[13:09:33.445] INFO: test: exit no parameter change
[13:09:33.762] QUIET: Connection to board 33 closed.
[13:09:33.784] INFO: pXar: this is the end, my friend