[11:22:27.063] INFO: *** Welcome to pxar ***
[11:22:27.063] INFO: *** Today: 2016/10/06
[11:22:27.928] INFO: *** Version: v1.9.0-818-g96727
[11:22:27.928] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//dacParameters35_C15.dat
[11:22:27.994] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:22:27.994] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//defaultMaskFile.dat
[11:22:27.000] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C15.dat
[11:22:28.111] INFO: clk: 4
[11:22:28.111] INFO: ctr: 4
[11:22:28.111] INFO: sda: 19
[11:22:28.111] INFO: tin: 9
[11:22:28.112] INFO: level: 15
[11:22:28.112] INFO: triggerdelay: 0
[11:22:28.112] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:22:28.112] INFO: Log level: INFO
[11:22:28.147] QUIET: Connection to board DTB_WREKRL opened.
[11:22:28.151] 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:22:28.153] INFO: RPC call hashes of host and DTB match: 398089610
[11:22:29.683] INFO: DUT info:
[11:22:29.683] INFO: The DUT currently contains the following objects:
[11:22:29.683] INFO: 2 TBM Cores tbm08c (2 ON)
[11:22:29.684] INFO: TBM Core alpha (0): 7 registers set
[11:22:29.684] INFO: TBM Core beta (1): 7 registers set
[11:22:29.684] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:22:29.684] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:29.684] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:22:30.138] INFO: enter 'restricted' command line mode
[11:22:30.138] INFO: enter test to run
[11:22:41.542] INFO: test: PixelAlive no parameter change
[11:22:41.542] INFO: running: pixelalive
[11:22:41.560] INFO: ----------------------------------------------------------------------
[11:22:41.560] 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:22:41.560] INFO: ----------------------------------------------------------------------
[11:22:41.883] INFO: Expecting 41600 events.
[11:22:46.226] INFO: 41600 events read in total (3625ms).
[11:22:46.392] INFO: Test took 4830ms.
[11:22:46.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:22:46.676] INFO: PixTestAlive::aliveTest() done
[11:22:46.676] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 1 1 0 0 0 0 0
[11:22:46.704] INFO: enter test to run
[11:22:59.502] INFO: test: timing no parameter change
[11:22:59.502] INFO: running: timing
[11:22:59.505] INFO: ######################################################################
[11:22:59.505] INFO: PixTestTiming::doTest()
[11:22:59.506] INFO: ######################################################################
[11:22:59.506] INFO: ----------------------------------------------------------------------
[11:22:59.506] INFO: PixTestTiming::TBMPhaseScan()
[11:22:59.506] INFO: ----------------------------------------------------------------------
[11:28:53.553] INFO: TBM Phase Settings: 240
[11:28:53.553] INFO: 400MHz Phase: 4
[11:28:53.553] INFO: 160MHz Phase: 7
[11:28:53.553] INFO: Functional Phase Area: 5
[11:28:53.563] INFO: Test took 354057 ms.
[11:28:53.563] INFO: PixTestTiming::TBMPhaseScan() done.
[11:28:53.563] INFO: ----------------------------------------------------------------------
[11:28:53.563] INFO: PixTestTiming::ROCDelayScan()
[11:28:53.563] INFO: ----------------------------------------------------------------------
[11:30:53.572] INFO: ROC Delay Settings: 228
[11:30:53.572] INFO: ROC Header-Trailer/Token Delay: 11
[11:30:53.572] INFO: ROC Port 0 Delay: 4
[11:30:53.572] INFO: ROC Port 1 Delay: 4
[11:30:53.572] INFO: Functional ROC Area: 5
[11:30:53.575] INFO: Test took 120012 ms.
[11:30:53.575] INFO: PixTestTiming::ROCDelayScan() done.
[11:30:53.576] INFO: ----------------------------------------------------------------------
[11:30:53.576] INFO: PixTestTiming::TimingTest()
[11:30:53.576] INFO: ----------------------------------------------------------------------
[11:31:09.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:24.706] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:39.677] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:54.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:09.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:24.679] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:39.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:54.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:09.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:24.779] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:25.161] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:25.178] INFO: ----------------------------------------------------------------------
[11:33:25.178] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[11:33:25.178] INFO: ----------------------------------------------------------------------
[11:33:25.178] INFO: ----------------------------------------------------------------------
[11:33:25.178] INFO: Read back bit status: 1
[11:33:25.178] INFO: ----------------------------------------------------------------------
[11:33:25.178] INFO: ----------------------------------------------------------------------
[11:33:25.179] INFO: Timings are good!
[11:33:25.179] INFO: ----------------------------------------------------------------------
[11:33:25.179] INFO: Test took 151604 ms.
[11:33:25.179] INFO: PixTestTiming::TimingTest() done.
[11:33:25.179] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//tbmParameters_C0a.dat
[11:33:25.179] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:33:25.179] INFO: PixTestTiming::doTest took 625677 ms.
[11:33:25.179] INFO: PixTestTiming::doTest() done
[11:33:25.179] INFO: Write out TBMPhaseScan_0_V0
[11:33:25.180] INFO: Write out TBMPhaseScan_1_V0
[11:33:25.180] INFO: Write out CombinedTBMPhaseScan_V0
[11:33:25.201] INFO: Write out ROCDelayScan3_V0
[11:33:25.202] INFO: enter test to run
[11:34:58.313] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:34:58.313] INFO: running: highrate
[11:34:58.399] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:34:58.679] INFO: ----------------------------------------------------------------------
[11:34:58.679] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:34:58.679] INFO: ----------------------------------------------------------------------
[11:34:58.679] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:34:58.679] INFO: edge/corner pixel THR is adjusted
[11:34:58.679] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:34:59.656] INFO: Collecting data for 5 seconds...
[11:35:04.674] INFO: Done with hot pixel readout
[11:35:16.928] INFO: PixTest:: pg_setup set to default.


















