[13:38:39.946] INFO: *** Welcome to pxar ***
[13:38:39.946] INFO: *** Today: 2016/05/20
[13:38:40.081] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:38:40.081] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//dacParameters35_C15.dat
[13:38:40.102] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:38:40.102] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//defaultMaskFile.dat
[13:38:40.109] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C15.dat
[13:38:40.217] INFO: clk: 4
[13:38:40.217] INFO: ctr: 4
[13:38:40.217] INFO: sda: 19
[13:38:40.217] INFO: tin: 9
[13:38:40.218] INFO: level: 15
[13:38:40.218] INFO: triggerdelay: 0
[13:38:40.218] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:38:40.218] INFO: Log level: INFO
[13:38:40.235] QUIET: Connection to board DTB_WREK4U opened.
[13:38:40.238] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[13:38:40.241] INFO: RPC call hashes of host and DTB match: 398089610
[13:38:41.771] INFO: DUT info:
[13:38:41.771] INFO: The DUT currently contains the following objects:
[13:38:41.771] INFO: 2 TBM Cores tbm08c (2 ON)
[13:38:41.771] INFO: TBM Core alpha (0): 7 registers set
[13:38:41.771] INFO: TBM Core beta (1): 7 registers set
[13:38:41.771] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:38:41.772] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:41.772] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:42.176] INFO: enter 'restricted' command line mode
[13:38:42.176] INFO: enter test to run
[13:38:48.462] INFO: test: PixelAlive no parameter change
[13:38:48.462] INFO: running: pixelalive
[13:38:48.472] INFO: ----------------------------------------------------------------------
[13:38:48.472] 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:38:48.472] INFO: ----------------------------------------------------------------------
[13:38:48.788] INFO: Expecting 41600 events.
[13:38:52.996] INFO: 41600 events read in total (3490ms).
[13:38:53.164] INFO: Test took 4689ms.
[13:38:53.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:53.469] INFO: PixTestAlive::aliveTest() done
[13:38:53.469] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:38:53.498] INFO: enter test to run
[13:39:19.614] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:39:19.614] INFO: running: highrate
[13:39:19.615] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:39:19.849] INFO: ----------------------------------------------------------------------
[13:39:19.849] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:39:19.849] INFO: ----------------------------------------------------------------------
[13:39:19.849] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:39:19.849] INFO: edge/corner pixel THR is adjusted
[13:39:19.849] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:39:20.807] INFO: Collecting data for 5 seconds...
[13:39:25.824] INFO: Done with hot pixel readout
[13:39:38.585] INFO: PixTest:: pg_setup set to default.









[13:39:38.616] INFO: 275 hot pixels found in step 0
[13:39:39.616] INFO: Collecting data for 5 seconds...
[13:39:44.632] INFO: Done with hot pixel readout
[13:39:57.675] INFO: PixTest:: pg_setup set to default.











[13:39:57.677] INFO: 250 hot pixels found in step 1
[13:39:58.675] INFO: Collecting data for 5 seconds...
[13:40:03.691] INFO: Done with hot pixel readout
[13:40:16.737] INFO: PixTest:: pg_setup set to default.




















[13:40:16.739] INFO: 241 hot pixels found in step 2
[13:40:17.740] INFO: Collecting data for 5 seconds...
[13:40:22.756] INFO: Done with hot pixel readout
[13:40:35.534] INFO: PixTest:: pg_setup set to default.















[13:40:35.536] INFO: 236 hot pixels found in step 3
[13:40:36.537] INFO: Collecting data for 5 seconds...
[13:40:41.554] INFO: Done with hot pixel readout
[13:40:53.625] INFO: PixTest:: pg_setup set to default.














[13:40:53.627] INFO: 202 hot pixels found in step 4
[13:40:54.628] INFO: Collecting data for 5 seconds...
[13:40:59.646] INFO: Done with hot pixel readout
[13:41:12.315] INFO: PixTest:: pg_setup set to default.

















[13:41:12.317] INFO: 171 hot pixels found in step 5
[13:41:13.320] INFO: Collecting data for 5 seconds...
[13:41:18.335] INFO: Done with hot pixel readout
[13:41:30.991] INFO: PixTest:: pg_setup set to default.




























[13:41:30.993] INFO: 171 hot pixels found in step 6
[13:41:31.994] INFO: Collecting data for 5 seconds...
[13:41:37.011] INFO: Done with hot pixel readout
[13:41:49.285] INFO: PixTest:: pg_setup set to default.


























