[12:02:44.909] INFO: *** Welcome to pxar ***
[12:02:44.909] INFO: *** Today: 2016/06/27
[12:02:44.926] INFO: *** Version: v1.9.0-814-g7497
[12:02:44.926] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//dacParameters35_C15.dat
[12:02:44.927] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:02:44.927] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//defaultMaskFile.dat
[12:02:44.927] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C15.dat
[12:02:45.002] INFO: clk: 4
[12:02:45.002] INFO: ctr: 4
[12:02:45.002] INFO: sda: 19
[12:02:45.002] INFO: tin: 9
[12:02:45.002] INFO: level: 15
[12:02:45.002] INFO: triggerdelay: 0
[12:02:45.002] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:02:45.002] INFO: Log level: INFO
[12:02:45.019] QUIET: Connection to board DTB_WREK4U opened.
[12:02:45.023] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[12:02:45.026] INFO: RPC call hashes of host and DTB match: 398089610
[12:02:46.562] INFO: DUT info:
[12:02:46.562] INFO: The DUT currently contains the following objects:
[12:02:46.562] INFO: 2 TBM Cores tbm08c (2 ON)
[12:02:46.562] INFO: TBM Core alpha (0): 7 registers set
[12:02:46.562] INFO: TBM Core beta (1): 7 registers set
[12:02:46.562] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:02:46.562] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.562] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.562] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.562] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.562] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.563] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:02:46.966] INFO: enter 'restricted' command line mode
[12:02:46.966] INFO: enter test to run
[12:02:53.131] INFO: test: PixelAlive no parameter change
[12:02:53.131] INFO: running: pixelalive
[12:02:53.140] INFO: ----------------------------------------------------------------------
[12:02:53.140] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:02:53.140] INFO: ----------------------------------------------------------------------
[12:02:53.459] INFO: Expecting 41600 events.
[12:02:57.676] INFO: 41600 events read in total (3498ms).
[12:02:57.845] INFO: Test took 4702ms.
[12:02:57.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:58.428] INFO: PixTestAlive::aliveTest() done
[12:02:58.428] INFO: number of dead pixels (per ROC): 0 0 0 0 0 2 0 0 0 0 1 0 0 0 0 0
[12:02:58.654] INFO: enter test to run
[12:03:30.883] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:03:30.883] INFO: running: highrate
[12:03:30.893] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:03:31.183] INFO: ----------------------------------------------------------------------
[12:03:31.183] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:03:31.183] INFO: ----------------------------------------------------------------------
[12:03:31.183] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:03:31.183] INFO: edge/corner pixel THR is adjusted
[12:03:31.183] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:03:32.143] INFO: Collecting data for 5 seconds...
[12:03:37.159] INFO: Done with hot pixel readout
[12:03:48.289] INFO: PixTest:: pg_setup set to default.
[12:03:48.290] INFO: 12 hot pixels found in step 0
[12:03:49.302] INFO: Collecting data for 5 seconds...
[12:03:54.318] INFO: Done with hot pixel readout
[12:04:05.783] INFO: PixTest:: pg_setup set to default.
[12:04:05.784] INFO: 18 hot pixels found in step 1
[12:04:06.782] INFO: Collecting data for 5 seconds...
[12:04:11.799] INFO: Done with hot pixel readout
[12:04:22.906] INFO: PixTest:: pg_setup set to default.
[12:04:22.906] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:04:22.906] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:04:22.907] INFO: 17 hot pixels found in step 2
[12:04:23.898] INFO: Collecting data for 5 seconds...
[12:04:28.915] INFO: Done with hot pixel readout
[12:04:39.847] INFO: PixTest:: pg_setup set to default.
[12:04:39.847] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:04:39.847] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:04:39.848] INFO: 15 hot pixels found in step 3
[12:04:40.840] INFO: Collecting data for 5 seconds...
[12:04:45.856] INFO: Done with hot pixel readout
[12:04:57.094] INFO: PixTest:: pg_setup set to default.
[12:04:57.094] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:04:57.095] INFO: 15 hot pixels found in step 4
[12:04:58.086] INFO: Collecting data for 5 seconds...
[12:05:03.102] INFO: Done with hot pixel readout
[12:05:14.279] INFO: PixTest:: pg_setup set to default.
[12:05:14.279] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:05:14.280] INFO: 10 hot pixels found in step 5
[12:05:15.272] INFO: Collecting data for 5 seconds...
[12:05:20.292] INFO: Done with hot pixel readout
[12:05:32.120] INFO: PixTest:: pg_setup set to default.
[12:05:32.120] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:05:32.120] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:05:32.121] INFO: 9 hot pixels found in step 6
[12:05:33.112] INFO: Collecting data for 5 seconds...
[12:05:38.131] INFO: Done with hot pixel readout
[12:05:49.870] INFO: PixTest:: pg_setup set to default.
[12:05:49.870] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:05:49.871] INFO: 3 hot pixels found in step 7
[12:05:50.863] INFO: Collecting data for 5 seconds...
[12:05:55.881] INFO: Done with hot pixel readout
[12:06:07.406] INFO: PixTest:: pg_setup set to default.
[12:06:07.406] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:07.407] INFO: 7 hot pixels found in step 8
[12:06:08.399] INFO: Collecting data for 5 seconds...
[12:06:13.420] INFO: Done with hot pixel readout
[12:06:24.296] INFO: PixTest:: pg_setup set to default.
[12:06:24.296] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:24.296] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:24.297] INFO: 9 hot pixels found in step 9
[12:06:25.294] INFO: Collecting data for 5 seconds...
[12:06:30.311] INFO: Done with hot pixel readout
[12:06:41.425] INFO: PixTest:: pg_setup set to default.
[12:06:41.425] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:41.426] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:41.426] INFO: 6 hot pixels found in step 10
[12:06:42.418] INFO: Collecting data for 5 seconds...
[12:06:47.435] INFO: Done with hot pixel readout
[12:06:59.102] INFO: PixTest:: pg_setup set to default.
[12:06:59.102] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:06:59.103] INFO: 4 hot pixels found in step 11
[12:07:00.095] INFO: Collecting data for 5 seconds...
[12:07:05.113] INFO: Done with hot pixel readout
[12:07:16.645] INFO: PixTest:: pg_setup set to default.
[12:07:16.645] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:07:16.646] INFO: 2 hot pixels found in step 12
[12:07:17.639] INFO: Collecting data for 5 seconds...
[12:07:22.658] INFO: Done with hot pixel readout
[12:07:34.218] INFO: PixTest:: pg_setup set to default.
[12:07:34.218] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:07:34.219] INFO: 3 hot pixels found in step 13
[12:07:35.211] INFO: Collecting data for 5 seconds...
[12:07:40.231] INFO: Done with hot pixel readout
[12:07:51.867] INFO: PixTest:: pg_setup set to default.
[12:07:51.867] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:07:51.868] INFO: 3 hot pixels found in step 14
[12:07:51.912] INFO: 3 hot pixels could not be trimmed and have been masked.
[12:07:51.923] INFO: PixTest::trimHotPixels() done
[12:07:51.981] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C0.dat
[12:07:51.987] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C1.dat
[12:07:51.993] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C2.dat
[12:07:51.999] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C3.dat
[12:07:52.004] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C4.dat
[12:07:52.010] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C5.dat
[12:07:52.016] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C6.dat
[12:07:52.022] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C7.dat
[12:07:52.027] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C8.dat
[12:07:52.033] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C9.dat
[12:07:52.038] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C10.dat
[12:07:52.044] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C11.dat
[12:07:52.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C12.dat
[12:07:52.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C13.dat
[12:07:52.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C14.dat
[12:07:52.066] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C15.dat
[12:07:52.071] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//defaultMaskFile.dat
[12:07:52.081] INFO: enter test to run
[12:09:23.136] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200\<-
[12:09:23.136] INFO: running: highrate
[12:09:23.141] INFO: ----------------------------------------------------------------------
[12:09:23.141] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:09:23.141] INFO: ----------------------------------------------------------------------
[12:09:23.141] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:09:23.141] INFO: edge/corner pixel THR is adjusted
[12:09:23.141] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:09:24.099] INFO: Collecting data for 1 seconds...
[12:09:25.103] INFO: Done with hot pixel readout
[12:09:29.040] INFO: PixTest:: pg_setup set to default.
[12:09:29.042] INFO: 0 hot pixels found in step 0
[12:09:29.051] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:09:29.087] INFO: PixTest::trimHotPixels() done
[12:09:29.087] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C0.dat
[12:09:29.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C1.dat
[12:09:29.106] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C2.dat
[12:09:29.111] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C3.dat
[12:09:29.117] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C4.dat
[12:09:29.122] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C5.dat
[12:09:29.127] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C6.dat
[12:09:29.133] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C7.dat
[12:09:29.138] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C8.dat
[12:09:29.144] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C9.dat
[12:09:29.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C10.dat
[12:09:29.154] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C11.dat
[12:09:29.160] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C12.dat
[12:09:29.165] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C13.dat
[12:09:29.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C14.dat
[12:09:29.176] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C15.dat
[12:09:29.181] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-33_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//defaultMaskFile.dat
[12:09:29.191] INFO: enter test to run
[12:09:49.816] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:09:49.816] INFO: running: xray
[12:09:49.816] INFO: ----------------------------------------------------------------------
[12:09:49.816] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:09:49.817] INFO: ----------------------------------------------------------------------
[12:09:50.800] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:10:02.355] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:10:31.631] INFO: Resuming triggers.
[12:10:43.184] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:11:11.698] INFO: Resuming triggers.
[12:11:23.254] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:11:51.625] INFO: Resuming triggers.
[12:12:03.181] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:12:31.539] INFO: Resuming triggers.
[12:12:43.096] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:13:11.839] INFO: Resuming triggers.
[12:13:23.397] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[12:13:51.460] INFO: Resuming triggers.
[12:14:03.013] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:14:30.999] INFO: Resuming triggers.
[12:14:42.554] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[12:15:10.408] INFO: Resuming triggers.
[12:15:18.288] INFO: data taking finished, elapsed time: 100 seconds.
[12:15:38.298] INFO: PixTest:: pg_setup set to default.
[12:15:38.301] INFO: PixTestXray::doPhRun() done
[12:15:38.518] INFO: enter test to run
[12:16:46.429] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:16:46.429] INFO: running: xray
[12:16:46.430] INFO: ----------------------------------------------------------------------
[12:16:46.430] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:16:46.430] INFO: ----------------------------------------------------------------------
[12:16:47.400] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:16:54.260] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:17:25.167] INFO: Resuming triggers.
[12:17:32.025] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:18:03.285] INFO: Resuming triggers.
[12:18:10.145] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:18:41.086] INFO: Resuming triggers.
[12:18:47.943] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[12:19:18.794] INFO: Resuming triggers.
[12:19:25.652] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:19:57.027] INFO: Resuming triggers.
[12:20:03.885] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[12:20:35.095] INFO: Resuming triggers.
[12:20:41.953] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:21:12.172] INFO: Resuming triggers.
[12:21:19.030] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:21:49.275] INFO: Resuming triggers.
[12:21:56.135] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[12:22:26.320] INFO: Resuming triggers.
[12:22:33.179] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:23:03.402] INFO: Resuming triggers.
[12:23:10.264] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[12:23:40.476] INFO: Resuming triggers.
[12:23:47.334] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:24:17.694] INFO: Resuming triggers.
[12:24:24.554] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:24:54.654] INFO: Resuming triggers.
[12:25:01.512] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:25:31.777] INFO: Resuming triggers.
[12:25:36.093] INFO: data taking finished, elapsed time: 100 seconds.
[12:25:55.411] INFO: PixTest:: pg_setup set to default.
[12:25:55.415] INFO: PixTestXray::doPhRun() done
[12:25:55.564] INFO: enter test to run
[12:27:54.665] INFO: test: HighRate no parameter change
[12:27:54.665] INFO: running: highrate
[12:27:54.679] INFO: ----------------------------------------------------------------------
[12:27:54.679] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:27:54.679] INFO: ----------------------------------------------------------------------
[12:27:54.834] INFO: Expecting 768 events.
[12:27:55.968] INFO: 768 events read in total (419ms).
[12:27:55.969] INFO: Test took 1269ms.
[12:27:56.772] INFO: Expecting 41600 events.
[12:27:59.865] INFO: 41600 events read in total (2566ms).
[12:27:59.866] INFO: Test took 3878ms.
[12:27:59.905] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:00.628] INFO: Expecting 41600 events.
[12:28:03.828] INFO: 41600 events read in total (2673ms).
[12:28:03.847] INFO: Test took 3923ms.
[12:28:03.884] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:04.589] INFO: Expecting 41600 events.
[12:28:07.827] INFO: 41600 events read in total (2711ms).
[12:28:07.828] INFO: Test took 3925ms.
[12:28:07.861] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:08.588] INFO: Expecting 41600 events.
[12:28:11.821] INFO: 41600 events read in total (2706ms).
[12:28:11.822] INFO: Test took 3942ms.
[12:28:11.856] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:12.581] INFO: Expecting 41600 events.
[12:28:15.819] INFO: 41600 events read in total (2711ms).
[12:28:15.820] INFO: Test took 3946ms.
[12:28:15.855] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:16.579] INFO: Expecting 41600 events.
[12:28:19.800] INFO: 41600 events read in total (2694ms).
[12:28:19.801] INFO: Test took 3928ms.
[12:28:19.835] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:20.557] INFO: Expecting 41600 events.
[12:28:23.794] INFO: 41600 events read in total (2710ms).
[12:28:23.795] INFO: Test took 3942ms.
[12:28:23.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:24.552] INFO: Expecting 41600 events.
[12:28:27.793] INFO: 41600 events read in total (2715ms).
[12:28:27.794] INFO: Test took 3947ms.
[12:28:27.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:28.554] INFO: Expecting 41600 events.
[12:28:31.800] INFO: 41600 events read in total (2719ms).
[12:28:31.801] INFO: Test took 3955ms.
[12:28:31.835] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:32.560] INFO: Expecting 41600 events.
[12:28:35.807] INFO: 41600 events read in total (2720ms).
[12:28:35.808] INFO: Test took 3956ms.
[12:28:35.843] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:36.564] INFO: Expecting 41600 events.
[12:28:39.806] INFO: 41600 events read in total (2715ms).
[12:28:39.807] INFO: Test took 3946ms.
[12:28:39.840] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:40.567] INFO: Expecting 41600 events.
[12:28:43.810] INFO: 41600 events read in total (2716ms).
[12:28:43.811] INFO: Test took 3952ms.
[12:28:43.845] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:44.567] INFO: Expecting 41600 events.
[12:28:47.807] INFO: 41600 events read in total (2713ms).
[12:28:47.808] INFO: Test took 3944ms.
[12:28:47.842] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:48.566] INFO: Expecting 41600 events.
[12:28:51.875] INFO: 41600 events read in total (2782ms).
[12:28:51.876] INFO: Test took 4015ms.
[12:28:51.910] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:52.630] INFO: Expecting 41600 events.
[12:28:55.936] INFO: 41600 events read in total (2779ms).
[12:28:55.937] INFO: Test took 4008ms.
[12:28:55.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:56.695] INFO: Expecting 41600 events.
[12:28:59.898] INFO: 41600 events read in total (2676ms).
[12:28:59.899] INFO: Test took 3910ms.
[12:28:59.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:00.647] INFO: Expecting 41600 events.
[12:29:03.915] INFO: 41600 events read in total (2741ms).
[12:29:03.915] INFO: Test took 3964ms.
[12:29:03.950] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:04.660] INFO: Expecting 41600 events.
[12:29:07.885] INFO: 41600 events read in total (2698ms).
[12:29:07.886] INFO: Test took 3918ms.
[12:29:07.921] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:08.643] INFO: Expecting 41600 events.
[12:29:11.915] INFO: 41600 events read in total (2745ms).
[12:29:11.916] INFO: Test took 3978ms.
[12:29:11.951] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:12.672] INFO: Expecting 41600 events.
[12:29:15.791] INFO: 41600 events read in total (2592ms).
[12:29:15.793] INFO: Test took 3825ms.
[12:29:15.827] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:16.188] INFO: enter test to run
[12:31:21.599] INFO: test: HighRate no parameter change
[12:31:21.599] INFO: running: highrate
[12:31:21.600] INFO: ----------------------------------------------------------------------
[12:31:21.600] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:31:21.600] INFO: ----------------------------------------------------------------------
[12:31:22.233] INFO: Expecting 208000 events.
[12:31:34.350] INFO: 208000 events read in total (11591ms).
[12:31:34.353] INFO: Test took 12743ms.
[12:31:34.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:34.758] INFO: number of dead pixels (per ROC): 0 0 0 0 0 2 0 0 0 0 1 0 0 0 0 0
[12:31:34.758] INFO: number of red-efficiency pixels: 72 63 84 107 122 163 110 97 84 101 100 91 92 55 18 26
[12:31:34.758] INFO: number of X-ray hits detected: 63638 42978 67639 103057 109408 122989 116410 86663 76365 96623 92753 83594 83922 51097 21263 23966
[12:31:34.758] 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:31:34.758] INFO: number of Vcal hits detected: 207926 207937 207913 207892 207875 207734 207885 207900 207915 207896 207848 207905 207906 207945 207982 207974
[12:31:34.758] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[12:31:34.758] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[12:31:34.758] INFO: X-ray hit rate [MHz/cm2]: 18.7 12.6 19.8 30.2 32.1 36.0 34.1 25.4 22.4 28.3 27.2 24.5 24.6 15.0 6.2 7.0
[12:31:34.758] INFO: PixTestHighRate::doXPixelAlive() done
[12:31:34.807] INFO: PixTest:: pg_setup set to default.
[12:31:34.824] INFO: enter test to run
[12:33:33.662] INFO: test: HighRate no parameter change
[12:33:33.663] INFO: running: highrate
[12:33:33.664] INFO: ----------------------------------------------------------------------
[12:33:33.664] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:33:33.664] INFO: ----------------------------------------------------------------------
[12:33:34.280] INFO: Expecting 208000 events.
[12:33:47.741] INFO: 208000 events read in total (12934ms).
[12:33:47.746] INFO: Test took 14072ms.
[12:33:48.025] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:48.321] INFO: number of dead pixels (per ROC): 0 0 0 0 0 2 0 0 0 0 1 0 0 0 0 0
[12:33:48.321] INFO: number of red-efficiency pixels: 166 89 278 397 363 555 416 322 214 264 255 282 262 147 51 49
[12:33:48.321] INFO: number of X-ray hits detected: 126688 85439 134208 204351 217451 243634 231145 172934 152472 191999 184463 166344 166827 101287 42626 47969
[12:33:48.322] 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:33:48.322] INFO: number of Vcal hits detected: 207827 207909 207696 207583 207609 207287 207556 207652 207778 207725 207684 207707 207725 207848 207948 207951
[12:33:48.322] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.7 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[12:33:48.322] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.7 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[12:33:48.322] INFO: X-ray hit rate [MHz/cm2]: 37.1 25.0 39.3 59.9 63.7 71.4 67.8 50.7 44.7 56.3 54.1 48.8 48.9 29.7 12.5 14.1
[12:33:48.322] INFO: PixTestHighRate::doXPixelAlive() done
[12:33:48.375] INFO: PixTest:: pg_setup set to default.
[12:33:48.388] INFO: enter test to run
[12:34:12.558] INFO: test: HighRate no parameter change
[12:34:12.558] INFO: running: highrate
[12:34:12.559] INFO: ----------------------------------------------------------------------
[12:34:12.559] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:34:12.559] INFO: ----------------------------------------------------------------------
[12:34:13.184] INFO: Expecting 208000 events.
[12:34:27.796] INFO: 208000 events read in total (14085ms).
[12:34:27.803] INFO: Test took 15233ms.
[12:34:28.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:28.576] INFO: number of dead pixels (per ROC): 0 0 0 0 0 2 0 0 0 0 1 0 0 0 0 0
[12:34:28.576] INFO: number of red-efficiency pixels: 396 211 633 974 789 1324 945 765 509 629 603 606 678 300 88 91
[12:34:28.576] INFO: number of X-ray hits detected: 192218 131463 204755 309803 329470 371063 349975 262156 232262 290809 280642 253400 253582 155019 64477 72577
[12:34:28.576] 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:34:28.576] INFO: number of Vcal hits detected: 207555 207778 207177 206828 207086 206136 206825 207044 207435 207287 207300 207318 207234 207668 207911 207906
[12:34:28.576] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.5 99.6 99.2 99.5 99.6 99.7 99.7 99.7 99.7 99.7 99.9 100.0 100.0
[12:34:28.576] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.4 99.6 99.1 99.4 99.5 99.7 99.7 99.7 99.7 99.6 99.8 100.0 100.0
[12:34:28.576] INFO: X-ray hit rate [MHz/cm2]: 56.3 38.5 60.0 90.8 96.6 108.8 102.6 76.8 68.1 85.2 82.3 74.3 74.3 45.4 18.9 21.3
[12:34:28.576] INFO: PixTestHighRate::doXPixelAlive() done
[12:34:28.626] INFO: PixTest:: pg_setup set to default.
[12:34:28.640] INFO: enter test to run
[12:35:20.933] INFO: test: exit no parameter change
[12:35:21.335] QUIET: Connection to board 32 closed.
[12:35:21.347] INFO: pXar: this is the end, my friend