[11:35:16.930] INFO: 92 hot pixels found in step 0
[11:35:17.926] INFO: Collecting data for 5 seconds...
[11:35:22.942] INFO: Done with hot pixel readout
[11:35:35.046] INFO: PixTest:: pg_setup set to default.




















[11:35:35.047] INFO: 87 hot pixels found in step 1
[11:35:36.043] INFO: Collecting data for 5 seconds...
[11:35:41.061] INFO: Done with hot pixel readout
[11:35:53.295] INFO: PixTest:: pg_setup set to default.




























[11:35:53.296] INFO: 82 hot pixels found in step 2
[11:35:54.292] INFO: Collecting data for 5 seconds...
[11:35:59.310] INFO: Done with hot pixel readout
[11:36:11.517] INFO: PixTest:: pg_setup set to default.























[11:36:11.518] INFO: 83 hot pixels found in step 3
[11:36:12.516] INFO: Collecting data for 5 seconds...
[11:36:17.535] INFO: Done with hot pixel readout
[11:36:29.702] INFO: PixTest:: pg_setup set to default.



























[11:36:29.703] INFO: 79 hot pixels found in step 4
[11:36:30.700] INFO: Collecting data for 5 seconds...
[11:36:35.718] INFO: Done with hot pixel readout
[11:36:47.507] INFO: PixTest:: pg_setup set to default.

























[11:36:47.509] INFO: 63 hot pixels found in step 5
[11:36:48.505] INFO: Collecting data for 5 seconds...
[11:36:53.523] INFO: Done with hot pixel readout
[11:37:05.231] INFO: PixTest:: pg_setup set to default.




























[11:37:05.233] INFO: 78 hot pixels found in step 6
[11:37:06.230] INFO: Collecting data for 5 seconds...
[11:37:11.248] INFO: Done with hot pixel readout
[11:37:23.209] INFO: PixTest:: pg_setup set to default.

