[13:41:49.287] INFO: 162 hot pixels found in step 7
[13:41:50.291] INFO: Collecting data for 5 seconds...
[13:41:55.307] INFO: Done with hot pixel readout
[13:42:07.438] INFO: PixTest:: pg_setup set to default.


























[13:42:07.439] INFO: 153 hot pixels found in step 8
[13:42:08.442] INFO: Collecting data for 5 seconds...
[13:42:13.459] INFO: Done with hot pixel readout
[13:42:26.309] INFO: PixTest:: pg_setup set to default.































[13:42:26.312] INFO: 155 hot pixels found in step 9
[13:42:27.322] INFO: Collecting data for 5 seconds...
[13:42:32.340] INFO: Done with hot pixel readout
[13:42:45.376] INFO: PixTest:: pg_setup set to default.




























[13:42:45.378] INFO: 144 hot pixels found in step 10
[13:42:46.380] INFO: Collecting data for 5 seconds...
[13:42:51.397] INFO: Done with hot pixel readout
[13:43:04.006] INFO: PixTest:: pg_setup set to default.






















[13:43:04.008] INFO: 109 hot pixels found in step 11
[13:43:05.010] INFO: Collecting data for 5 seconds...
[13:43:10.028] INFO: Done with hot pixel readout
[13:43:22.664] INFO: PixTest:: pg_setup set to default.

































[13:43:22.666] INFO: 126 hot pixels found in step 12
[13:43:23.668] INFO: Collecting data for 5 seconds...
[13:43:28.686] INFO: Done with hot pixel readout
[13:43:41.454] INFO: PixTest:: pg_setup set to default.































[13:43:41.457] INFO: 114 hot pixels found in step 13
[13:43:42.458] INFO: Collecting data for 5 seconds...
[13:43:47.475] INFO: Done with hot pixel readout
[13:43:59.389] INFO: PixTest:: pg_setup set to default.






















