[11:57:13.323] INFO: *** Welcome to pxar ***
[11:57:13.323] INFO: *** Today: 2016/07/14
[11:57:13.353] INFO: *** Version: v1.9.0-814-g7497
[11:57:13.353] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//dacParameters35_C15.dat
[11:57:13.382] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:57:13.382] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//defaultMaskFile.dat
[11:57:13.382] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C15.dat
[11:57:13.479] INFO: clk: 4
[11:57:13.479] INFO: ctr: 4
[11:57:13.479] INFO: sda: 19
[11:57:13.479] INFO: tin: 9
[11:57:13.479] INFO: level: 15
[11:57:13.479] INFO: triggerdelay: 0
[11:57:13.479] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:57:13.479] INFO: Log level: INFO
[11:57:13.497] QUIET: Connection to board DTB_WREKRL opened.
[11:57:13.500] 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:
------------------------------------------------------
[11:57:13.503] INFO: RPC call hashes of host and DTB match: 398089610
[11:57:15.032] INFO: DUT info:
[11:57:15.032] INFO: The DUT currently contains the following objects:
[11:57:15.032] INFO: 2 TBM Cores tbm08c (2 ON)
[11:57:15.032] INFO: TBM Core alpha (0): 7 registers set
[11:57:15.032] INFO: TBM Core beta (1): 7 registers set
[11:57:15.032] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:57:15.032] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.032] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:57:15.460] INFO: enter 'restricted' command line mode
[11:57:15.460] INFO: enter test to run
[11:57:21.643] INFO: test: PixelAlive no parameter change
[11:57:21.644] INFO: running: pixelalive
[11:57:21.653] INFO: ----------------------------------------------------------------------
[11:57:21.653] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:57:21.653] INFO: ----------------------------------------------------------------------
[11:57:21.968] INFO: Expecting 41600 events.
[11:57:26.310] INFO: 41600 events read in total (3623ms).
[11:57:26.478] INFO: Test took 4823ms.
[11:57:26.489] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:26.756] INFO: PixTestAlive::aliveTest() done
[11:57:26.756] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[11:57:26.785] INFO: enter test to run
[11:57:44.539] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:57:44.539] INFO: running: highrate
[11:57:44.540] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:57:44.779] INFO: ----------------------------------------------------------------------
[11:57:44.779] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:57:44.779] INFO: ----------------------------------------------------------------------
[11:57:44.779] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:57:44.779] INFO: edge/corner pixel THR is adjusted
[11:57:44.779] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:57:45.738] INFO: Collecting data for 5 seconds...
[11:57:50.755] INFO: Done with hot pixel readout
[11:58:02.763] INFO: PixTest:: pg_setup set to default.
[11:58:02.764] INFO: 33 hot pixels found in step 0
[11:58:03.756] INFO: Collecting data for 5 seconds...
[11:58:08.772] INFO: Done with hot pixel readout
[11:58:20.705] INFO: PixTest:: pg_setup set to default.
[11:58:20.706] INFO: 22 hot pixels found in step 1
[11:58:21.703] INFO: Collecting data for 5 seconds...
[11:58:26.718] INFO: Done with hot pixel readout
[11:58:38.626] INFO: PixTest:: pg_setup set to default.
[11:58:38.627] INFO: 29 hot pixels found in step 2
[11:58:39.623] INFO: Collecting data for 5 seconds...
[11:58:44.639] INFO: Done with hot pixel readout
[11:58:56.610] INFO: PixTest:: pg_setup set to default.
[11:58:56.611] INFO: 22 hot pixels found in step 3
[11:58:57.606] INFO: Collecting data for 5 seconds...
[11:59:02.622] INFO: Done with hot pixel readout
[11:59:14.580] INFO: PixTest:: pg_setup set to default.
[11:59:14.580] INFO: 27 hot pixels found in step 4
[11:59:15.574] INFO: Collecting data for 5 seconds...
[11:59:20.590] INFO: Done with hot pixel readout
[11:59:32.565] INFO: PixTest:: pg_setup set to default.
[11:59:32.566] INFO: 28 hot pixels found in step 5
[11:59:33.560] INFO: Collecting data for 5 seconds...
[11:59:38.577] INFO: Done with hot pixel readout
[11:59:50.564] INFO: PixTest:: pg_setup set to default.
[11:59:50.565] INFO: 19 hot pixels found in step 6
[11:59:51.560] INFO: Collecting data for 5 seconds...
[11:59:56.576] INFO: Done with hot pixel readout
[12:00:08.481] INFO: PixTest:: pg_setup set to default.
[12:00:08.482] INFO: 14 hot pixels found in step 7
[12:00:09.478] INFO: Collecting data for 5 seconds...
[12:00:14.494] INFO: Done with hot pixel readout
[12:00:26.445] INFO: PixTest:: pg_setup set to default.
[12:00:26.445] INFO: 14 hot pixels found in step 8
[12:00:27.446] INFO: Collecting data for 5 seconds...
[12:00:32.462] INFO: Done with hot pixel readout
[12:00:44.383] INFO: PixTest:: pg_setup set to default.
[12:00:44.384] INFO: 19 hot pixels found in step 9
[12:00:45.379] INFO: Collecting data for 5 seconds...
[12:00:50.395] INFO: Done with hot pixel readout
[12:01:02.305] INFO: PixTest:: pg_setup set to default.
[12:01:02.305] INFO: 11 hot pixels found in step 10
[12:01:03.301] INFO: Collecting data for 5 seconds...
[12:01:08.317] INFO: Done with hot pixel readout
[12:01:20.262] INFO: PixTest:: pg_setup set to default.
[12:01:20.263] INFO: 9 hot pixels found in step 11
[12:01:21.258] INFO: Collecting data for 5 seconds...
[12:01:26.274] INFO: Done with hot pixel readout
[12:01:38.204] INFO: PixTest:: pg_setup set to default.
[12:01:38.205] INFO: 18 hot pixels found in step 12
[12:01:39.200] INFO: Collecting data for 5 seconds...
[12:01:44.216] INFO: Done with hot pixel readout
[12:01:56.135] INFO: PixTest:: pg_setup set to default.
[12:01:56.136] INFO: 9 hot pixels found in step 13
[12:01:57.132] INFO: Collecting data for 5 seconds...
[12:02:02.148] INFO: Done with hot pixel readout
[12:02:14.095] INFO: PixTest:: pg_setup set to default.
[12:02:14.096] INFO: 14 hot pixels found in step 14
[12:02:14.135] INFO: 14 hot pixels could not be trimmed and have been masked.
[12:02:14.139] INFO: PixTest::trimHotPixels() done
[12:02:14.139] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C0.dat
[12:02:14.144] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C1.dat
[12:02:14.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C2.dat
[12:02:14.155] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C3.dat
[12:02:14.161] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C4.dat
[12:02:14.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C5.dat
[12:02:14.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C6.dat
[12:02:14.176] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C7.dat
[12:02:14.181] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C8.dat
[12:02:14.187] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C9.dat
[12:02:14.192] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C10.dat
[12:02:14.197] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C11.dat
[12:02:14.202] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C12.dat
[12:02:14.208] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C13.dat
[12:02:14.213] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C14.dat
[12:02:14.219] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C15.dat
[12:02:14.224] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//defaultMaskFile.dat
[12:02:14.242] INFO: enter test to run
[12:02:56.305] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:02:56.305] INFO: running: highrate
[12:02:56.310] INFO: ----------------------------------------------------------------------
[12:02:56.310] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:02:56.310] INFO: ----------------------------------------------------------------------
[12:02:56.310] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:02:56.310] INFO: edge/corner pixel THR is adjusted
[12:02:56.310] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:02:57.267] INFO: Collecting data for 1 seconds...
[12:02:58.271] INFO: Done with hot pixel readout
[12:03:02.418] INFO: PixTest:: pg_setup set to default.
[12:03:02.419] INFO: 0 hot pixels found in step 0
[12:03:02.424] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:03:02.509] INFO: PixTest::trimHotPixels() done
[12:03:02.509] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C0.dat
[12:03:02.520] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C1.dat
[12:03:02.526] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C2.dat
[12:03:02.532] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C3.dat
[12:03:02.537] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C4.dat
[12:03:02.542] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C5.dat
[12:03:02.547] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C6.dat
[12:03:02.552] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C7.dat
[12:03:02.557] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C8.dat
[12:03:02.563] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C9.dat
[12:03:02.568] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C10.dat
[12:03:02.573] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C11.dat
[12:03:02.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C12.dat
[12:03:02.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C13.dat
[12:03:02.589] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C14.dat
[12:03:02.594] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C15.dat
[12:03:02.599] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-46_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//defaultMaskFile.dat
[12:03:02.609] INFO: enter test to run
[12:04:08.553] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:04:08.553] INFO: running: xray
[12:04:08.554] INFO: ----------------------------------------------------------------------
[12:04:08.554] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:04:08.554] INFO: ----------------------------------------------------------------------
[12:04:09.517] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:04:20.651] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:04:49.925] INFO: Resuming triggers.
[12:05:01.062] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:05:31.053] INFO: Resuming triggers.
[12:05:42.186] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:06:12.183] INFO: Resuming triggers.
[12:06:23.315] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[12:06:53.230] INFO: Resuming triggers.
[12:07:04.361] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[12:07:34.153] INFO: Resuming triggers.
[12:07:45.284] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[12:08:15.206] INFO: Resuming triggers.
[12:08:26.339] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[12:08:56.010] INFO: Resuming triggers.
[12:09:07.142] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:09:36.606] INFO: Resuming triggers.
[12:09:47.738] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[12:10:17.079] INFO: Resuming triggers.
[12:10:17.242] INFO: data taking finished, elapsed time: 100 seconds.
[12:10:18.184] INFO: PixTest:: pg_setup set to default.
[12:10:18.187] INFO: PixTestXray::doPhRun() done
[12:10:18.326] INFO: enter test to run
[12:11:12.302] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:11:12.302] INFO: running: xray
[12:11:12.303] INFO: ----------------------------------------------------------------------
[12:11:12.303] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:11:12.303] INFO: ----------------------------------------------------------------------
[12:11:13.274] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:11:19.725] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:11:49.811] INFO: Resuming triggers.
[12:11:56.263] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:12:26.447] INFO: Resuming triggers.
[12:12:32.902] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[12:13:03.103] INFO: Resuming triggers.
[12:13:09.558] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[12:13:39.671] INFO: Resuming triggers.
[12:13:46.123] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:14:16.189] INFO: Resuming triggers.
[12:14:22.643] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[12:14:52.784] INFO: Resuming triggers.
[12:14:59.236] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:15:29.319] INFO: Resuming triggers.
[12:15:35.772] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[12:16:05.881] INFO: Resuming triggers.
[12:16:12.332] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:16:42.509] INFO: Resuming triggers.
[12:16:48.961] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[12:17:19.957] INFO: Resuming triggers.
[12:17:26.408] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:17:57.140] INFO: Resuming triggers.
[12:18:03.592] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[12:18:34.626] INFO: Resuming triggers.
[12:18:41.074] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[12:19:12.080] INFO: Resuming triggers.
[12:19:18.532] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[12:19:49.777] INFO: Resuming triggers.
[12:19:56.229] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[12:20:27.333] INFO: Resuming triggers.
[12:20:30.888] INFO: data taking finished, elapsed time: 100 seconds.
[12:20:47.774] INFO: PixTest:: pg_setup set to default.
[12:20:47.778] INFO: PixTestXray::doPhRun() done
[12:20:47.929] INFO: enter test to run
[12:21:51.682] INFO: test: HighRate no parameter change
[12:21:51.682] INFO: running: highrate
[12:21:51.696] INFO: ----------------------------------------------------------------------
[12:21:51.696] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:21:51.696] INFO: ----------------------------------------------------------------------
[12:21:51.851] INFO: Expecting 768 events.
[12:21:52.984] INFO: 768 events read in total (417ms).
[12:21:52.984] INFO: Test took 1267ms.
[12:21:53.788] INFO: Expecting 41600 events.
[12:21:56.881] INFO: 41600 events read in total (2566ms).
[12:21:56.882] INFO: Test took 3891ms.
[12:21:56.916] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:57.645] INFO: Expecting 41600 events.
[12:22:00.843] INFO: 41600 events read in total (2671ms).
[12:22:00.844] INFO: Test took 3910ms.
[12:22:00.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:01.603] INFO: Expecting 41600 events.
[12:22:04.800] INFO: 41600 events read in total (2670ms).
[12:22:04.801] INFO: Test took 3904ms.
[12:22:04.837] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:05.556] INFO: Expecting 41600 events.
[12:22:08.797] INFO: 41600 events read in total (2714ms).
[12:22:08.798] INFO: Test took 3943ms.
[12:22:08.835] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:09.553] INFO: Expecting 41600 events.
[12:22:12.795] INFO: 41600 events read in total (2715ms).
[12:22:12.796] INFO: Test took 3942ms.
[12:22:12.832] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:13.554] INFO: Expecting 41600 events.
[12:22:16.780] INFO: 41600 events read in total (2699ms).
[12:22:16.781] INFO: Test took 3931ms.
[12:22:16.816] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:17.540] INFO: Expecting 41600 events.
[12:22:20.822] INFO: 41600 events read in total (2755ms).
[12:22:20.824] INFO: Test took 3990ms.
[12:22:20.867] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:21.576] INFO: Expecting 41600 events.
[12:22:24.834] INFO: 41600 events read in total (2731ms).
[12:22:24.835] INFO: Test took 3948ms.
[12:22:24.871] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:25.592] INFO: Expecting 41600 events.
[12:22:28.815] INFO: 41600 events read in total (2696ms).
[12:22:28.816] INFO: Test took 3925ms.
[12:22:28.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:29.573] INFO: Expecting 41600 events.
[12:22:32.810] INFO: 41600 events read in total (2710ms).
[12:22:32.811] INFO: Test took 3940ms.
[12:22:32.847] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:33.566] INFO: Expecting 41600 events.
[12:22:36.817] INFO: 41600 events read in total (2724ms).
[12:22:36.818] INFO: Test took 3953ms.
[12:22:36.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:37.573] INFO: Expecting 41600 events.
[12:22:40.812] INFO: 41600 events read in total (2712ms).
[12:22:40.813] INFO: Test took 3940ms.
[12:22:40.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:41.567] INFO: Expecting 41600 events.
[12:22:44.813] INFO: 41600 events read in total (2719ms).
[12:22:44.814] INFO: Test took 3946ms.
[12:22:44.851] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:45.573] INFO: Expecting 41600 events.
[12:22:48.819] INFO: 41600 events read in total (2720ms).
[12:22:48.820] INFO: Test took 3950ms.
[12:22:48.855] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:49.577] INFO: Expecting 41600 events.
[12:22:52.827] INFO: 41600 events read in total (2723ms).
[12:22:52.828] INFO: Test took 3954ms.
[12:22:52.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:53.587] INFO: Expecting 41600 events.
[12:22:56.825] INFO: 41600 events read in total (2711ms).
[12:22:56.826] INFO: Test took 3943ms.
[12:22:56.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:57.585] INFO: Expecting 41600 events.
[12:23:00.845] INFO: 41600 events read in total (2733ms).
[12:23:00.846] INFO: Test took 3965ms.
[12:23:00.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:01.605] INFO: Expecting 41600 events.
[12:23:04.850] INFO: 41600 events read in total (2718ms).
[12:23:04.851] INFO: Test took 3951ms.
[12:23:04.887] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:05.609] INFO: Expecting 41600 events.
[12:23:08.820] INFO: 41600 events read in total (2684ms).
[12:23:08.821] INFO: Test took 3915ms.
[12:23:08.856] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:09.575] INFO: Expecting 41600 events.
[12:23:12.681] INFO: 41600 events read in total (2579ms).
[12:23:12.682] INFO: Test took 3807ms.
[12:23:12.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:13.079] INFO: enter test to run
[12:23:25.233] INFO: test: HighRate no parameter change
[12:23:25.233] INFO: running: highrate
[12:23:25.234] INFO: ----------------------------------------------------------------------
[12:23:25.234] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:23:25.234] INFO: ----------------------------------------------------------------------
[12:23:25.846] INFO: Expecting 208000 events.
[12:23:37.754] INFO: 208000 events read in total (11381ms).
[12:23:37.757] INFO: Test took 12513ms.
[12:23:37.912] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:38.168] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[12:23:38.168] INFO: number of red-efficiency pixels: 65 60 83 131 160 177 209 107 109 184 154 105 113 63 17 24
[12:23:38.168] INFO: number of X-ray hits detected: 63840 42653 69513 107643 114904 125882 125396 88231 86762 115510 110871 92973 94568 57463 21558 25013
[12:23:38.168] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:23:38.168] INFO: number of Vcal hits detected: 207885 207939 207913 207868 207834 207813 207782 207892 207889 207768 207839 207893 207885 207936 207982 207927
[12:23:38.168] 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 100.0 99.9 100.0 100.0 100.0
[12:23:38.169] INFO: Vcal hit overall efficiency (%): 99.9 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
[12:23:38.169] INFO: X-ray hit rate [MHz/cm2]: 18.7 12.5 20.4 31.6 33.7 36.9 36.8 25.9 25.4 33.9 32.5 27.3 27.7 16.8 6.3 7.3
[12:23:38.169] INFO: PixTestHighRate::doXPixelAlive() done
[12:23:38.215] INFO: PixTest:: pg_setup set to default.
[12:23:38.226] INFO: enter test to run
[12:24:45.592] INFO: test: HighRate no parameter change
[12:24:45.592] INFO: running: highrate
[12:24:45.594] INFO: ----------------------------------------------------------------------
[12:24:45.594] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:24:45.594] INFO: ----------------------------------------------------------------------
[12:24:46.207] INFO: Expecting 208000 events.
[12:24:59.999] INFO: 208000 events read in total (13265ms).
[12:25:00.004] INFO: Test took 14401ms.
[12:25:00.319] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:00.629] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[12:25:00.630] INFO: number of red-efficiency pixels: 210 121 278 384 580 655 669 320 344 495 442 296 318 172 53 56
[12:25:00.630] INFO: number of X-ray hits detected: 129780 86958 141257 220579 235681 256841 255692 181352 179393 237457 228465 191692 194251 118832 45045 50992
[12:25:00.630] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:25:00.630] INFO: number of Vcal hits detected: 207729 207876 207694 207585 207364 207266 207239 207646 207629 207354 207518 207679 207661 207822 207946 207895
[12:25:00.630] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.8 99.8 99.7 99.8 99.9 99.9 99.9 100.0 100.0
[12:25:00.630] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.6 99.6 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 99.9
[12:25:00.630] INFO: X-ray hit rate [MHz/cm2]: 38.0 25.5 41.4 64.7 69.1 75.3 74.9 53.2 52.6 69.6 67.0 56.2 56.9 34.8 13.2 14.9
[12:25:00.630] INFO: PixTestHighRate::doXPixelAlive() done
[12:25:00.678] INFO: PixTest:: pg_setup set to default.
[12:25:00.691] INFO: enter test to run
[12:25:25.192] INFO: test: HighRate no parameter change
[12:25:25.192] INFO: running: highrate
[12:25:25.193] INFO: ----------------------------------------------------------------------
[12:25:25.193] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:25:25.193] INFO: ----------------------------------------------------------------------
[12:25:25.810] INFO: Expecting 208000 events.
[12:25:41.598] INFO: 208000 events read in total (15261ms).
[12:25:41.605] INFO: Test took 16402ms.
[12:25:42.076] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:42.432] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[12:25:42.432] INFO: number of red-efficiency pixels: 435 295 653 787 1321 1487 1610 699 693 1059 964 681 646 394 97 100
[12:25:42.432] INFO: number of X-ray hits detected: 196674 130858 214499 332398 354033 385729 385087 272511 268985 358125 343361 289161 291074 177952 67750 76227
[12:25:42.432] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:25:42.432] INFO: number of Vcal hits detected: 207453 207677 207122 207076 206282 205930 205725 207133 207153 206476 206811 207171 207267 207550 207903 207847
[12:25:42.432] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.6 99.2 99.1 99.0 99.6 99.6 99.3 99.5 99.6 99.7 99.8 100.0 100.0
[12:25:42.432] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 99.6 99.2 99.0 98.9 99.6 99.6 99.3 99.4 99.6 99.6 99.8 100.0 99.9
[12:25:42.432] INFO: X-ray hit rate [MHz/cm2]: 57.6 38.4 62.9 97.4 103.8 113.1 112.9 79.9 78.8 105.0 100.6 84.8 85.3 52.2 19.9 22.3
[12:25:42.432] INFO: PixTestHighRate::doXPixelAlive() done
[12:25:42.482] INFO: PixTest:: pg_setup set to default.
[12:25:42.496] INFO: enter test to run
[12:26:18.472] INFO: test: exit no parameter change
[12:26:18.749] QUIET: Connection to board 33 closed.
[12:26:18.750] INFO: pXar: this is the end, my friend