[11:37:23.210] INFO: 76 hot pixels found in step 7
[11:37:24.206] INFO: Collecting data for 5 seconds...
[11:37:29.225] INFO: Done with hot pixel readout
[11:37:41.211] INFO: PixTest:: pg_setup set to default.





















[11:37:41.213] INFO: 60 hot pixels found in step 8
[11:37:42.209] INFO: Collecting data for 5 seconds...
[11:37:47.227] INFO: Done with hot pixel readout
[11:37:59.314] INFO: PixTest:: pg_setup set to default.





























[11:37:59.315] INFO: 66 hot pixels found in step 9
[11:38:00.312] INFO: Collecting data for 5 seconds...
[11:38:05.329] INFO: Done with hot pixel readout
[11:38:17.104] INFO: PixTest:: pg_setup set to default.




























[11:38:17.105] INFO: 71 hot pixels found in step 10
[11:38:18.102] INFO: Collecting data for 5 seconds...
[11:38:23.120] INFO: Done with hot pixel readout
[11:38:35.183] INFO: PixTest:: pg_setup set to default.




























[11:38:35.184] INFO: 64 hot pixels found in step 11
[11:38:36.184] INFO: Collecting data for 5 seconds...
[11:38:41.202] INFO: Done with hot pixel readout
[11:38:53.349] INFO: PixTest:: pg_setup set to default.


































[11:38:53.350] INFO: 68 hot pixels found in step 12
[11:38:54.346] INFO: Collecting data for 5 seconds...
[11:38:59.363] INFO: Done with hot pixel readout
[11:39:11.639] INFO: PixTest:: pg_setup set to default.




























[11:39:11.641] INFO: 78 hot pixels found in step 13
[11:39:12.640] INFO: Collecting data for 5 seconds...
[11:39:17.660] INFO: Done with hot pixel readout
[11:39:29.863] INFO: PixTest:: pg_setup set to default.


































