[13:47:25.141] INFO: *** Welcome to pxar ***
[13:47:25.141] INFO: *** Today: 2016/09/20
[13:47:25.912] INFO: *** Version: v1.9.0-818-g96727
[13:47:25.912] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//dacParameters35_C15.dat
[13:47:25.950] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:47:25.950] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//defaultMaskFile.dat
[13:47:25.970] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C15.dat
[13:47:26.104] INFO: clk: 4
[13:47:26.104] INFO: ctr: 4
[13:47:26.104] INFO: sda: 19
[13:47:26.104] INFO: tin: 9
[13:47:26.104] INFO: level: 15
[13:47:26.104] INFO: triggerdelay: 0
[13:47:26.104] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:47:26.104] INFO: Log level: INFO
[13:47:26.122] QUIET: Connection to board DTB_WREKRL opened.
[13:47:26.125] 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:47:26.128] INFO: RPC call hashes of host and DTB match: 398089610
[13:47:27.663] INFO: DUT info:
[13:47:27.663] INFO: The DUT currently contains the following objects:
[13:47:27.663] INFO: 2 TBM Cores tbm08c (2 ON)
[13:47:27.686] INFO: TBM Core alpha (0): 7 registers set
[13:47:27.686] INFO: TBM Core beta (1): 7 registers set
[13:47:27.687] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:47:27.687] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:27.687] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:28.110] INFO: enter 'restricted' command line mode
[13:47:28.110] INFO: enter test to run
[13:48:52.087] INFO: test: PixelAlive no parameter change
[13:48:52.087] INFO: running: pixelalive
[13:48:52.107] INFO: ----------------------------------------------------------------------
[13:48:52.107] 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:48:52.108] INFO: ----------------------------------------------------------------------
[13:48:52.424] INFO: Expecting 41600 events.
[13:48:56.773] INFO: 41600 events read in total (3631ms).
[13:48:56.938] INFO: Test took 4828ms.
[13:48:56.946] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:57.243] INFO: PixTestAlive::aliveTest() done
[13:48:57.243] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 1 0 0
[13:48:57.274] INFO: enter test to run
[13:49:14.527] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:49:14.527] INFO: running: highrate
[13:49:14.528] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:49:14.773] INFO: ----------------------------------------------------------------------
[13:49:14.773] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:49:14.773] INFO: ----------------------------------------------------------------------
[13:49:14.773] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:49:14.773] INFO: edge/corner pixel THR is adjusted
[13:49:14.773] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:49:15.732] INFO: Collecting data for 5 seconds...
[13:49:20.747] INFO: Done with hot pixel readout
[13:49:32.322] INFO: PixTest:: pg_setup set to default.
[13:49:32.323] INFO: 2 hot pixels found in step 0
[13:49:33.313] INFO: Collecting data for 5 seconds...
[13:49:38.329] INFO: Done with hot pixel readout
[13:49:49.823] INFO: PixTest:: pg_setup set to default.
[13:49:49.823] INFO: 1 hot pixels found in step 1
[13:49:50.815] INFO: Collecting data for 5 seconds...
[13:49:55.832] INFO: Done with hot pixel readout
[13:50:07.369] INFO: PixTest:: pg_setup set to default.
[13:50:07.370] INFO: 2 hot pixels found in step 2
[13:50:08.361] INFO: Collecting data for 5 seconds...
[13:50:13.377] INFO: Done with hot pixel readout
[13:50:24.946] INFO: PixTest:: pg_setup set to default.
[13:50:24.947] INFO: 3 hot pixels found in step 3
[13:50:25.939] INFO: Collecting data for 5 seconds...
[13:50:30.956] INFO: Done with hot pixel readout
[13:50:42.494] INFO: PixTest:: pg_setup set to default.
[13:50:42.495] INFO: 2 hot pixels found in step 4
[13:50:43.486] INFO: Collecting data for 5 seconds...
[13:50:48.502] INFO: Done with hot pixel readout
[13:50:59.070] INFO: PixTest:: pg_setup set to default.
[13:50:59.071] INFO: 5 hot pixels found in step 5
[13:51:00.063] INFO: Collecting data for 5 seconds...
[13:51:05.080] INFO: Done with hot pixel readout
[13:51:16.620] INFO: PixTest:: pg_setup set to default.
[13:51:16.620] INFO: 2 hot pixels found in step 6
[13:51:17.613] INFO: Collecting data for 5 seconds...
[13:51:22.630] INFO: Done with hot pixel readout
[13:51:34.226] INFO: PixTest:: pg_setup set to default.
[13:51:34.227] INFO: 1 hot pixels found in step 7
[13:51:35.220] INFO: Collecting data for 5 seconds...
[13:51:40.236] INFO: Done with hot pixel readout
[13:51:51.735] INFO: PixTest:: pg_setup set to default.
[13:51:51.736] INFO: 1 hot pixels found in step 8
[13:51:52.728] INFO: Collecting data for 5 seconds...
[13:51:57.745] INFO: Done with hot pixel readout
[13:52:09.299] INFO: PixTest:: pg_setup set to default.
[13:52:09.300] INFO: 3 hot pixels found in step 9
[13:52:10.291] INFO: Collecting data for 5 seconds...
[13:52:15.308] INFO: Done with hot pixel readout
[13:52:27.028] INFO: PixTest:: pg_setup set to default.
[13:52:27.028] INFO: 0 hot pixels found in step 10
[13:52:27.065] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:52:27.069] INFO: PixTest::trimHotPixels() done
[13:52:27.069] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C0.dat
[13:52:27.075] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C1.dat
[13:52:27.080] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C2.dat
[13:52:27.086] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C3.dat
[13:52:27.091] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C4.dat
[13:52:27.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C5.dat
[13:52:27.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C6.dat
[13:52:27.107] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C7.dat
[13:52:27.113] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C8.dat
[13:52:27.118] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C9.dat
[13:52:27.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C10.dat
[13:52:27.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C11.dat
[13:52:27.134] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C12.dat
[13:52:27.139] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C13.dat
[13:52:27.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C14.dat
[13:52:27.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C15.dat
[13:52:27.156] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//defaultMaskFile.dat
[13:52:27.166] INFO: enter test to run
[13:53:01.414] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:53:01.414] INFO: running: highrate
[13:53:01.418] INFO: ----------------------------------------------------------------------
[13:53:01.419] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:53:01.419] INFO: ----------------------------------------------------------------------
[13:53:01.419] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:53:01.419] INFO: edge/corner pixel THR is adjusted
[13:53:01.419] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:53:02.375] INFO: Collecting data for 1 seconds...
[13:53:03.379] INFO: Done with hot pixel readout
[13:53:07.302] INFO: PixTest:: pg_setup set to default.
[13:53:07.303] INFO: 0 hot pixels found in step 0
[13:53:07.308] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:53:07.370] INFO: PixTest::trimHotPixels() done
[13:53:07.370] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C0.dat
[13:53:07.382] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C1.dat
[13:53:07.388] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C2.dat
[13:53:07.393] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C3.dat
[13:53:07.398] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C4.dat
[13:53:07.404] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C5.dat
[13:53:07.409] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C6.dat
[13:53:07.414] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C7.dat
[13:53:07.420] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C8.dat
[13:53:07.425] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C9.dat
[13:53:07.431] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C10.dat
[13:53:07.436] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C11.dat
[13:53:07.441] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C12.dat
[13:53:07.446] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C13.dat
[13:53:07.452] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C14.dat
[13:53:07.457] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//trimParameters35_C15.dat
[13:53:07.463] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-9-03_FPIXTest-17C-FNAL-160919-1227-150V_2016-09-19_12h27m_1474306038/000_FPIXTest_p17//defaultMaskFile.dat
[13:53:07.473] INFO: enter test to run
[13:53:30.774] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:53:30.774] INFO: running: xray
[13:53:30.775] INFO: ----------------------------------------------------------------------
[13:53:30.775] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:53:30.775] INFO: ----------------------------------------------------------------------
[13:53:31.737] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:53:43.392] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:54:12.935] INFO: Resuming triggers.
[13:54:24.593] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:54:53.690] INFO: Resuming triggers.
[13:55:05.347] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:55:35.017] INFO: Resuming triggers.
[13:55:46.674] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:56:15.465] INFO: Resuming triggers.
[13:56:27.124] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:56:57.786] INFO: Resuming triggers.
[13:57:09.442] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:57:39.917] INFO: Resuming triggers.
[13:57:51.575] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:58:21.987] INFO: Resuming triggers.
[13:58:33.650] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:59:04.088] INFO: Resuming triggers.
[13:59:11.188] INFO: data taking finished, elapsed time: 100 seconds.
[13:59:29.419] INFO: PixTest:: pg_setup set to default.
[13:59:29.422] INFO: PixTestXray::doPhRun() done
[13:59:29.662] INFO: enter test to run
[14:00:01.435] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:00:01.435] INFO: running: xray
[14:00:01.436] INFO: ----------------------------------------------------------------------
[14:00:01.436] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:00:01.436] INFO: ----------------------------------------------------------------------
[14:00:02.405] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:00:09.370] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:00:39.686] INFO: Resuming triggers.
[14:00:46.649] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:01:16.930] INFO: Resuming triggers.
[14:01:23.896] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:01:54.144] INFO: Resuming triggers.
[14:02:01.115] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:02:31.305] INFO: Resuming triggers.
[14:02:38.273] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:03:08.491] INFO: Resuming triggers.
[14:03:15.461] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[14:03:45.799] INFO: Resuming triggers.
[14:03:52.771] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[14:04:22.887] INFO: Resuming triggers.
[14:04:29.856] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:05:00.064] INFO: Resuming triggers.
[14:05:07.033] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[14:05:37.251] INFO: Resuming triggers.
[14:05:44.222] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:06:14.892] INFO: Resuming triggers.
[14:06:21.867] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[14:06:53.042] INFO: Resuming triggers.
[14:07:00.014] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:07:30.431] INFO: Resuming triggers.
[14:07:37.406] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[14:08:08.451] INFO: Resuming triggers.
[14:08:15.421] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[14:08:46.255] INFO: Resuming triggers.
[14:08:49.021] INFO: data taking finished, elapsed time: 100 seconds.
[14:09:01.745] INFO: PixTest:: pg_setup set to default.
[14:09:01.748] INFO: PixTestXray::doPhRun() done
[14:09:01.903] INFO: enter test to run
[14:09:33.647] INFO: test: HighRate no parameter change
[14:09:33.647] INFO: running: highrate
[14:09:33.661] INFO: ----------------------------------------------------------------------
[14:09:33.661] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:09:33.661] INFO: ----------------------------------------------------------------------
[14:09:33.815] INFO: Expecting 768 events.
[14:09:34.948] INFO: 768 events read in total (417ms).
[14:09:34.949] INFO: Test took 1268ms.
[14:09:35.751] INFO: Expecting 41600 events.
[14:09:38.809] INFO: 41600 events read in total (2531ms).
[14:09:38.810] INFO: Test took 3817ms.
[14:09:38.843] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:39.563] INFO: Expecting 41600 events.
[14:09:42.741] INFO: 41600 events read in total (2651ms).
[14:09:42.742] INFO: Test took 3881ms.
[14:09:42.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:43.498] INFO: Expecting 41600 events.
[14:09:46.727] INFO: 41600 events read in total (2703ms).
[14:09:46.728] INFO: Test took 3934ms.
[14:09:46.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:47.484] INFO: Expecting 41600 events.
[14:09:50.677] INFO: 41600 events read in total (2666ms).
[14:09:50.678] INFO: Test took 3899ms.
[14:09:50.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:51.436] INFO: Expecting 41600 events.
[14:09:54.655] INFO: 41600 events read in total (2692ms).
[14:09:54.656] INFO: Test took 3928ms.
[14:09:54.690] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:55.405] INFO: Expecting 41600 events.
[14:09:58.597] INFO: 41600 events read in total (2666ms).
[14:09:58.597] INFO: Test took 3889ms.
[14:09:58.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:59.354] INFO: Expecting 41600 events.
[14:10:02.546] INFO: 41600 events read in total (2665ms).
[14:10:02.547] INFO: Test took 3899ms.
[14:10:02.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:03.306] INFO: Expecting 41600 events.
[14:10:06.500] INFO: 41600 events read in total (2667ms).
[14:10:06.501] INFO: Test took 3903ms.
[14:10:06.535] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:07.255] INFO: Expecting 41600 events.
[14:10:10.577] INFO: 41600 events read in total (2795ms).
[14:10:10.578] INFO: Test took 4026ms.
[14:10:10.613] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:11.325] INFO: Expecting 41600 events.
[14:10:14.676] INFO: 41600 events read in total (2824ms).
[14:10:14.677] INFO: Test took 4044ms.
[14:10:14.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:15.428] INFO: Expecting 41600 events.
[14:10:18.706] INFO: 41600 events read in total (2751ms).
[14:10:18.707] INFO: Test took 3978ms.
[14:10:18.742] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:19.461] INFO: Expecting 41600 events.
[14:10:22.788] INFO: 41600 events read in total (2800ms).
[14:10:22.789] INFO: Test took 4030ms.
[14:10:22.827] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:23.534] INFO: Expecting 41600 events.
[14:10:26.850] INFO: 41600 events read in total (2789ms).
[14:10:26.851] INFO: Test took 4000ms.
[14:10:26.888] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:27.604] INFO: Expecting 41600 events.
[14:10:30.838] INFO: 41600 events read in total (2708ms).
[14:10:30.839] INFO: Test took 3934ms.
[14:10:30.873] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:31.594] INFO: Expecting 41600 events.
[14:10:34.884] INFO: 41600 events read in total (2764ms).
[14:10:34.885] INFO: Test took 3994ms.
[14:10:34.918] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:35.642] INFO: Expecting 41600 events.
[14:10:38.943] INFO: 41600 events read in total (2774ms).
[14:10:38.944] INFO: Test took 4006ms.
[14:10:38.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:39.695] INFO: Expecting 41600 events.
[14:10:42.960] INFO: 41600 events read in total (2738ms).
[14:10:42.961] INFO: Test took 3966ms.
[14:10:42.995] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:43.712] INFO: Expecting 41600 events.
[14:10:46.962] INFO: 41600 events read in total (2723ms).
[14:10:46.963] INFO: Test took 3951ms.
[14:10:46.996] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:47.713] INFO: Expecting 41600 events.
[14:10:50.938] INFO: 41600 events read in total (2699ms).
[14:10:50.939] INFO: Test took 3925ms.
[14:10:50.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:51.693] INFO: Expecting 41600 events.
[14:10:54.813] INFO: 41600 events read in total (2593ms).
[14:10:54.814] INFO: Test took 3824ms.
[14:10:54.847] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:55.211] INFO: enter test to run
[14:11:05.798] INFO: test: HighRate no parameter change
[14:11:05.798] INFO: running: highrate
[14:11:05.799] INFO: ----------------------------------------------------------------------
[14:11:05.799] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:11:05.799] INFO: ----------------------------------------------------------------------
[14:11:06.415] INFO: Expecting 208000 events.
[14:11:18.168] INFO: 208000 events read in total (11226ms).
[14:11:18.171] INFO: Test took 12365ms.
[14:11:18.312] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:18.564] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 19 0 0 0 0 0 0 1 0 0
[14:11:18.564] INFO: number of red-efficiency pixels: 104 54 69 135 142 151 182 101 87 124 151 90 103 54 24 19
[14:11:18.564] INFO: number of X-ray hits detected: 69169 40517 63141 98688 101346 110017 115029 78331 74552 94358 90375 76486 77283 48477 20281 22090
[14:11:18.564] 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:11:18.564] INFO: number of Vcal hits detected: 207894 207945 207928 207863 207858 207847 206160 207898 207912 207876 207843 207909 207895 207895 207976 207981
[14:11:18.564] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.6 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:11:18.564] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.1 100.0 100.0 99.9 99.9 100.0 99.9 99.9 100.0 100.0
[14:11:18.564] INFO: X-ray hit rate [MHz/cm2]: 20.3 11.9 18.5 28.9 29.7 32.2 33.7 23.0 21.9 27.7 26.5 22.4 22.7 14.2 5.9 6.5
[14:11:18.564] INFO: PixTestHighRate::doXPixelAlive() done
[14:11:18.611] INFO: PixTest:: pg_setup set to default.
[14:11:18.627] INFO: enter test to run
[14:13:01.293] INFO: test: HighRate no parameter change
[14:13:01.294] INFO: running: highrate
[14:13:01.295] INFO: ----------------------------------------------------------------------
[14:13:01.295] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:13:01.295] INFO: ----------------------------------------------------------------------
[14:13:01.918] INFO: Expecting 208000 events.
[14:13:15.386] INFO: 208000 events read in total (12941ms).
[14:13:15.391] INFO: Test took 14087ms.
[14:13:15.658] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:15.953] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 36 0 0 0 0 0 0 1 0 0
[14:13:15.953] INFO: number of red-efficiency pixels: 249 93 204 448 415 492 564 365 245 384 406 231 258 133 47 63
[14:13:15.953] INFO: number of X-ray hits detected: 141544 83014 128950 202131 207391 224912 233786 160731 153228 193983 185335 158954 159216 99872 41721 45571
[14:13:15.953] 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:13:15.953] INFO: number of Vcal hits detected: 207730 207904 207779 207517 207554 207460 203390 207607 207745 207589 207564 207759 207732 207810 207952 207936
[14:13:15.953] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 98.6 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:13:15.953] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.7 97.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:13:15.953] INFO: X-ray hit rate [MHz/cm2]: 41.5 24.3 37.8 59.2 60.8 65.9 68.5 47.1 44.9 56.9 54.3 46.6 46.7 29.3 12.2 13.4
[14:13:15.953] INFO: PixTestHighRate::doXPixelAlive() done
[14:13:15.004] INFO: PixTest:: pg_setup set to default.
[14:13:16.017] INFO: enter test to run
[14:13:31.477] INFO: test: HighRate no parameter change
[14:13:31.477] INFO: running: highrate
[14:13:31.478] INFO: ----------------------------------------------------------------------
[14:13:31.478] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:13:31.478] INFO: ----------------------------------------------------------------------
[14:13:32.096] INFO: Expecting 208000 events.
[14:13:47.179] INFO: 208000 events read in total (14556ms).
[14:13:47.186] INFO: Test took 15699ms.
[14:13:47.613] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:47.957] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 4 0 0 0 0 0 0 1 0 0
[14:13:47.957] INFO: number of red-efficiency pixels: 586 203 468 1002 889 1219 1140 815 438 964 860 486 657 314 98 73
[14:13:47.957] INFO: number of X-ray hits detected: 215610 126701 194837 307604 315552 341735 353270 245150 233329 294531 282166 241110 241771 152841 63419 68967
[14:13:47.957] 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:13:47.957] INFO: number of Vcal hits detected: 207299 207783 207435 206751 206908 206409 200740 206964 207513 206832 206959 207461 207249 207602 207902 207927
[14:13:47.957] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.8 99.5 99.5 99.3 96.6 99.6 99.8 99.5 99.5 99.8 99.7 99.8 100.0 100.0
[14:13:47.957] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.4 99.5 99.2 96.5 99.5 99.8 99.4 99.5 99.7 99.6 99.8 100.0 100.0
[14:13:47.957] INFO: X-ray hit rate [MHz/cm2]: 63.2 37.1 57.1 90.2 92.5 100.2 103.5 71.9 68.4 86.3 82.7 70.7 70.9 44.8 18.6 20.2
[14:13:47.957] INFO: PixTestHighRate::doXPixelAlive() done
[14:13:48.006] INFO: PixTest:: pg_setup set to default.
[14:13:48.027] INFO: enter test to run
[14:14:04.701] INFO: test: exit no parameter change
[14:14:05.071] QUIET: Connection to board 33 closed.
[14:14:05.080] INFO: pXar: this is the end, my friend