[17:04:32.806] INFO: *** Welcome to pxar ***
[17:04:32.806] INFO: *** Today: 2016/10/18
[17:04:33.617] INFO: *** Version: v1.9.0-818-g96727
[17:04:33.617] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//dacParameters35_C15.dat
[17:04:33.629] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:04:33.629] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//defaultMaskFile.dat
[17:04:33.643] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C15.dat
[17:04:33.739] INFO: clk: 4
[17:04:33.739] INFO: ctr: 4
[17:04:33.739] INFO: sda: 19
[17:04:33.739] INFO: tin: 9
[17:04:33.739] INFO: level: 15
[17:04:33.739] INFO: triggerdelay: 0
[17:04:33.739] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[17:04:33.739] INFO: Log level: INFO
[17:04:33.755] QUIET: Connection to board DTB_WREKRL opened.
[17:04:33.758] 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:
------------------------------------------------------
[17:04:33.761] INFO: RPC call hashes of host and DTB match: 398089610
[17:04:35.300] INFO: DUT info:
[17:04:35.300] INFO: The DUT currently contains the following objects:
[17:04:35.300] INFO: 2 TBM Cores tbm08c (2 ON)
[17:04:35.300] INFO: TBM Core alpha (0): 7 registers set
[17:04:35.300] INFO: TBM Core beta (1): 7 registers set
[17:04:35.300] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[17:04:35.300] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.300] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:04:35.713] INFO: enter 'restricted' command line mode
[17:04:35.713] INFO: enter test to run
[17:04:56.569] INFO: test: PixelAlive no parameter change
[17:04:56.569] INFO: running: pixelalive
[17:04:56.580] INFO: ----------------------------------------------------------------------
[17:04:56.580] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:04:56.580] INFO: ----------------------------------------------------------------------
[17:04:56.933] INFO: Expecting 41600 events.
[17:05:01.309] INFO: 41600 events read in total (3658ms).
[17:05:01.475] INFO: Test took 4893ms.
[17:05:01.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:05:01.951] INFO: PixTestAlive::aliveTest() done
[17:05:01.951] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0
[17:05:02.010] INFO: enter test to run
[17:05:18.440] INFO: test: timing no parameter change
[17:05:18.440] INFO: running: timing
[17:05:18.444] INFO: ######################################################################
[17:05:18.444] INFO: PixTestTiming::doTest()
[17:05:18.444] INFO: ######################################################################
[17:05:18.444] INFO: ----------------------------------------------------------------------
[17:05:18.444] INFO: PixTestTiming::TBMPhaseScan()
[17:05:18.444] INFO: ----------------------------------------------------------------------
[17:10:14.721] INFO: TBM Phase Settings: 240
[17:10:14.722] INFO: 400MHz Phase: 4
[17:10:14.722] INFO: 160MHz Phase: 7
[17:10:14.722] INFO: Functional Phase Area: 5
[17:10:14.731] INFO: Test took 296287 ms.
[17:10:14.731] INFO: PixTestTiming::TBMPhaseScan() done.
[17:10:14.731] INFO: ----------------------------------------------------------------------
[17:10:14.731] INFO: PixTestTiming::ROCDelayScan()
[17:10:14.731] INFO: ----------------------------------------------------------------------
[17:12:19.172] INFO: ROC Delay Settings: 227
[17:12:19.172] INFO: ROC Header-Trailer/Token Delay: 11
[17:12:19.172] INFO: ROC Port 0 Delay: 3
[17:12:19.172] INFO: ROC Port 1 Delay: 4
[17:12:19.172] INFO: Functional ROC Area: 3
[17:12:19.175] INFO: Test took 124444 ms.
[17:12:19.175] INFO: PixTestTiming::ROCDelayScan() done.
[17:12:19.176] INFO: ----------------------------------------------------------------------
[17:12:19.176] INFO: PixTestTiming::TimingTest()
[17:12:19.176] INFO: ----------------------------------------------------------------------
[17:12:35.340] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:12:50.313] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:05.299] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:20.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:35.266] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:50.263] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:05.253] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:20.242] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:35.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:50.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:50.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:50.963] INFO: ----------------------------------------------------------------------
[17:14:50.963] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[17:14:50.963] INFO: ----------------------------------------------------------------------
[17:14:50.963] INFO: ----------------------------------------------------------------------
[17:14:50.963] INFO: Read back bit status: 1
[17:14:50.963] INFO: ----------------------------------------------------------------------
[17:14:50.963] INFO: ----------------------------------------------------------------------
[17:14:50.963] INFO: Timings are good!
[17:14:50.963] INFO: ----------------------------------------------------------------------
[17:14:50.963] INFO: Test took 151787 ms.
[17:14:50.963] INFO: PixTestTiming::TimingTest() done.
[17:14:50.994] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//tbmParameters_C0a.dat
[17:14:50.994] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:14:50.994] INFO: PixTestTiming::doTest took 572553 ms.
[17:14:50.995] INFO: PixTestTiming::doTest() done
[17:14:50.995] INFO: Write out TBMPhaseScan_0_V0
[17:14:50.995] INFO: Write out TBMPhaseScan_1_V0
[17:14:50.995] INFO: Write out CombinedTBMPhaseScan_V0
[17:14:51.063] INFO: Write out ROCDelayScan3_V0
[17:14:51.064] INFO: enter test to run
[17:15:16.684] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[17:15:16.684] INFO: running: highrate
[17:15:16.728] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[17:15:17.094] INFO: ----------------------------------------------------------------------
[17:15:17.094] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[17:15:17.094] INFO: ----------------------------------------------------------------------
[17:15:17.094] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[17:15:17.094] INFO: edge/corner pixel THR is adjusted
[17:15:17.094] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:15:18.065] INFO: Collecting data for 5 seconds...
[17:15:23.083] INFO: Done with hot pixel readout
[17:15:34.877] INFO: PixTest:: pg_setup set to default.
[17:15:34.878] INFO: 0 hot pixels found in step 0
[17:15:34.915] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:15:34.919] INFO: PixTest::trimHotPixels() done
[17:15:34.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C0.dat
[17:15:34.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C1.dat
[17:15:34.942] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C2.dat
[17:15:34.947] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C3.dat
[17:15:34.952] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C4.dat
[17:15:34.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C5.dat
[17:15:34.963] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C6.dat
[17:15:34.969] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C7.dat
[17:15:34.974] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C8.dat
[17:15:34.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C9.dat
[17:15:34.985] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C10.dat
[17:15:34.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C11.dat
[17:15:34.996] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C12.dat
[17:15:34.001] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C13.dat
[17:15:35.006] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C14.dat
[17:15:35.012] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//trimParameters35_C15.dat
[17:15:35.017] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-4-27_FPIXTest-17C-FNAL-161005-1339-300V_2016-10-05_13h39m_1475692780/000_FPIXTest_p17//defaultMaskFile.dat
[17:15:35.028] INFO: enter test to run
[17:16:02.789] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[17:16:02.789] INFO: running: xray
[17:16:02.791] INFO: ----------------------------------------------------------------------
[17:16:02.791] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:16:02.791] INFO: ----------------------------------------------------------------------
[17:16:03.812] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:16:15.412] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[17:16:45.253] INFO: Resuming triggers.
[17:16:56.857] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[17:17:26.494] INFO: Resuming triggers.
[17:17:38.093] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[17:18:07.144] INFO: Resuming triggers.
[17:18:18.747] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[17:18:49.112] INFO: Resuming triggers.
[17:19:00.710] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[17:19:31.282] INFO: Resuming triggers.
[17:19:42.884] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[17:20:13.060] INFO: Resuming triggers.
[17:20:24.662] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[17:20:55.274] INFO: Resuming triggers.
[17:21:06.876] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[17:21:36.302] INFO: Resuming triggers.
[17:21:43.866] INFO: data taking finished, elapsed time: 100 seconds.
[17:22:03.239] INFO: PixTest:: pg_setup set to default.
[17:22:03.242] INFO: PixTestXray::doPhRun() done
[17:22:03.428] INFO: enter test to run
[17:22:24.994] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:22:24.994] INFO: running: xray
[17:22:24.995] INFO: ----------------------------------------------------------------------
[17:22:24.995] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:22:24.995] INFO: ----------------------------------------------------------------------
[17:22:25.959] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:22:32.792] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[17:23:02.898] INFO: Resuming triggers.
[17:23:09.732] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[17:23:39.954] INFO: Resuming triggers.
[17:23:46.792] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[17:24:17.032] INFO: Resuming triggers.
[17:24:23.862] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[17:24:54.160] INFO: Resuming triggers.
[17:25:00.988] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[17:25:31.238] INFO: Resuming triggers.
[17:25:38.071] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[17:26:08.251] INFO: Resuming triggers.
[17:26:15.084] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[17:26:45.291] INFO: Resuming triggers.
[17:26:52.119] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[17:27:22.390] INFO: Resuming triggers.
[17:27:29.219] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[17:27:59.427] INFO: Resuming triggers.
[17:28:06.254] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[17:28:37.454] INFO: Resuming triggers.
[17:28:44.281] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[17:29:15.009] INFO: Resuming triggers.
[17:29:21.836] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[17:29:52.650] INFO: Resuming triggers.
[17:29:59.477] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[17:30:30.442] INFO: Resuming triggers.
[17:30:37.267] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[17:31:08.186] INFO: Resuming triggers.
[17:31:12.910] INFO: data taking finished, elapsed time: 100 seconds.
[17:31:34.466] INFO: PixTest:: pg_setup set to default.
[17:31:34.470] INFO: PixTestXray::doPhRun() done
[17:31:34.621] INFO: enter test to run
[17:32:13.302] INFO: test: HighRate no parameter change
[17:32:13.302] INFO: running: highrate
[17:32:13.313] INFO: ----------------------------------------------------------------------
[17:32:13.313] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:32:13.313] INFO: ----------------------------------------------------------------------
[17:32:13.460] INFO: Expecting 768 events.
[17:32:14.607] INFO: 768 events read in total (432ms).
[17:32:14.607] INFO: Test took 1282ms.
[17:32:15.411] INFO: Expecting 41600 events.
[17:32:18.625] INFO: 41600 events read in total (2687ms).
[17:32:18.626] INFO: Test took 4013ms.
[17:32:18.662] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:19.384] INFO: Expecting 41600 events.
[17:32:22.679] INFO: 41600 events read in total (2768ms).
[17:32:22.680] INFO: Test took 3999ms.
[17:32:22.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:23.433] INFO: Expecting 41600 events.
[17:32:26.732] INFO: 41600 events read in total (2773ms).
[17:32:26.733] INFO: Test took 3999ms.
[17:32:26.768] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:27.481] INFO: Expecting 41600 events.
[17:32:30.812] INFO: 41600 events read in total (2804ms).
[17:32:30.813] INFO: Test took 4027ms.
[17:32:30.851] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:31.568] INFO: Expecting 41600 events.
[17:32:34.909] INFO: 41600 events read in total (2814ms).
[17:32:34.910] INFO: Test took 4040ms.
[17:32:34.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:35.666] INFO: Expecting 41600 events.
[17:32:38.999] INFO: 41600 events read in total (2806ms).
[17:32:38.001] INFO: Test took 4035ms.
[17:32:39.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:39.750] INFO: Expecting 41600 events.
[17:32:43.034] INFO: 41600 events read in total (2757ms).
[17:32:43.035] INFO: Test took 3977ms.
[17:32:43.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:43.789] INFO: Expecting 41600 events.
[17:32:47.136] INFO: 41600 events read in total (2820ms).
[17:32:47.137] INFO: Test took 4048ms.
[17:32:47.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:47.889] INFO: Expecting 41600 events.
[17:32:51.263] INFO: 41600 events read in total (2846ms).
[17:32:51.264] INFO: Test took 4073ms.
[17:32:51.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:52.009] INFO: Expecting 41600 events.
[17:32:55.358] INFO: 41600 events read in total (2823ms).
[17:32:55.359] INFO: Test took 4041ms.
[17:32:55.395] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:56.114] INFO: Expecting 41600 events.
[17:32:59.449] INFO: 41600 events read in total (2808ms).
[17:32:59.450] INFO: Test took 4037ms.
[17:32:59.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:00.203] INFO: Expecting 41600 events.
[17:33:03.481] INFO: 41600 events read in total (2752ms).
[17:33:03.482] INFO: Test took 3978ms.
[17:33:03.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:04.236] INFO: Expecting 41600 events.
[17:33:07.547] INFO: 41600 events read in total (2784ms).
[17:33:07.548] INFO: Test took 4011ms.
[17:33:07.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:08.295] INFO: Expecting 41600 events.
[17:33:11.616] INFO: 41600 events read in total (2795ms).
[17:33:11.617] INFO: Test took 4012ms.
[17:33:11.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:12.371] INFO: Expecting 41600 events.
[17:33:15.660] INFO: 41600 events read in total (2762ms).
[17:33:15.660] INFO: Test took 3990ms.
[17:33:15.697] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:16.413] INFO: Expecting 41600 events.
[17:33:19.781] INFO: 41600 events read in total (2842ms).
[17:33:19.782] INFO: Test took 4066ms.
[17:33:19.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:20.530] INFO: Expecting 41600 events.
[17:33:23.811] INFO: 41600 events read in total (2755ms).
[17:33:23.812] INFO: Test took 3972ms.
[17:33:23.848] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:24.569] INFO: Expecting 41600 events.
[17:33:27.974] INFO: 41600 events read in total (2878ms).
[17:33:27.975] INFO: Test took 4109ms.
[17:33:28.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:28.729] INFO: Expecting 41600 events.
[17:33:32.056] INFO: 41600 events read in total (2800ms).
[17:33:32.057] INFO: Test took 4027ms.
[17:33:32.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:32.814] INFO: Expecting 41600 events.
[17:33:35.865] INFO: 41600 events read in total (2524ms).
[17:33:35.866] INFO: Test took 3754ms.
[17:33:35.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:36.262] INFO: enter test to run
[17:33:50.349] INFO: test: HighRate no parameter change
[17:33:50.349] INFO: running: highrate
[17:33:50.350] INFO: ----------------------------------------------------------------------
[17:33:50.350] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:33:50.350] INFO: ----------------------------------------------------------------------
[17:33:50.972] INFO: Expecting 208000 events.
[17:34:03.276] INFO: 208000 events read in total (11777ms).
[17:34:03.280] INFO: Test took 12921ms.
[17:34:03.435] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:34:03.691] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0
[17:34:03.691] INFO: number of red-efficiency pixels: 82 48 90 147 128 159 149 124 99 138 128 109 95 46 22 29
[17:34:03.691] INFO: number of X-ray hits detected: 70736 47361 71986 111720 115359 123035 119253 83870 81407 105085 103381 85982 89855 54112 21877 24549
[17:34:03.691] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:34:03.691] INFO: number of Vcal hits detected: 207916 207950 207901 207848 207864 207836 207848 207874 207753 207859 207870 207890 207901 207952 207978 207970
[17:34:03.691] 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
[17:34:03.691] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[17:34:03.691] INFO: X-ray hit rate [MHz/cm2]: 20.7 13.9 21.1 32.7 33.8 36.1 35.0 24.6 23.9 30.8 30.3 25.2 26.3 15.9 6.4 7.2
[17:34:03.691] INFO: PixTestHighRate::doXPixelAlive() done
[17:34:03.736] INFO: PixTest:: pg_setup set to default.
[17:34:03.750] INFO: enter test to run
[17:35:00.989] INFO: test: HighRate no parameter change
[17:35:00.989] INFO: running: highrate
[17:35:00.990] INFO: ----------------------------------------------------------------------
[17:35:00.990] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:35:00.990] INFO: ----------------------------------------------------------------------
[17:35:01.607] INFO: Expecting 208000 events.
[17:35:15.294] INFO: 208000 events read in total (13160ms).
[17:35:15.299] INFO: Test took 14299ms.
[17:35:15.591] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:35:15.890] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0
[17:35:15.890] INFO: number of red-efficiency pixels: 255 138 253 515 397 615 473 361 300 445 429 284 301 169 58 56
[17:35:15.890] INFO: number of X-ray hits detected: 141653 94861 142306 223390 230317 246197 239396 168511 161509 208981 205471 171640 180450 108395 43816 49960
[17:35:15.890] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:35:15.890] INFO: number of Vcal hits detected: 207728 207853 207715 207428 207571 207296 207481 207599 207532 207518 207541 207704 207690 207827 207937 207943
[17:35:15.890] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[17:35:15.890] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[17:35:15.890] INFO: X-ray hit rate [MHz/cm2]: 41.5 27.8 41.7 65.5 67.5 72.2 70.2 49.4 47.3 61.3 60.2 50.3 52.9 31.8 12.8 14.6
[17:35:15.890] INFO: PixTestHighRate::doXPixelAlive() done
[17:35:15.935] INFO: PixTest:: pg_setup set to default.
[17:35:15.952] INFO: enter test to run
[17:35:32.108] INFO: test: HighRate no parameter change
[17:35:32.108] INFO: running: highrate
[17:35:32.110] INFO: ----------------------------------------------------------------------
[17:35:32.110] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:35:32.110] INFO: ----------------------------------------------------------------------
[17:35:32.731] INFO: Expecting 208000 events.
[17:35:47.973] INFO: 208000 events read in total (14715ms).
[17:35:47.980] INFO: Test took 15860ms.
[17:35:48.402] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:35:48.746] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0
[17:35:48.746] INFO: number of red-efficiency pixels: 542 261 512 1132 864 1344 1017 737 598 956 860 531 568 353 84 80
[17:35:48.746] INFO: number of X-ray hits detected: 204181 136842 205646 320538 331422 354811 342392 241553 234181 302062 296343 247142 258780 156724 63419 71630
[17:35:48.746] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:35:48.746] INFO: number of Vcal hits detected: 207352 207710 207354 206582 206984 206225 206728 207056 207173 206856 206988 207405 207367 207599 207914 207917
[17:35:48.746] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.4 99.6 99.2 99.5 99.6 99.7 99.5 99.6 99.7 99.7 99.8 100.0 100.0
[17:35:48.746] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.3 99.5 99.1 99.4 99.5 99.6 99.5 99.5 99.7 99.7 99.8 100.0 100.0
[17:35:48.746] INFO: X-ray hit rate [MHz/cm2]: 59.8 40.1 60.3 94.0 97.1 104.0 100.4 70.8 68.6 88.5 86.9 72.4 75.9 45.9 18.6 21.0
[17:35:48.746] INFO: PixTestHighRate::doXPixelAlive() done
[17:35:48.795] INFO: PixTest:: pg_setup set to default.
[17:35:48.811] INFO: enter test to run
[17:36:00.588] INFO: test: exit no parameter change
[17:36:01.064] QUIET: Connection to board 33 closed.
[17:36:01.075] INFO: pXar: this is the end, my friend