[13:43:59.391] INFO: 107 hot pixels found in step 14
[13:43:59.438] INFO: 107 hot pixels could not be trimmed and have been masked.
[13:43:59.441] INFO: PixTest::trimHotPixels() done
[13:43:59.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C0.dat
[13:43:59.482] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C1.dat
[13:43:59.489] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C2.dat
[13:43:59.495] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C3.dat
[13:43:59.501] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C4.dat
[13:43:59.506] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C5.dat
[13:43:59.512] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C6.dat
[13:43:59.517] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C7.dat
[13:43:59.522] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C8.dat
[13:43:59.528] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C9.dat
[13:43:59.533] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C10.dat
[13:43:59.539] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C11.dat
[13:43:59.544] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C12.dat
[13:43:59.550] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C13.dat
[13:43:59.555] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C14.dat
[13:43:59.560] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C15.dat
[13:43:59.566] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//defaultMaskFile.dat
[13:43:59.578] INFO: enter test to run
[13:44:18.716] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:44:18.716] INFO: running: highrate
[13:44:18.721] INFO: ----------------------------------------------------------------------
[13:44:18.721] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:44:18.721] INFO: ----------------------------------------------------------------------
[13:44:18.721] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:44:18.721] INFO: edge/corner pixel THR is adjusted
[13:44:18.721] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:44:19.678] INFO: Collecting data for 1 seconds...
[13:44:20.682] INFO: Done with hot pixel readout
[13:44:25.292] INFO: PixTest:: pg_setup set to default.
[13:44:25.293] INFO: 0 hot pixels found in step 0
[13:44:25.299] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:44:25.356] INFO: PixTest::trimHotPixels() done
[13:44:25.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C0.dat
[13:44:25.368] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C1.dat
[13:44:25.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C2.dat
[13:44:25.379] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C3.dat
[13:44:25.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C4.dat
[13:44:25.390] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C5.dat
[13:44:25.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C6.dat
[13:44:25.401] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C7.dat
[13:44:25.406] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C8.dat
[13:44:25.412] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C9.dat
[13:44:25.417] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C10.dat
[13:44:25.422] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C11.dat
[13:44:25.428] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C12.dat
[13:44:25.433] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C13.dat
[13:44:25.438] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C14.dat
[13:44:25.443] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//trimParameters35_C15.dat
[13:44:25.449] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-A-NJ_FPIXTest-17C-FNAL-160517-0937_2016-05-17_09h37m_1463495863/000_FPIXTest_p17//defaultMaskFile.dat
[13:44:25.459] INFO: enter test to run
[13:44:39.100] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:44:39.100] INFO: running: xray
[13:44:39.101] INFO: ----------------------------------------------------------------------
[13:44:39.101] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:44:39.101] INFO: ----------------------------------------------------------------------
[13:44:40.065] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:44:50.105] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:45:19.059] INFO: Resuming triggers.
[13:45:29.099] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:45:58.267] INFO: Resuming triggers.
[13:46:08.313] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[13:46:37.296] INFO: Resuming triggers.
[13:46:47.335] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[13:47:15.629] INFO: Resuming triggers.
[13:47:25.670] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[13:47:54.702] INFO: Resuming triggers.
[13:48:04.743] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[13:48:33.715] INFO: Resuming triggers.
[13:48:43.756] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:49:12.822] INFO: Resuming triggers.
[13:49:22.867] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:49:51.741] INFO: Resuming triggers.
[13:50:01.785] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[13:50:30.864] INFO: Resuming triggers.
[13:50:40.802] INFO: data taking finished, elapsed time: 100 seconds.
[13:51:09.761] INFO: PixTest:: pg_setup set to default.
[13:51:09.764] INFO: PixTestXray::doPhRun() done
[13:51:09.906] INFO: enter test to run
[13:51:29.001] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:51:29.001] INFO: running: xray
[13:51:29.002] INFO: ----------------------------------------------------------------------
[13:51:29.002] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:51:29.002] INFO: ----------------------------------------------------------------------
[13:51:30.981] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:51:36.345] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[13:52:06.528] INFO: Resuming triggers.
[13:52:11.895] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:52:41.715] INFO: Resuming triggers.
[13:52:47.078] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[13:53:16.865] INFO: Resuming triggers.
[13:53:22.230] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[13:53:52.987] INFO: Resuming triggers.
[13:53:58.352] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[13:54:28.549] INFO: Resuming triggers.
[13:54:33.915] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:55:04.012] INFO: Resuming triggers.
[13:55:09.375] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[13:55:39.249] INFO: Resuming triggers.
[13:55:44.619] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[13:56:14.482] INFO: Resuming triggers.
[13:56:19.847] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[13:56:49.610] INFO: Resuming triggers.
[13:56:54.973] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[13:57:24.835] INFO: Resuming triggers.
[13:57:30.200] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:57:59.301] INFO: Resuming triggers.
[13:58:04.664] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[13:58:34.434] INFO: Resuming triggers.
[13:58:39.796] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:59:09.642] INFO: Resuming triggers.
[13:59:15.008] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:59:44.737] INFO: Resuming triggers.
[13:59:50.104] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:00:19.785] INFO: Resuming triggers.
[14:00:25.148] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:00:55.710] INFO: Resuming triggers.
[14:01:01.071] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[14:01:31.290] INFO: Resuming triggers.
[14:01:36.652] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:02:06.760] INFO: Resuming triggers.
[14:02:10.524] INFO: data taking finished, elapsed time: 100 seconds.
[14:02:31.910] INFO: PixTest:: pg_setup set to default.
[14:02:31.913] INFO: PixTestXray::doPhRun() done
[14:02:32.062] INFO: enter test to run
[14:03:26.219] INFO: test: HighRate no parameter change
[14:03:26.219] INFO: running: highrate
[14:03:26.240] INFO: ----------------------------------------------------------------------
[14:03:26.240] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:03:26.240] INFO: ----------------------------------------------------------------------
[14:03:26.396] INFO: Expecting 768 events.
[14:03:27.539] INFO: 768 events read in total (418ms).
[14:03:27.540] INFO: Test took 1279ms.
[14:03:28.342] INFO: Expecting 41600 events.
[14:03:31.606] INFO: 41600 events read in total (2737ms).
[14:03:31.607] INFO: Test took 4043ms.
[14:03:31.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:32.353] INFO: Expecting 41600 events.
[14:03:35.761] INFO: 41600 events read in total (2881ms).
[14:03:35.762] INFO: Test took 4086ms.
[14:03:35.809] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:36.509] INFO: Expecting 41600 events.
[14:03:39.890] INFO: 41600 events read in total (2855ms).
[14:03:39.891] INFO: Test took 4060ms.
[14:03:39.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:40.633] INFO: Expecting 41600 events.
[14:03:44.016] INFO: 41600 events read in total (2856ms).
[14:03:44.017] INFO: Test took 4056ms.
[14:03:44.065] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:44.762] INFO: Expecting 41600 events.
[14:03:48.120] INFO: 41600 events read in total (2832ms).
[14:03:48.121] INFO: Test took 4034ms.
[14:03:48.169] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:48.867] INFO: Expecting 41600 events.
[14:03:52.253] INFO: 41600 events read in total (2859ms).
[14:03:52.254] INFO: Test took 4062ms.
[14:03:52.301] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:52.991] INFO: Expecting 41600 events.
[14:03:56.341] INFO: 41600 events read in total (2823ms).
[14:03:56.343] INFO: Test took 4020ms.
[14:03:56.392] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:57.088] INFO: Expecting 41600 events.
[14:04:00.466] INFO: 41600 events read in total (2851ms).
[14:04:00.467] INFO: Test took 4053ms.
[14:04:00.515] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:01.210] INFO: Expecting 41600 events.
[14:04:04.619] INFO: 41600 events read in total (2882ms).
[14:04:04.620] INFO: Test took 4083ms.
[14:04:04.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:05.363] INFO: Expecting 41600 events.
[14:04:08.733] INFO: 41600 events read in total (2843ms).
[14:04:08.734] INFO: Test took 4044ms.
[14:04:08.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:09.476] INFO: Expecting 41600 events.
[14:04:12.752] INFO: 41600 events read in total (2749ms).
[14:04:12.753] INFO: Test took 3949ms.
[14:04:12.800] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:13.494] INFO: Expecting 41600 events.
[14:04:16.845] INFO: 41600 events read in total (2824ms).
[14:04:16.846] INFO: Test took 4024ms.
[14:04:16.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:17.587] INFO: Expecting 41600 events.
[14:04:21.009] INFO: 41600 events read in total (2896ms).
[14:04:21.011] INFO: Test took 4096ms.
[14:04:21.059] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:21.753] INFO: Expecting 41600 events.
[14:04:25.165] INFO: 41600 events read in total (2885ms).
[14:04:25.166] INFO: Test took 4083ms.
[14:04:25.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:25.912] INFO: Expecting 41600 events.
[14:04:29.256] INFO: 41600 events read in total (2817ms).
[14:04:29.257] INFO: Test took 4021ms.
[14:04:29.305] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:29.003] INFO: Expecting 41600 events.
[14:04:33.403] INFO: 41600 events read in total (2873ms).
[14:04:33.404] INFO: Test took 4076ms.
[14:04:33.452] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:34.144] INFO: Expecting 41600 events.
[14:04:37.595] INFO: 41600 events read in total (2924ms).
[14:04:37.596] INFO: Test took 4121ms.
[14:04:37.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:38.314] INFO: Expecting 41600 events.
[14:04:41.707] INFO: 41600 events read in total (2867ms).
[14:04:41.708] INFO: Test took 4031ms.
[14:04:41.755] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:42.446] INFO: Expecting 41600 events.
[14:04:45.804] INFO: 41600 events read in total (2831ms).
[14:04:45.806] INFO: Test took 4027ms.
[14:04:45.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:46.552] INFO: Expecting 41600 events.
[14:04:49.733] INFO: 41600 events read in total (2654ms).
[14:04:49.734] INFO: Test took 3859ms.
[14:04:49.781] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:50.122] INFO: enter test to run
[14:04:59.691] INFO: test: HighRate no parameter change
[14:04:59.691] INFO: running: highrate
[14:04:59.692] INFO: ----------------------------------------------------------------------
[14:04:59.692] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:04:59.692] INFO: ----------------------------------------------------------------------
[14:05:00.311] INFO: Expecting 208000 events.
[14:05:13.395] INFO: 208000 events read in total (12557ms).
[14:05:13.399] INFO: Test took 13700ms.
[14:05:13.614] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:13.897] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:05:13.897] INFO: number of red-efficiency pixels: 122 109 178 235 250 243 224 164 151 180 237 195 212 110 30 44
[14:05:13.897] INFO: number of X-ray hits detected: 92399 65236 98380 149530 164297 162042 161543 122185 118575 143802 144007 122782 134671 77420 30051 31642
[14:05:13.897] 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:05:13.897] INFO: number of Vcal hits detected: 207870 207886 207815 207759 207740 207748 207770 207828 207844 207816 207755 207794 207782 207888 207970 207955
[14:05:13.897] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:05:13.897] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:05:13.897] INFO: X-ray hit rate [MHz/cm2]: 27.1 19.1 28.8 43.8 48.2 47.5 47.3 35.8 34.8 42.1 42.2 36.0 39.5 22.7 8.8 9.3
[14:05:13.897] INFO: PixTestHighRate::doXPixelAlive() done
[14:05:13.941] INFO: PixTest:: pg_setup set to default.
[14:05:13.959] INFO: enter test to run
[14:05:31.739] INFO: test: HighRate no parameter change
[14:05:31.739] INFO: running: highrate
[14:05:31.740] INFO: ----------------------------------------------------------------------
[14:05:31.740] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:05:31.740] INFO: ----------------------------------------------------------------------
[14:05:32.370] INFO: Expecting 208000 events.
[14:05:47.839] INFO: 208000 events read in total (14942ms).
[14:05:47.846] INFO: Test took 16098ms.
[14:05:48.281] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:48.626] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:05:48.626] INFO: number of red-efficiency pixels: 427 282 556 937 931 1042 914 526 598 624 791 712 796 365 65 76
[14:05:48.626] INFO: number of X-ray hits detected: 184248 130805 198159 297916 329396 324047 324029 247020 238844 287302 286738 247123 270493 155130 60615 64216
[14:05:48.626] 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:05:48.626] INFO: number of Vcal hits detected: 207509 207692 207321 206887 206887 206714 206890 207386 207333 207310 207083 207167 207088 207581 207932 207920
[14:05:48.626] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.5 99.4 99.5 99.7 99.7 99.7 99.6 99.6 99.6 99.8 100.0 100.0
[14:05:48.626] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.5 99.5 99.4 99.5 99.7 99.7 99.7 99.6 99.6 99.6 99.8 100.0 100.0
[14:05:48.626] INFO: X-ray hit rate [MHz/cm2]: 54.0 38.3 58.1 87.3 96.5 95.0 95.0 72.4 70.0 84.2 84.0 72.4 79.3 45.5 17.8 18.8
[14:05:48.626] INFO: PixTestHighRate::doXPixelAlive() done
[14:05:48.672] INFO: PixTest:: pg_setup set to default.
[14:05:48.688] INFO: enter test to run
[14:06:07.946] INFO: test: HighRate no parameter change
[14:06:07.946] INFO: running: highrate
[14:06:07.948] INFO: ----------------------------------------------------------------------
[14:06:07.948] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:06:07.948] INFO: ----------------------------------------------------------------------
[14:06:08.567] INFO: Expecting 208000 events.
[14:06:27.067] INFO: 208000 events read in total (17973ms).
[14:06:27.077] INFO: Test took 19121ms.
[14:06:27.723] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:28.128] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:06:28.128] INFO: number of red-efficiency pixels: 957 600 1247 2087 2014 2380 2026 1227 1383 1534 1964 1520 1828 781 133 113
[14:06:28.128] INFO: number of X-ray hits detected: 279605 198276 299571 450767 497494 488775 490543 373775 362742 435434 436315 373963 408172 236152 91343 97640
[14:06:28.128] 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:06:28.129] INFO: number of Vcal hits detected: 206613 207251 205689 204562 204751 203835 204555 206142 206092 205829 205039 205713 205273 206826 207861 207883
[14:06:28.129] INFO: Vcal hit fiducial efficiency (%): 99.4 99.7 99.0 98.5 98.6 98.2 98.6 99.2 99.2 99.1 98.7 99.1 98.8 99.5 99.9 99.9
[14:06:28.129] INFO: Vcal hit overall efficiency (%): 99.3 99.6 98.9 98.3 98.4 98.0 98.3 99.1 99.1 99.0 98.6 98.9 98.7 99.4 99.9 99.9
[14:06:28.129] INFO: X-ray hit rate [MHz/cm2]: 82.0 58.1 87.8 132.1 145.8 143.3 143.8 109.6 106.3 127.6 127.9 109.6 119.6 69.2 26.8 28.6
[14:06:28.129] INFO: PixTestHighRate::doXPixelAlive() done
[14:06:28.175] INFO: PixTest:: pg_setup set to default.
[14:06:28.192] INFO: enter test to run
[14:07:01.634] INFO: test: exit no parameter change
[14:07:02.036] QUIET: Connection to board 32 closed.
[14:07:02.044] INFO: pXar: this is the end, my friend