[11:43:06.481] INFO: *** Welcome to pxar ***
[11:43:06.481] INFO: *** Today: 2016/05/11
[11:43:06.498] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:43:06.498] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//dacParameters35_C15.dat
[11:43:06.541] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:43:06.541] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//defaultMaskFile.dat
[11:43:06.549] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C15.dat
[11:43:06.665] INFO: clk: 4
[11:43:06.665] INFO: ctr: 4
[11:43:06.665] INFO: sda: 19
[11:43:06.665] INFO: tin: 9
[11:43:06.665] INFO: level: 15
[11:43:06.665] INFO: triggerdelay: 0
[11:43:06.665] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:43:06.665] INFO: Log level: INFO
[11:43:06.681] QUIET: Connection to board DTB_WREKRL opened.
[11:43:06.684] 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:43:06.687] INFO: RPC call hashes of host and DTB match: 398089610
[11:43:08.223] INFO: DUT info:
[11:43:08.223] INFO: The DUT currently contains the following objects:
[11:43:08.223] INFO: 2 TBM Cores tbm08c (2 ON)
[11:43:08.223] INFO: TBM Core alpha (0): 7 registers set
[11:43:08.223] INFO: TBM Core beta (1): 7 registers set
[11:43:08.223] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:43:08.224] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.224] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:43:08.628] INFO: enter 'restricted' command line mode
[11:43:08.628] INFO: enter test to run
[11:43:15.679] INFO: test: PixelAlive no parameter change
[11:43:15.679] INFO: running: pixelalive
[11:43:15.688] INFO: ----------------------------------------------------------------------
[11:43:15.689] 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:43:15.689] INFO: ----------------------------------------------------------------------
[11:43:16.009] INFO: Expecting 41600 events.
[11:43:20.230] INFO: 41600 events read in total (3503ms).
[11:43:20.394] INFO: Test took 4703ms.
[11:43:20.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:20.681] INFO: PixTestAlive::aliveTest() done
[11:43:20.681] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:43:20.720] INFO: enter test to run
[11:43:56.911] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:43:56.911] INFO: running: highrate
[11:43:56.911] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:43:58.162] INFO: ----------------------------------------------------------------------
[11:43:58.162] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:43:58.162] INFO: ----------------------------------------------------------------------
[11:43:58.162] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:43:58.162] INFO: edge/corner pixel THR is adjusted
[11:43:58.162] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:43:59.120] INFO: Collecting data for 5 seconds...
[11:44:04.138] INFO: Done with hot pixel readout
[11:44:14.287] INFO: PixTest:: pg_setup set to default.
[11:44:14.288] INFO: 31 hot pixels found in step 0
[11:44:15.282] INFO: Collecting data for 5 seconds...
[11:44:20.295] INFO: Done with hot pixel readout
[11:44:31.428] INFO: PixTest:: pg_setup set to default.
[11:44:31.429] INFO: 35 hot pixels found in step 1
[11:44:32.432] INFO: Collecting data for 5 seconds...
[11:44:37.449] INFO: Done with hot pixel readout
[11:44:47.211] INFO: PixTest:: pg_setup set to default.
[11:44:47.211] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:44:47.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:44:47.212] INFO: 27 hot pixels found in step 2
[11:44:48.211] INFO: Collecting data for 5 seconds...
[11:44:53.223] INFO: Done with hot pixel readout
[11:45:05.341] INFO: PixTest:: pg_setup set to default.
[11:45:05.342] INFO: 24 hot pixels found in step 3
[11:45:06.341] INFO: Collecting data for 5 seconds...
[11:45:11.359] INFO: Done with hot pixel readout
[11:45:23.709] INFO: PixTest:: pg_setup set to default.
[11:45:23.710] INFO: 25 hot pixels found in step 4
[11:45:24.708] INFO: Collecting data for 5 seconds...
[11:45:29.727] INFO: Done with hot pixel readout
[11:45:41.872] INFO: PixTest:: pg_setup set to default.
[11:45:41.872] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:45:41.873] INFO: 21 hot pixels found in step 5
[11:45:42.872] INFO: Collecting data for 5 seconds...
[11:45:47.890] INFO: Done with hot pixel readout
[11:46:00.186] INFO: PixTest:: pg_setup set to default.
[11:46:00.186] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:46:00.186] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:46:00.187] INFO: 21 hot pixels found in step 6
[11:46:01.185] INFO: Collecting data for 5 seconds...
[11:46:06.202] INFO: Done with hot pixel readout
[11:46:18.268] INFO: PixTest:: pg_setup set to default.
[11:46:18.268] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:46:18.269] INFO: 26 hot pixels found in step 7
[11:46:19.269] INFO: Collecting data for 5 seconds...
[11:46:24.286] INFO: Done with hot pixel readout
[11:46:36.634] INFO: PixTest:: pg_setup set to default.
[11:46:36.634] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:46:36.635] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:46:36.635] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:46:36.635] INFO: 21 hot pixels found in step 8
[11:46:37.632] INFO: Collecting data for 5 seconds...
[11:46:42.648] INFO: Done with hot pixel readout
[11:46:55.043] INFO: PixTest:: pg_setup set to default.
[11:46:55.043] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:46:55.044] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:46:55.044] INFO: 22 hot pixels found in step 9
[11:46:56.041] INFO: Collecting data for 5 seconds...
[11:47:01.057] INFO: Done with hot pixel readout
[11:47:13.493] INFO: PixTest:: pg_setup set to default.
[11:47:13.494] INFO: 10 hot pixels found in step 10
[11:47:14.492] INFO: Collecting data for 5 seconds...
[11:47:19.508] INFO: Done with hot pixel readout
[11:47:31.914] INFO: PixTest:: pg_setup set to default.
[11:47:31.914] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:47:31.915] INFO: 20 hot pixels found in step 11
[11:47:32.912] INFO: Collecting data for 5 seconds...
[11:47:37.928] INFO: Done with hot pixel readout
[11:47:47.553] INFO: PixTest:: pg_setup set to default.
[11:47:47.553] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:47:47.554] INFO: 17 hot pixels found in step 12
[11:47:48.552] INFO: Collecting data for 5 seconds...
[11:47:53.565] INFO: Done with hot pixel readout
[11:48:05.940] INFO: PixTest:: pg_setup set to default.
[11:48:05.940] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:48:05.940] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:48:05.941] INFO: 20 hot pixels found in step 13
[11:48:06.938] INFO: Collecting data for 5 seconds...
[11:48:11.954] INFO: Done with hot pixel readout
[11:48:24.365] INFO: PixTest:: pg_setup set to default.
[11:48:24.365] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:48:24.365] INFO: 11 hot pixels found in step 14
[11:48:24.407] INFO: 11 hot pixels could not be trimmed and have been masked.
[11:48:24.411] INFO: PixTest::trimHotPixels() done
[11:48:24.411] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C0.dat
[11:48:24.422] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C1.dat
[11:48:24.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C2.dat
[11:48:24.433] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C3.dat
[11:48:24.438] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C4.dat
[11:48:24.443] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C5.dat
[11:48:24.448] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C6.dat
[11:48:24.453] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C7.dat
[11:48:24.459] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C8.dat
[11:48:24.464] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C9.dat
[11:48:24.469] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C10.dat
[11:48:24.474] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C11.dat
[11:48:24.480] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C12.dat
[11:48:24.485] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C13.dat
[11:48:24.490] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C14.dat
[11:48:24.496] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C15.dat
[11:48:24.501] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//defaultMaskFile.dat
[11:48:24.512] INFO: enter test to run
[11:50:08.476] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:50:08.476] INFO: running: highrate
[11:50:08.481] INFO: ----------------------------------------------------------------------
[11:50:08.481] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:50:08.481] INFO: ----------------------------------------------------------------------
[11:50:08.481] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:50:08.481] INFO: edge/corner pixel THR is adjusted
[11:50:08.481] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:50:09.439] INFO: Collecting data for 1 seconds...
[11:50:10.443] INFO: Done with hot pixel readout
[11:50:14.902] INFO: PixTest:: pg_setup set to default.
[11:50:14.903] INFO: 0 hot pixels found in step 0
[11:50:14.908] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:50:14.982] INFO: PixTest::trimHotPixels() done
[11:50:14.982] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C0.dat
[11:50:14.991] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C1.dat
[11:50:14.997] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C2.dat
[11:50:15.002] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C3.dat
[11:50:15.007] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C4.dat
[11:50:15.013] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C5.dat
[11:50:15.018] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C6.dat
[11:50:15.023] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C7.dat
[11:50:15.028] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C8.dat
[11:50:15.034] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C9.dat
[11:50:15.039] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C10.dat
[11:50:15.044] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C11.dat
[11:50:15.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C12.dat
[11:50:15.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C13.dat
[11:50:15.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C14.dat
[11:50:15.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C15.dat
[11:50:15.070] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-H-NW_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//defaultMaskFile.dat
[11:50:15.081] INFO: enter test to run
[11:50:42.948] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:50:42.948] INFO: running: xray
[11:50:42.949] INFO: ----------------------------------------------------------------------
[11:50:42.949] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:50:42.949] INFO: ----------------------------------------------------------------------
[11:50:43.913] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:50:54.765] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[11:51:24.468] INFO: Resuming triggers.
[11:51:35.319] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[11:52:04.932] INFO: Resuming triggers.
[11:52:15.784] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[11:52:45.480] INFO: Resuming triggers.
[11:52:56.331] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[11:53:25.988] INFO: Resuming triggers.
[11:53:36.839] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[11:54:06.849] INFO: Resuming triggers.
[11:54:17.698] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[11:54:47.497] INFO: Resuming triggers.
[11:54:58.348] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[11:55:28.118] INFO: Resuming triggers.
[11:55:38.972] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[11:56:09.399] INFO: Resuming triggers.
[11:56:20.253] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[11:56:50.600] INFO: Resuming triggers.
[11:56:53.286] INFO: data taking finished, elapsed time: 100 seconds.
[11:57:00.931] INFO: PixTest:: pg_setup set to default.
[11:57:00.934] INFO: PixTestXray::doPhRun() done
[11:57:01.102] INFO: enter test to run
[11:57:37.825] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:57:37.825] INFO: running: xray
[11:57:37.826] INFO: ----------------------------------------------------------------------
[11:57:37.826] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:57:37.826] INFO: ----------------------------------------------------------------------
[11:57:38.797] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:57:44.690] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[11:58:14.944] INFO: Resuming triggers.
[11:58:20.836] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:58:51.074] INFO: Resuming triggers.
[11:58:56.968] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[11:59:27.195] INFO: Resuming triggers.
[11:59:33.087] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:00:03.306] INFO: Resuming triggers.
[12:00:09.199] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[12:00:39.455] INFO: Resuming triggers.
[12:00:45.348] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:01:15.528] INFO: Resuming triggers.
[12:01:21.422] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[12:01:51.657] INFO: Resuming triggers.
[12:01:57.548] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:02:27.738] INFO: Resuming triggers.
[12:02:33.630] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[12:03:03.891] INFO: Resuming triggers.
[12:03:09.785] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[12:03:40.054] INFO: Resuming triggers.
[12:03:45.947] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[12:04:16.180] INFO: Resuming triggers.
[12:04:22.071] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[12:04:52.310] INFO: Resuming triggers.
[12:04:58.204] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:05:29.186] INFO: Resuming triggers.
[12:05:35.081] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:06:05.796] INFO: Resuming triggers.
[12:06:11.691] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:06:42.313] INFO: Resuming triggers.
[12:06:48.208] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:07:19.620] INFO: Resuming triggers.
[12:07:25.513] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[12:07:56.260] INFO: Resuming triggers.
[12:07:56.415] INFO: data taking finished, elapsed time: 100 seconds.
[12:07:57.597] INFO: PixTest:: pg_setup set to default.
[12:07:57.600] INFO: PixTestXray::doPhRun() done
[12:07:57.754] INFO: enter test to run
[12:08:53.348] INFO: test: HighRate no parameter change
[12:08:53.348] INFO: running: highrate
[12:08:53.349] INFO: ----------------------------------------------------------------------
[12:08:53.349] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:08:53.349] INFO: ----------------------------------------------------------------------
[12:08:53.506] INFO: Expecting 768 events.
[12:08:54.640] INFO: 768 events read in total (419ms).
[12:08:54.640] INFO: Test took 1283ms.
[12:08:55.443] INFO: Expecting 41600 events.
[12:08:58.561] INFO: 41600 events read in total (2591ms).
[12:08:58.562] INFO: Test took 3915ms.
[12:08:58.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:59.320] INFO: Expecting 41600 events.
[12:09:02.560] INFO: 41600 events read in total (2713ms).
[12:09:02.561] INFO: Test took 3940ms.
[12:09:02.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:03.314] INFO: Expecting 41600 events.
[12:09:06.616] INFO: 41600 events read in total (2775ms).
[12:09:06.617] INFO: Test took 3996ms.
[12:09:06.658] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:07.368] INFO: Expecting 41600 events.
[12:09:10.661] INFO: 41600 events read in total (2766ms).
[12:09:10.662] INFO: Test took 3984ms.
[12:09:10.702] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:11.415] INFO: Expecting 41600 events.
[12:09:14.708] INFO: 41600 events read in total (2766ms).
[12:09:14.709] INFO: Test took 3986ms.
[12:09:14.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:15.464] INFO: Expecting 41600 events.
[12:09:18.761] INFO: 41600 events read in total (2770ms).
[12:09:18.762] INFO: Test took 3993ms.
[12:09:18.802] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:19.515] INFO: Expecting 41600 events.
[12:09:22.829] INFO: 41600 events read in total (2788ms).
[12:09:22.830] INFO: Test took 4009ms.
[12:09:22.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:23.582] INFO: Expecting 41600 events.
[12:09:26.883] INFO: 41600 events read in total (2774ms).
[12:09:26.884] INFO: Test took 3993ms.
[12:09:26.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:27.634] INFO: Expecting 41600 events.
[12:09:30.942] INFO: 41600 events read in total (2781ms).
[12:09:30.943] INFO: Test took 3998ms.
[12:09:30.983] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:31.696] INFO: Expecting 41600 events.
[12:09:35.020] INFO: 41600 events read in total (2797ms).
[12:09:35.021] INFO: Test took 4019ms.
[12:09:35.060] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:35.770] INFO: Expecting 41600 events.
[12:09:39.075] INFO: 41600 events read in total (2778ms).
[12:09:39.076] INFO: Test took 3995ms.
[12:09:39.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:39.826] INFO: Expecting 41600 events.
[12:09:43.108] INFO: 41600 events read in total (2755ms).
[12:09:43.109] INFO: Test took 3973ms.
[12:09:43.149] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:43.859] INFO: Expecting 41600 events.
[12:09:47.166] INFO: 41600 events read in total (2780ms).
[12:09:47.167] INFO: Test took 3999ms.
[12:09:47.207] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:47.922] INFO: Expecting 41600 events.
[12:09:51.224] INFO: 41600 events read in total (2776ms).
[12:09:51.226] INFO: Test took 4000ms.
[12:09:51.266] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:51.980] INFO: Expecting 41600 events.
[12:09:55.268] INFO: 41600 events read in total (2761ms).
[12:09:55.269] INFO: Test took 3982ms.
[12:09:55.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:56.024] INFO: Expecting 41600 events.
[12:09:59.332] INFO: 41600 events read in total (2781ms).
[12:09:59.333] INFO: Test took 4004ms.
[12:09:59.373] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:00.084] INFO: Expecting 41600 events.
[12:10:03.389] INFO: 41600 events read in total (2778ms).
[12:10:03.390] INFO: Test took 3996ms.
[12:10:03.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:04.140] INFO: Expecting 41600 events.
[12:10:07.444] INFO: 41600 events read in total (2777ms).
[12:10:07.445] INFO: Test took 3994ms.
[12:10:07.485] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:08.196] INFO: Expecting 41600 events.
[12:10:11.480] INFO: 41600 events read in total (2757ms).
[12:10:11.481] INFO: Test took 3976ms.
[12:10:11.521] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:12.236] INFO: Expecting 41600 events.
[12:10:15.435] INFO: 41600 events read in total (2672ms).
[12:10:15.436] INFO: Test took 3893ms.
[12:10:15.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:15.826] INFO: enter test to run
[12:10:36.443] INFO: test: HighRate no parameter change
[12:10:36.443] INFO: running: highrate
[12:10:36.444] INFO: ----------------------------------------------------------------------
[12:10:36.444] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:10:36.444] INFO: ----------------------------------------------------------------------
[12:10:37.060] INFO: Expecting 208000 events.
[12:10:49.440] INFO: 208000 events read in total (11853ms).
[12:10:49.443] INFO: Test took 12990ms.
[12:10:49.621] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:49.884] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:10:49.884] INFO: number of red-efficiency pixels: 100 79 120 163 152 189 172 137 117 161 135 147 136 58 20 46
[12:10:49.884] INFO: number of X-ray hits detected: 82491 55949 83996 129435 143220 140165 135429 101423 100042 122592 119636 102895 108291 62643 24370 27858
[12:10:49.884] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:10:49.884] INFO: number of Vcal hits detected: 207899 207919 207875 207831 207816 207803 207826 207862 207878 207834 207861 207853 207861 207941 207980 207954
[12:10:49.884] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 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 100.0
[12:10:49.884] INFO: Vcal hit overall efficiency (%): 100.0 100.0 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 100.0
[12:10:49.884] INFO: X-ray hit rate [MHz/cm2]: 24.2 16.4 24.6 37.9 42.0 41.1 39.7 29.7 29.3 35.9 35.1 30.2 31.7 18.4 7.1 8.2
[12:10:49.884] INFO: PixTestHighRate::doXPixelAlive() done
[12:10:49.930] INFO: PixTest:: pg_setup set to default.
[12:10:49.947] INFO: enter test to run
[12:11:06.835] INFO: test: HighRate no parameter change
[12:11:06.835] INFO: running: highrate
[12:11:06.836] INFO: ----------------------------------------------------------------------
[12:11:06.836] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:11:06.836] INFO: ----------------------------------------------------------------------
[12:11:07.458] INFO: Expecting 208000 events.
[12:11:22.073] INFO: 208000 events read in total (14088ms).
[12:11:22.079] INFO: Test took 15234ms.
[12:11:22.440] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:22.761] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:11:22.761] INFO: number of red-efficiency pixels: 303 211 367 691 610 717 751 377 385 632 477 454 388 256 56 71
[12:11:22.761] INFO: number of X-ray hits detected: 170282 116641 174230 270489 292373 290628 281580 210312 207546 252872 250024 214526 225333 130249 50654 57935
[12:11:22.761] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:11:22.761] INFO: number of Vcal hits detected: 207673 207777 207591 207221 207282 207172 207146 207588 207578 207304 207474 207503 207586 207724 207943 207928
[12:11:22.761] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.6 99.6 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[12:11:22.762] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.6 99.7 99.6 99.6 99.8 99.8 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[12:11:22.762] INFO: X-ray hit rate [MHz/cm2]: 49.9 34.2 51.1 79.3 85.7 85.2 82.5 61.6 60.8 74.1 73.3 62.9 66.0 38.2 14.8 17.0
[12:11:22.762] INFO: PixTestHighRate::doXPixelAlive() done
[12:11:22.810] INFO: PixTest:: pg_setup set to default.
[12:11:22.827] INFO: enter test to run
[12:11:33.763] INFO: test: HighRate no parameter change
[12:11:33.763] INFO: running: highrate
[12:11:33.764] INFO: ----------------------------------------------------------------------
[12:11:33.764] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:11:33.764] INFO: ----------------------------------------------------------------------
[12:11:34.384] INFO: Expecting 208000 events.
[12:11:51.564] INFO: 208000 events read in total (16653ms).
[12:11:51.573] INFO: Test took 17799ms.
[12:11:52.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:52.510] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:11:52.510] INFO: number of red-efficiency pixels: 653 476 791 1693 1553 1672 1872 947 886 1594 1164 1149 944 573 77 100
[12:11:52.510] INFO: number of X-ray hits detected: 258264 176819 266331 409107 443504 442853 427586 319943 316284 384806 378767 325482 343939 199454 77414 88757
[12:11:52.510] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:11:52.510] INFO: number of Vcal hits detected: 207151 207434 206844 205570 205814 205543 205157 206747 206867 205798 206503 206514 206855 207287 207919 207898
[12:11:52.510] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.5 98.9 99.0 99.0 98.8 99.4 99.5 99.0 99.3 99.4 99.5 99.7 100.0 100.0
[12:11:52.510] INFO: Vcal hit overall efficiency (%): 99.6 99.7 99.4 98.8 98.9 98.8 98.6 99.4 99.5 98.9 99.3 99.3 99.4 99.7 100.0 100.0
[12:11:52.510] INFO: X-ray hit rate [MHz/cm2]: 75.7 51.8 78.1 119.9 130.0 129.8 125.3 93.8 92.7 112.8 111.0 95.4 100.8 58.5 22.7 26.0
[12:11:52.510] INFO: PixTestHighRate::doXPixelAlive() done
[12:11:52.556] INFO: PixTest:: pg_setup set to default.
[12:11:52.576] INFO: enter test to run
[12:11:54.234] INFO: test: exit no parameter change
[12:11:54.534] QUIET: Connection to board 33 closed.
[12:11:54.535] INFO: pXar: this is the end, my friend