[13:37:38.295] INFO: *** Welcome to pxar ***
[13:37:38.295] INFO: *** Today: 2016/05/06
[13:37:38.313] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:37:38.313] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//dacParameters35_C15.dat
[13:37:38.365] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:37:38.365] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//defaultMaskFile.dat
[13:37:38.365] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C15.dat
[13:37:38.507] INFO: clk: 4
[13:37:38.507] INFO: ctr: 4
[13:37:38.507] INFO: sda: 19
[13:37:38.507] INFO: tin: 9
[13:37:38.507] INFO: level: 15
[13:37:38.507] INFO: triggerdelay: 0
[13:37:38.507] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:37:38.507] INFO: Log level: INFO
[13:37:38.526] QUIET: Connection to board DTB_WREKRL opened.
[13:37:38.529] 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:
------------------------------------------------------
[13:37:38.532] INFO: RPC call hashes of host and DTB match: 398089610
[13:37:40.057] INFO: DUT info:
[13:37:40.057] INFO: The DUT currently contains the following objects:
[13:37:40.057] INFO: 2 TBM Cores tbm08c (2 ON)
[13:37:40.057] INFO: TBM Core alpha (0): 7 registers set
[13:37:40.057] INFO: TBM Core beta (1): 7 registers set
[13:37:40.057] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:37:40.057] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.057] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.057] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.057] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.057] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.058] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:40.462] INFO: enter 'restricted' command line mode
[13:37:40.462] INFO: enter test to run
[13:37:48.464] INFO: test: PixelAlive no parameter change
[13:37:48.464] INFO: running: pixelalive
[13:37:48.474] INFO: ----------------------------------------------------------------------
[13:37:48.474] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:37:48.474] INFO: ----------------------------------------------------------------------
[13:37:48.792] INFO: Expecting 41600 events.
[13:37:53.124] INFO: 41600 events read in total (3614ms).
[13:37:53.289] INFO: Test took 4812ms.
[13:37:53.298] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:53.581] INFO: PixTestAlive::aliveTest() done
[13:37:53.581] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 1
[13:37:53.614] INFO: enter test to run
[13:39:00.944] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:39:00.944] INFO: running: highrate
[13:39:00.944] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:39:01.203] INFO: ----------------------------------------------------------------------
[13:39:01.203] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:39:01.203] INFO: ----------------------------------------------------------------------
[13:39:01.203] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:39:01.203] INFO: edge/corner pixel THR is adjusted
[13:39:01.203] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:39:02.162] INFO: Collecting data for 5 seconds...
[13:39:07.179] INFO: Done with hot pixel readout
[13:39:18.736] INFO: PixTest:: pg_setup set to default.
[13:39:18.737] INFO: 2 hot pixels found in step 0
[13:39:19.748] INFO: Collecting data for 5 seconds...
[13:39:24.765] INFO: Done with hot pixel readout
[13:39:36.278] INFO: PixTest:: pg_setup set to default.
[13:39:36.279] INFO: 3 hot pixels found in step 1
[13:39:37.271] INFO: Collecting data for 5 seconds...
[13:39:42.289] INFO: Done with hot pixel readout
[13:39:53.833] INFO: PixTest:: pg_setup set to default.
[13:39:53.834] INFO: 1 hot pixels found in step 2
[13:39:54.825] INFO: Collecting data for 5 seconds...
[13:39:59.842] INFO: Done with hot pixel readout
[13:40:11.415] INFO: PixTest:: pg_setup set to default.
[13:40:11.416] INFO: 1 hot pixels found in step 3
[13:40:12.407] INFO: Collecting data for 5 seconds...
[13:40:17.423] INFO: Done with hot pixel readout
[13:40:28.972] INFO: PixTest:: pg_setup set to default.
[13:40:28.973] INFO: 1 hot pixels found in step 4
[13:40:29.965] INFO: Collecting data for 5 seconds...
[13:40:34.982] INFO: Done with hot pixel readout
[13:40:46.792] INFO: PixTest:: pg_setup set to default.
[13:40:46.793] INFO: 1 hot pixels found in step 5
[13:40:47.784] INFO: Collecting data for 5 seconds...
[13:40:52.802] INFO: Done with hot pixel readout
[13:41:04.252] INFO: PixTest:: pg_setup set to default.
[13:41:04.253] INFO: 0 hot pixels found in step 6
[13:41:04.289] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:41:04.293] INFO: PixTest::trimHotPixels() done
[13:41:04.304] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C0.dat
[13:41:04.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C1.dat
[13:41:04.324] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C2.dat
[13:41:04.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C3.dat
[13:41:04.336] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C4.dat
[13:41:04.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C5.dat
[13:41:04.347] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C6.dat
[13:41:04.352] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C7.dat
[13:41:04.358] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C8.dat
[13:41:04.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C9.dat
[13:41:04.368] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C10.dat
[13:41:04.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C11.dat
[13:41:04.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C12.dat
[13:41:04.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C13.dat
[13:41:04.390] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C14.dat
[13:41:04.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C15.dat
[13:41:04.401] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//defaultMaskFile.dat
[13:41:04.413] INFO: enter test to run
[13:43:44.238] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:43:44.238] INFO: running: highrate
[13:43:44.242] INFO: ----------------------------------------------------------------------
[13:43:44.242] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:43:44.242] INFO: ----------------------------------------------------------------------
[13:43:44.242] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:43:44.242] INFO: edge/corner pixel THR is adjusted
[13:43:44.242] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:43:45.200] INFO: Collecting data for 1 seconds...
[13:43:46.204] INFO: Done with hot pixel readout
[13:43:50.146] INFO: PixTest:: pg_setup set to default.
[13:43:50.147] INFO: 0 hot pixels found in step 0
[13:43:50.153] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:43:50.244] INFO: PixTest::trimHotPixels() done
[13:43:50.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C0.dat
[13:43:50.257] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C1.dat
[13:43:50.263] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C2.dat
[13:43:50.268] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C3.dat
[13:43:50.274] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C4.dat
[13:43:50.279] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C5.dat
[13:43:50.284] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C6.dat
[13:43:50.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C7.dat
[13:43:50.295] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C8.dat
[13:43:50.300] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C9.dat
[13:43:50.306] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C10.dat
[13:43:50.311] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C11.dat
[13:43:50.316] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C12.dat
[13:43:50.322] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C13.dat
[13:43:50.327] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C14.dat
[13:43:50.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//trimParameters35_C15.dat
[13:43:50.337] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-49_FPIXTest-17C-FNAL-160429-1159_2016-04-29_11h59m_1461949190/000_FPIXTest_p17//defaultMaskFile.dat
[13:43:50.348] INFO: enter test to run
[13:44:19.342] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:44:19.342] INFO: running: xray
[13:44:19.343] INFO: ----------------------------------------------------------------------
[13:44:19.343] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:44:19.343] INFO: ----------------------------------------------------------------------
[13:44:20.306] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:44:31.989] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:45:01.166] INFO: Resuming triggers.
[13:45:12.845] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:45:42.835] INFO: Resuming triggers.
[13:45:54.519] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:46:24.238] INFO: Resuming triggers.
[13:46:35.920] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:47:05.754] INFO: Resuming triggers.
[13:47:17.438] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:47:46.781] INFO: Resuming triggers.
[13:47:58.465] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:48:27.787] INFO: Resuming triggers.
[13:48:39.469] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:49:08.825] INFO: Resuming triggers.
[13:49:20.504] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:49:49.816] INFO: Resuming triggers.
[13:49:56.707] INFO: data taking finished, elapsed time: 100 seconds.
[13:50:14.177] INFO: PixTest:: pg_setup set to default.
[13:50:14.181] INFO: PixTestXray::doPhRun() done
[13:50:14.316] INFO: enter test to run
[13:50:41.395] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:50:41.395] INFO: running: xray
[13:50:41.396] INFO: ----------------------------------------------------------------------
[13:50:41.396] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:50:41.396] INFO: ----------------------------------------------------------------------
[13:50:42.360] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:50:49.130] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:51:19.303] INFO: Resuming triggers.
[13:51:26.078] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:51:56.661] INFO: Resuming triggers.
[13:52:03.431] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:52:33.979] INFO: Resuming triggers.
[13:52:40.755] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[13:53:10.796] INFO: Resuming triggers.
[13:53:17.567] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:53:47.639] INFO: Resuming triggers.
[13:53:54.415] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[13:54:24.315] INFO: Resuming triggers.
[13:54:31.086] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:55:01.195] INFO: Resuming triggers.
[13:55:07.971] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[13:55:38.041] INFO: Resuming triggers.
[13:55:44.814] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[13:56:15.270] INFO: Resuming triggers.
[13:56:22.048] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:56:53.411] INFO: Resuming triggers.
[13:57:00.184] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:57:31.412] INFO: Resuming triggers.
[13:57:38.189] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:58:08.435] INFO: Resuming triggers.
[13:58:15.214] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[13:58:45.323] INFO: Resuming triggers.
[13:58:52.101] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[13:59:22.157] INFO: Resuming triggers.
[13:59:27.666] INFO: data taking finished, elapsed time: 100 seconds.
[13:59:52.349] INFO: PixTest:: pg_setup set to default.
[13:59:52.352] INFO: PixTestXray::doPhRun() done
[13:59:52.501] INFO: enter test to run
[14:00:30.950] INFO: test: HighRate no parameter change
[14:00:30.950] INFO: running: highrate
[14:00:30.952] INFO: ----------------------------------------------------------------------
[14:00:30.952] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:00:30.952] INFO: ----------------------------------------------------------------------
[14:00:31.092] INFO: Expecting 768 events.
[14:00:32.225] INFO: 768 events read in total (418ms).
[14:00:32.225] INFO: Test took 1267ms.
[14:00:33.028] INFO: Expecting 41600 events.
[14:00:36.621] INFO: 41600 events read in total (3066ms).
[14:00:36.623] INFO: Test took 4388ms.
[14:00:36.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:37.358] INFO: Expecting 41600 events.
[14:00:41.093] INFO: 41600 events read in total (3208ms).
[14:00:41.095] INFO: Test took 4348ms.
[14:00:41.185] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:41.834] INFO: Expecting 41600 events.
[14:00:45.606] INFO: 41600 events read in total (3246ms).
[14:00:45.609] INFO: Test took 4387ms.
[14:00:45.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:46.349] INFO: Expecting 41600 events.
[14:00:50.143] INFO: 41600 events read in total (3267ms).
[14:00:50.147] INFO: Test took 4410ms.
[14:00:50.243] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:50.892] INFO: Expecting 41600 events.
[14:00:54.679] INFO: 41600 events read in total (3260ms).
[14:00:54.681] INFO: Test took 4401ms.
[14:00:54.771] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:55.420] INFO: Expecting 41600 events.
[14:00:59.227] INFO: 41600 events read in total (3280ms).
[14:00:59.229] INFO: Test took 4422ms.
[14:00:59.319] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:59.968] INFO: Expecting 41600 events.
[14:01:03.781] INFO: 41600 events read in total (3286ms).
[14:01:03.783] INFO: Test took 4428ms.
[14:01:03.874] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:04.523] INFO: Expecting 41600 events.
[14:01:08.339] INFO: 41600 events read in total (3289ms).
[14:01:08.341] INFO: Test took 4429ms.
[14:01:08.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:09.079] INFO: Expecting 41600 events.
[14:01:12.909] INFO: 41600 events read in total (3303ms).
[14:01:12.911] INFO: Test took 4445ms.
[14:01:12.002] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:13.652] INFO: Expecting 41600 events.
[14:01:17.482] INFO: 41600 events read in total (3303ms).
[14:01:17.484] INFO: Test took 4444ms.
[14:01:17.575] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:18.225] INFO: Expecting 41600 events.
[14:01:22.050] INFO: 41600 events read in total (3299ms).
[14:01:22.053] INFO: Test took 4440ms.
[14:01:22.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:22.792] INFO: Expecting 41600 events.
[14:01:26.611] INFO: 41600 events read in total (3292ms).
[14:01:26.613] INFO: Test took 4432ms.
[14:01:26.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:27.354] INFO: Expecting 41600 events.
[14:01:31.184] INFO: 41600 events read in total (3303ms).
[14:01:31.186] INFO: Test took 4444ms.
[14:01:31.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:31.926] INFO: Expecting 41600 events.
[14:01:35.738] INFO: 41600 events read in total (3285ms).
[14:01:35.740] INFO: Test took 4425ms.
[14:01:35.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:36.481] INFO: Expecting 41600 events.
[14:01:40.303] INFO: 41600 events read in total (3295ms).
[14:01:40.306] INFO: Test took 4438ms.
[14:01:40.393] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:41.043] INFO: Expecting 41600 events.
[14:01:44.864] INFO: 41600 events read in total (3294ms).
[14:01:44.866] INFO: Test took 4436ms.
[14:01:44.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:45.608] INFO: Expecting 41600 events.
[14:01:49.424] INFO: 41600 events read in total (3289ms).
[14:01:49.426] INFO: Test took 4432ms.
[14:01:49.517] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:50.167] INFO: Expecting 41600 events.
[14:01:53.983] INFO: 41600 events read in total (3290ms).
[14:01:53.985] INFO: Test took 4432ms.
[14:01:54.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:54.726] INFO: Expecting 41600 events.
[14:01:58.567] INFO: 41600 events read in total (3314ms).
[14:01:58.569] INFO: Test took 4454ms.
[14:01:58.658] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:59.307] INFO: Expecting 41600 events.
[14:02:03.016] INFO: 41600 events read in total (3182ms).
[14:02:03.018] INFO: Test took 4322ms.
[14:02:03.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:03.391] INFO: enter test to run
[14:02:26.686] INFO: test: HighRate no parameter change
[14:02:26.686] INFO: running: highrate
[14:02:26.687] INFO: ----------------------------------------------------------------------
[14:02:26.687] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:02:26.687] INFO: ----------------------------------------------------------------------
[14:02:27.299] INFO: Expecting 208000 events.
[14:02:39.414] INFO: 208000 events read in total (11588ms).
[14:02:39.417] INFO: Test took 12722ms.
[14:02:39.588] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:39.848] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 1
[14:02:39.848] INFO: number of red-efficiency pixels: 77 48 93 149 165 174 161 100 116 141 116 112 105 84 21 36
[14:02:39.848] INFO: number of X-ray hits detected: 74926 52443 79678 125751 140394 136344 133964 96579 99715 111171 106092 93373 94610 58870 23405 29938
[14:02:39.848] 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:02:39.848] INFO: number of Vcal hits detected: 207922 207951 207903 207846 207820 207818 207834 207893 207881 207854 207879 207886 207893 207916 207930 207915
[14:02:39.848] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[14:02:39.848] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:02:39.848] INFO: X-ray hit rate [MHz/cm2]: 22.0 15.4 23.4 36.9 41.2 40.0 39.3 28.3 29.2 32.6 31.1 27.4 27.7 17.3 6.9 8.8
[14:02:39.848] INFO: PixTestHighRate::doXPixelAlive() done
[14:02:39.893] INFO: PixTest:: pg_setup set to default.
[14:02:39.905] INFO: enter test to run
[14:03:02.093] INFO: test: HighRate no parameter change
[14:03:02.093] INFO: running: highrate
[14:03:02.094] INFO: ----------------------------------------------------------------------
[14:03:02.094] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:03:02.094] INFO: ----------------------------------------------------------------------
[14:03:02.708] INFO: Expecting 208000 events.
[14:03:16.600] INFO: 208000 events read in total (13365ms).
[14:03:16.606] INFO: Test took 14504ms.
[14:03:16.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:17.231] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 1
[14:03:17.231] INFO: number of red-efficiency pixels: 195 169 233 370 497 501 421 258 238 327 307 232 267 154 43 56
[14:03:17.231] INFO: number of X-ray hits detected: 138530 97446 146885 231366 257880 251356 246521 178258 184393 204778 194041 171892 175521 108525 43426 56263
[14:03:17.231] 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:03:17.231] INFO: number of Vcal hits detected: 207790 207823 207749 207598 207461 207460 207545 207719 207752 207656 207677 207761 207723 207838 207907 207893
[14:03:17.231] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[14:03:17.231] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 99.9
[14:03:17.231] INFO: X-ray hit rate [MHz/cm2]: 40.6 28.6 43.1 67.8 75.6 73.7 72.3 52.2 54.0 60.0 56.9 50.4 51.4 31.8 12.7 16.5
[14:03:17.231] INFO: PixTestHighRate::doXPixelAlive() done
[14:03:17.276] INFO: PixTest:: pg_setup set to default.
[14:03:17.291] INFO: enter test to run
[14:03:31.941] INFO: test: HighRate no parameter change
[14:03:31.941] INFO: running: highrate
[14:03:31.942] INFO: ----------------------------------------------------------------------
[14:03:31.942] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:03:31.942] INFO: ----------------------------------------------------------------------
[14:03:32.558] INFO: Expecting 208000 events.
[14:03:47.978] INFO: 208000 events read in total (14893ms).
[14:03:47.985] INFO: Test took 16035ms.
[14:03:48.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:48.783] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 1
[14:03:48.783] INFO: number of red-efficiency pixels: 364 215 466 818 995 945 836 492 536 654 580 467 466 282 76 96
[14:03:48.783] INFO: number of X-ray hits detected: 198797 138905 210393 330421 370874 358743 349997 256424 264759 293568 279356 246628 250826 156449 61860 80446
[14:03:48.783] 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:03:48.783] INFO: number of Vcal hits detected: 207577 207769 207416 207041 206757 206829 207009 207416 207389 207250 207361 207478 207490 207694 207875 207850
[14:03:48.783] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.5 99.5 99.6 99.7 99.7 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[14:03:48.783] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.5 99.4 99.4 99.5 99.7 99.7 99.6 99.7 99.7 99.8 99.9 99.9 99.9
[14:03:48.783] INFO: X-ray hit rate [MHz/cm2]: 58.3 40.7 61.7 96.8 108.7 105.2 102.6 75.2 77.6 86.0 81.9 72.3 73.5 45.9 18.1 23.6
[14:03:48.783] INFO: PixTestHighRate::doXPixelAlive() done
[14:03:48.828] INFO: PixTest:: pg_setup set to default.
[14:03:48.844] INFO: enter test to run
[14:03:52.141] INFO: test: exit no parameter change
[14:03:52.477] QUIET: Connection to board 33 closed.
[14:03:52.479] INFO: pXar: this is the end, my friend