[11:39:29.865] INFO: 60 hot pixels found in step 14
[11:39:29.906] INFO: 60 hot pixels could not be trimmed and have been masked.
[11:39:29.909] INFO: PixTest::trimHotPixels() done
[11:39:29.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C0.dat
[11:39:29.917] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C1.dat
[11:39:29.924] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C2.dat
[11:39:29.930] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C3.dat
[11:39:29.935] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C4.dat
[11:39:29.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C5.dat
[11:39:29.946] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C6.dat
[11:39:29.951] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C7.dat
[11:39:29.957] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C8.dat
[11:39:29.963] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C9.dat
[11:39:29.968] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C10.dat
[11:39:29.973] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C11.dat
[11:39:29.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C12.dat
[11:39:29.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C13.dat
[11:39:29.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C14.dat
[11:39:29.995] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//trimParameters35_C15.dat
[11:39:30.018] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-39_FPIXTest-17C-FNAL-160929-1517-150V_2016-09-29_15h18m_1475180281/000_FPIXTest_p17//defaultMaskFile.dat
[11:39:30.028] INFO: enter test to run
[11:39:43.895] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:39:43.895] INFO: running: xray
[11:39:43.897] INFO: ----------------------------------------------------------------------
[11:39:43.897] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:39:43.897] INFO: ----------------------------------------------------------------------
[11:39:44.876] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:39:55.830] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[11:40:26.422] INFO: Resuming triggers.
[11:40:37.377] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[11:41:05.417] INFO: Resuming triggers.
[11:41:16.369] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[11:41:45.327] INFO: Resuming triggers.
[11:41:56.279] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[11:42:26.011] INFO: Resuming triggers.
[11:42:36.962] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[11:43:06.464] INFO: Resuming triggers.
[11:43:17.415] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[11:43:46.839] INFO: Resuming triggers.
[11:43:57.789] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[11:44:27.348] INFO: Resuming triggers.
[11:44:38.299] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[11:45:08.061] INFO: Resuming triggers.
[11:45:19.011] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[11:45:48.688] INFO: Resuming triggers.
[11:45:50.461] INFO: data taking finished, elapsed time: 100 seconds.
[11:45:55.621] INFO: PixTest:: pg_setup set to default.
[11:45:55.625] INFO: PixTestXray::doPhRun() done
[11:45:55.935] INFO: enter test to run
[11:47:01.628] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:47:01.628] INFO: running: xray
[11:47:01.629] INFO: ----------------------------------------------------------------------
[11:47:01.629] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:47:01.629] INFO: ----------------------------------------------------------------------
[11:47:02.610] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:47:09.234] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:47:39.406] INFO: Resuming triggers.
[11:47:46.027] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:48:16.308] INFO: Resuming triggers.
[11:48:22.933] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[11:48:53.202] INFO: Resuming triggers.
[11:48:59.826] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[11:49:29.893] INFO: Resuming triggers.
[11:49:36.518] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:50:04.951] INFO: Resuming triggers.
[11:50:11.576] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[11:50:40.466] INFO: Resuming triggers.
[11:50:47.089] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[11:51:17.882] INFO: Resuming triggers.
[11:51:24.506] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[11:51:54.970] INFO: Resuming triggers.
[11:52:01.595] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[11:52:32.265] INFO: Resuming triggers.
[11:52:38.890] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[11:53:09.540] INFO: Resuming triggers.
[11:53:16.163] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[11:53:46.924] INFO: Resuming triggers.
[11:53:53.548] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[11:54:24.367] INFO: Resuming triggers.
[11:54:30.990] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[11:55:01.608] INFO: Resuming triggers.
[11:55:08.230] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[11:55:39.505] INFO: Resuming triggers.
[11:55:46.123] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[11:56:17.361] INFO: Resuming triggers.
[11:56:18.357] INFO: data taking finished, elapsed time: 100 seconds.
[11:56:23.465] INFO: PixTest:: pg_setup set to default.
[11:56:23.469] INFO: PixTestXray::doPhRun() done
[11:56:23.652] INFO: enter test to run
[11:56:42.320] INFO: test: HighRate no parameter change
[11:56:42.320] INFO: running: highrate
[11:56:42.353] INFO: ----------------------------------------------------------------------
[11:56:42.353] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:56:42.353] INFO: ----------------------------------------------------------------------
[11:56:42.510] INFO: Expecting 768 events.
[11:56:43.650] INFO: 768 events read in total (424ms).
[11:56:43.650] INFO: Test took 1274ms.
[11:56:44.453] INFO: Expecting 41600 events.
[11:56:47.573] INFO: 41600 events read in total (2593ms).
[11:56:47.574] INFO: Test took 3852ms.
[11:56:47.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:48.332] INFO: Expecting 41600 events.
[11:56:51.576] INFO: 41600 events read in total (2717ms).
[11:56:51.577] INFO: Test took 3899ms.
[11:56:51.615] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:52.330] INFO: Expecting 41600 events.
[11:56:55.696] INFO: 41600 events read in total (2839ms).
[11:56:55.697] INFO: Test took 4063ms.
[11:56:55.736] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:56.445] INFO: Expecting 41600 events.
[11:56:59.727] INFO: 41600 events read in total (2755ms).
[11:56:59.729] INFO: Test took 3974ms.
[11:56:59.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:00.483] INFO: Expecting 41600 events.
[11:57:03.746] INFO: 41600 events read in total (2737ms).
[11:57:03.747] INFO: Test took 3960ms.
[11:57:03.785] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:04.497] INFO: Expecting 41600 events.
[11:57:07.798] INFO: 41600 events read in total (2774ms).
[11:57:07.799] INFO: Test took 3996ms.
[11:57:07.839] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:08.551] INFO: Expecting 41600 events.
[11:57:11.863] INFO: 41600 events read in total (2785ms).
[11:57:11.864] INFO: Test took 4005ms.
[11:57:11.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:12.619] INFO: Expecting 41600 events.
[11:57:15.949] INFO: 41600 events read in total (2803ms).
[11:57:15.950] INFO: Test took 4029ms.
[11:57:15.991] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:16.697] INFO: Expecting 41600 events.
[11:57:20.078] INFO: 41600 events read in total (2854ms).
[11:57:20.079] INFO: Test took 4068ms.
[11:57:20.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:20.832] INFO: Expecting 41600 events.
[11:57:24.114] INFO: 41600 events read in total (2755ms).
[11:57:24.115] INFO: Test took 3980ms.
[11:57:24.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:24.870] INFO: Expecting 41600 events.
[11:57:28.161] INFO: 41600 events read in total (2765ms).
[11:57:28.162] INFO: Test took 3991ms.
[11:57:28.199] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:28.908] INFO: Expecting 41600 events.
[11:57:32.207] INFO: 41600 events read in total (2772ms).
[11:57:32.208] INFO: Test took 3990ms.
[11:57:32.248] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:32.949] INFO: Expecting 41600 events.
[11:57:36.313] INFO: 41600 events read in total (2837ms).
[11:57:36.314] INFO: Test took 4045ms.
[11:57:36.352] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:37.063] INFO: Expecting 41600 events.
[11:57:40.382] INFO: 41600 events read in total (2792ms).
[11:57:40.383] INFO: Test took 4010ms.
[11:57:40.419] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:41.134] INFO: Expecting 41600 events.
[11:57:44.452] INFO: 41600 events read in total (2791ms).
[11:57:44.453] INFO: Test took 4015ms.
[11:57:44.491] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:45.207] INFO: Expecting 41600 events.
[11:57:48.578] INFO: 41600 events read in total (2844ms).
[11:57:48.580] INFO: Test took 4070ms.
[11:57:48.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:49.332] INFO: Expecting 41600 events.
[11:57:52.611] INFO: 41600 events read in total (2752ms).
[11:57:52.612] INFO: Test took 3974ms.
[11:57:52.651] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:53.364] INFO: Expecting 41600 events.
[11:57:56.742] INFO: 41600 events read in total (2851ms).
[11:57:56.743] INFO: Test took 4073ms.
[11:57:56.781] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:57.499] INFO: Expecting 41600 events.
[11:58:00.749] INFO: 41600 events read in total (2723ms).
[11:58:00.750] INFO: Test took 3950ms.
[11:58:00.789] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:01.506] INFO: Expecting 41600 events.
[11:58:04.684] INFO: 41600 events read in total (2651ms).
[11:58:04.685] INFO: Test took 3877ms.
[11:58:04.723] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:05.078] INFO: enter test to run
[11:58:22.063] INFO: test: HighRate no parameter change
[11:58:22.064] INFO: running: highrate
[11:58:22.065] INFO: ----------------------------------------------------------------------
[11:58:22.065] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:58:22.065] INFO: ----------------------------------------------------------------------
[11:58:22.729] INFO: Expecting 208000 events.
[11:58:34.767] INFO: 208000 events read in total (11511ms).
[11:58:34.771] INFO: Test took 12652ms.
[11:58:34.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:35.186] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 1 1 0 0 0 0 0
[11:58:35.209] INFO: number of red-efficiency pixels: 100 56 101 171 191 164 158 112 104 114 188 93 100 66 31 21
[11:58:35.209] INFO: number of X-ray hits detected: 76877 48885 75163 123109 126947 126919 125394 86509 81490 108632 113642 92372 93462 60660 23459 30350
[11:58:35.209] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:58:35.209] INFO: number of Vcal hits detected: 207896 207943 207897 207826 207799 207834 207841 207885 207894 207833 207756 207907 207900 207932 207968 207979
[11:58:35.209] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[11:58:35.209] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[11:58:35.209] INFO: X-ray hit rate [MHz/cm2]: 22.5 14.3 22.0 36.1 37.2 37.2 36.8 25.4 23.9 31.8 33.3 27.1 27.4 17.8 6.9 8.9
[11:58:35.209] INFO: PixTestHighRate::doXPixelAlive() done
[11:58:35.258] INFO: PixTest:: pg_setup set to default.
[11:58:35.272] INFO: enter test to run
[11:58:52.015] INFO: test: HighRate no parameter change
[11:58:52.015] INFO: running: highrate
[11:58:52.016] INFO: ----------------------------------------------------------------------
[11:58:52.016] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:58:52.017] INFO: ----------------------------------------------------------------------
[11:58:52.636] INFO: Expecting 208000 events.
[11:59:06.564] INFO: 208000 events read in total (13401ms).
[11:59:06.570] INFO: Test took 14545ms.
[11:59:06.884] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:07.194] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 1 1 0 0 0 0 0
[11:59:07.194] INFO: number of red-efficiency pixels: 350 158 412 622 676 517 544 370 298 357 570 299 344 197 68 79
[11:59:07.194] INFO: number of X-ray hits detected: 155717 98237 152910 247421 255029 254984 251831 173704 163926 217226 228971 185434 189019 122714 47210 60128
[11:59:07.194] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:59:07.194] INFO: number of Vcal hits detected: 207613 207836 207512 207305 207231 207431 207397 207594 207691 207566 207324 207682 207638 207789 207931 207920
[11:59:07.194] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.9 99.8 99.7 99.9 99.8 99.9 100.0 100.0
[11:59:07.194] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.7 99.7 99.8 99.9 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[11:59:07.194] INFO: X-ray hit rate [MHz/cm2]: 45.6 28.8 44.8 72.5 74.8 74.7 73.8 50.9 48.0 63.7 67.1 54.4 55.4 36.0 13.8 17.6
[11:59:07.194] INFO: PixTestHighRate::doXPixelAlive() done
[11:59:07.244] INFO: PixTest:: pg_setup set to default.
[11:59:07.256] INFO: enter test to run
[11:59:21.791] INFO: test: HighRate no parameter change
[11:59:21.791] INFO: running: highrate
[11:59:21.792] INFO: ----------------------------------------------------------------------
[11:59:21.792] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:59:21.792] INFO: ----------------------------------------------------------------------
[11:59:22.407] INFO: Expecting 208000 events.
[11:59:38.214] INFO: 208000 events read in total (15280ms).
[11:59:38.222] INFO: Test took 16421ms.
[11:59:38.697] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:39.049] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 1 1 0 0 0 0 0
[11:59:39.049] INFO: number of red-efficiency pixels: 646 316 758 1359 1471 1074 1137 752 672 762 1201 554 738 390 99 117
[11:59:39.049] INFO: number of X-ray hits detected: 227505 143234 221727 359453 371563 371817 367053 254092 239131 317917 332907 270770 275107 179548 69010 88103
[11:59:39.049] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:59:39.049] INFO: number of Vcal hits detected: 207141 207648 206952 206151 206012 206626 206512 207017 207250 207079 206430 207369 207133 207561 207898 207881
[11:59:39.049] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.6 99.2 99.1 99.4 99.4 99.6 99.7 99.6 99.3 99.7 99.6 99.8 100.0 99.9
[11:59:39.049] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.1 99.0 99.3 99.3 99.5 99.6 99.6 99.2 99.7 99.6 99.8 100.0 99.9
[11:59:39.049] INFO: X-ray hit rate [MHz/cm2]: 66.7 42.0 65.0 105.4 108.9 109.0 107.6 74.5 70.1 93.2 97.6 79.4 80.6 52.6 20.2 25.8
[11:59:39.049] INFO: PixTestHighRate::doXPixelAlive() done
[11:59:39.096] INFO: PixTest:: pg_setup set to default.
[11:59:39.106] INFO: enter test to run
[11:59:47.159] INFO: test: exit no parameter change
[11:59:47.930] QUIET: Connection to board 33 closed.
[11:59:48.110] INFO: pXar: this is the end, my friend