[13:31:04.238] INFO: *** Welcome to pxar ***
[13:31:04.238] INFO: *** Today: 2016/06/27
[13:31:05.094] INFO: *** Version: v1.9.0-814-g7497
[13:31:05.094] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//dacParameters35_C15.dat
[13:31:05.128] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:31:05.128] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//defaultMaskFile.dat
[13:31:05.128] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C15.dat
[13:31:05.222] INFO: clk: 4
[13:31:05.222] INFO: ctr: 4
[13:31:05.222] INFO: sda: 19
[13:31:05.222] INFO: tin: 9
[13:31:05.222] INFO: level: 15
[13:31:05.222] INFO: triggerdelay: 0
[13:31:05.222] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:31:05.222] INFO: Log level: INFO
[13:31:05.238] QUIET: Connection to board DTB_WREK4U opened.
[13:31:05.241] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[13:31:05.244] INFO: RPC call hashes of host and DTB match: 398089610
[13:31:06.784] INFO: DUT info:
[13:31:06.784] INFO: The DUT currently contains the following objects:
[13:31:06.784] INFO: 2 TBM Cores tbm08c (2 ON)
[13:31:06.784] INFO: TBM Core alpha (0): 7 registers set
[13:31:06.784] INFO: TBM Core beta (1): 7 registers set
[13:31:06.784] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:31:06.785] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:06.785] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:31:07.224] INFO: enter 'restricted' command line mode
[13:31:07.224] INFO: enter test to run
[13:31:12.727] INFO: test: PixelAlive no parameter change
[13:31:12.727] INFO: running: pixelalive
[13:31:12.752] INFO: ----------------------------------------------------------------------
[13:31:12.752] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:31:12.752] INFO: ----------------------------------------------------------------------
[13:31:13.077] INFO: Expecting 41600 events.
[13:31:17.462] INFO: 41600 events read in total (3667ms).
[13:31:17.627] INFO: Test took 4872ms.
[13:31:17.634] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:17.919] INFO: PixTestAlive::aliveTest() done
[13:31:17.919] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 2 0 0 0 0 0
[13:31:17.950] INFO: enter test to run
[13:31:47.951] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:31:47.951] INFO: running: highrate
[13:31:47.951] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:31:48.349] INFO: ----------------------------------------------------------------------
[13:31:48.349] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:31:48.349] INFO: ----------------------------------------------------------------------
[13:31:48.349] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:31:48.349] INFO: edge/corner pixel THR is adjusted
[13:31:48.349] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:31:49.307] INFO: Collecting data for 5 seconds...
[13:31:54.327] INFO: Done with hot pixel readout
[13:32:06.247] INFO: PixTest:: pg_setup set to default.
[13:32:06.248] INFO: 26 hot pixels found in step 0
[13:32:07.259] INFO: Collecting data for 5 seconds...
[13:32:12.275] INFO: Done with hot pixel readout
[13:32:24.030] INFO: PixTest:: pg_setup set to default.
[13:32:24.031] INFO: 23 hot pixels found in step 1
[13:32:25.020] INFO: Collecting data for 5 seconds...
[13:32:30.036] INFO: Done with hot pixel readout
[13:32:41.773] INFO: PixTest:: pg_setup set to default.
[13:32:41.773] INFO: 28 hot pixels found in step 2
[13:32:42.761] INFO: Collecting data for 5 seconds...
[13:32:47.779] INFO: Done with hot pixel readout
[13:32:59.545] INFO: PixTest:: pg_setup set to default.
[13:32:59.546] INFO: 25 hot pixels found in step 3
[13:33:00.533] INFO: Collecting data for 5 seconds...
[13:33:05.549] INFO: Done with hot pixel readout
[13:33:17.314] INFO: PixTest:: pg_setup set to default.
[13:33:17.314] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:33:17.315] INFO: 22 hot pixels found in step 4
[13:33:18.303] INFO: Collecting data for 5 seconds...
[13:33:23.320] INFO: Done with hot pixel readout
[13:33:35.027] INFO: PixTest:: pg_setup set to default.
[13:33:35.027] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:33:35.028] INFO: 18 hot pixels found in step 5
[13:33:36.016] INFO: Collecting data for 5 seconds...
[13:33:41.033] INFO: Done with hot pixel readout
[13:33:52.441] INFO: PixTest:: pg_setup set to default.
[13:33:52.441] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:33:52.442] INFO: 19 hot pixels found in step 6
[13:33:53.431] INFO: Collecting data for 5 seconds...
[13:33:58.448] INFO: Done with hot pixel readout
[13:34:10.213] INFO: PixTest:: pg_setup set to default.
[13:34:10.213] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:34:10.214] INFO: 13 hot pixels found in step 7
[13:34:11.203] INFO: Collecting data for 5 seconds...
[13:34:16.220] INFO: Done with hot pixel readout
[13:34:27.973] INFO: PixTest:: pg_setup set to default.
[13:34:27.973] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:34:27.974] INFO: 18 hot pixels found in step 8
[13:34:28.964] INFO: Collecting data for 5 seconds...
[13:34:33.980] INFO: Done with hot pixel readout
[13:34:45.672] INFO: PixTest:: pg_setup set to default.
[13:34:45.672] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:34:45.673] INFO: 11 hot pixels found in step 9
[13:34:46.664] INFO: Collecting data for 5 seconds...
[13:34:51.680] INFO: Done with hot pixel readout
[13:35:03.475] INFO: PixTest:: pg_setup set to default.
[13:35:03.475] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:03.476] INFO: 16 hot pixels found in step 10
[13:35:04.464] INFO: Collecting data for 5 seconds...
[13:35:09.481] INFO: Done with hot pixel readout
[13:35:21.241] INFO: PixTest:: pg_setup set to default.
[13:35:21.241] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:21.242] INFO: 12 hot pixels found in step 11
[13:35:22.230] INFO: Collecting data for 5 seconds...
[13:35:27.247] INFO: Done with hot pixel readout
[13:35:39.012] INFO: PixTest:: pg_setup set to default.
[13:35:39.013] INFO: 7 hot pixels found in step 12
[13:35:40.002] INFO: Collecting data for 5 seconds...
[13:35:45.018] INFO: Done with hot pixel readout
[13:35:56.835] INFO: PixTest:: pg_setup set to default.
[13:35:56.835] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:35:56.836] INFO: 12 hot pixels found in step 13
[13:35:57.824] INFO: Collecting data for 5 seconds...
[13:36:02.840] INFO: Done with hot pixel readout
[13:36:14.594] INFO: PixTest:: pg_setup set to default.
[13:36:14.594] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:36:14.595] INFO: 7 hot pixels found in step 14
[13:36:14.627] INFO: 7 hot pixels could not be trimmed and have been masked.
[13:36:14.631] INFO: PixTest::trimHotPixels() done
[13:36:14.633] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C0.dat
[13:36:14.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C1.dat
[13:36:14.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C2.dat
[13:36:14.650] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C3.dat
[13:36:14.655] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C4.dat
[13:36:14.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C5.dat
[13:36:14.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C6.dat
[13:36:14.670] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C7.dat
[13:36:14.676] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C8.dat
[13:36:14.681] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C9.dat
[13:36:14.686] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C10.dat
[13:36:14.691] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C11.dat
[13:36:14.696] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C12.dat
[13:36:14.702] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C13.dat
[13:36:14.707] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C14.dat
[13:36:14.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C15.dat
[13:36:14.717] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//defaultMaskFile.dat
[13:36:14.727] INFO: enter test to run
[13:36:53.221] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:36:53.221] INFO: running: highrate
[13:36:53.226] INFO: ----------------------------------------------------------------------
[13:36:53.226] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:36:53.226] INFO: ----------------------------------------------------------------------
[13:36:53.226] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:36:53.226] INFO: edge/corner pixel THR is adjusted
[13:36:53.226] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:36:54.187] INFO: Collecting data for 1 seconds...
[13:36:55.191] INFO: Done with hot pixel readout
[13:36:59.162] INFO: PixTest:: pg_setup set to default.
[13:36:59.163] INFO: 0 hot pixels found in step 0
[13:36:59.168] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:36:59.259] INFO: PixTest::trimHotPixels() done
[13:36:59.260] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C0.dat
[13:36:59.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C1.dat
[13:36:59.276] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C2.dat
[13:36:59.281] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C3.dat
[13:36:59.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C4.dat
[13:36:59.292] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C5.dat
[13:36:59.297] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C6.dat
[13:36:59.302] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C7.dat
[13:36:59.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C8.dat
[13:36:59.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C9.dat
[13:36:59.318] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C10.dat
[13:36:59.323] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C11.dat
[13:36:59.328] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C12.dat
[13:36:59.334] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C13.dat
[13:36:59.339] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C14.dat
[13:36:59.344] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//trimParameters35_C15.dat
[13:36:59.349] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-08_FPIXTest-17C-FNAL-160620-1539_2016-06-20_15h39m_1466455149/000_FPIXTest_p17//defaultMaskFile.dat
[13:36:59.366] INFO: enter test to run
[13:37:34.021] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:37:34.021] INFO: running: xray
[13:37:34.022] INFO: ----------------------------------------------------------------------
[13:37:34.022] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:37:34.022] INFO: ----------------------------------------------------------------------
[13:37:34.986] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:37:46.471] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:38:15.989] INFO: Resuming triggers.
[13:38:27.474] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:38:57.064] INFO: Resuming triggers.
[13:39:08.548] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:39:37.981] INFO: Resuming triggers.
[13:39:49.466] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:40:19.340] INFO: Resuming triggers.
[13:40:30.823] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:40:59.752] INFO: Resuming triggers.
[13:41:11.237] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:41:40.910] INFO: Resuming triggers.
[13:41:52.401] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:42:22.428] INFO: Resuming triggers.
[13:42:33.919] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:43:03.921] INFO: Resuming triggers.
[13:43:12.386] INFO: data taking finished, elapsed time: 100 seconds.
[13:43:34.678] INFO: PixTest:: pg_setup set to default.
[13:43:34.682] INFO: PixTestXray::doPhRun() done
[13:43:34.818] INFO: enter test to run
[13:45:19.457] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:45:19.457] INFO: running: xray
[13:45:19.459] INFO: ----------------------------------------------------------------------
[13:45:19.459] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:45:19.459] INFO: ----------------------------------------------------------------------
[13:45:20.422] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:45:27.233] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:45:57.464] INFO: Resuming triggers.
[13:46:04.272] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:46:34.502] INFO: Resuming triggers.
[13:46:41.314] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:47:11.583] INFO: Resuming triggers.
[13:47:18.392] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:47:48.703] INFO: Resuming triggers.
[13:47:55.516] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:48:25.821] INFO: Resuming triggers.
[13:48:32.630] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[13:49:02.754] INFO: Resuming triggers.
[13:49:09.567] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:49:39.870] INFO: Resuming triggers.
[13:49:46.682] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:50:16.995] INFO: Resuming triggers.
[13:50:23.805] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:50:53.838] INFO: Resuming triggers.
[13:51:00.650] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:51:30.946] INFO: Resuming triggers.
[13:51:37.758] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:52:08.729] INFO: Resuming triggers.
[13:52:15.541] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:52:46.349] INFO: Resuming triggers.
[13:52:53.159] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[13:53:24.055] INFO: Resuming triggers.
[13:53:30.867] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[13:54:02.400] INFO: Resuming triggers.
[13:54:07.388] INFO: data taking finished, elapsed time: 100 seconds.
[13:54:30.415] INFO: PixTest:: pg_setup set to default.
[13:54:30.418] INFO: PixTestXray::doPhRun() done
[13:54:30.569] INFO: enter test to run
[13:55:46.685] INFO: test: HighRate no parameter change
[13:55:46.685] INFO: running: highrate
[13:55:46.700] INFO: ----------------------------------------------------------------------
[13:55:46.700] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:55:46.700] INFO: ----------------------------------------------------------------------
[13:55:46.856] INFO: Expecting 768 events.
[13:55:47.989] INFO: 768 events read in total (418ms).
[13:55:47.990] INFO: Test took 1268ms.
[13:55:48.793] INFO: Expecting 41600 events.
[13:55:51.882] INFO: 41600 events read in total (2562ms).
[13:55:51.883] INFO: Test took 3866ms.
[13:55:51.916] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:52.643] INFO: Expecting 41600 events.
[13:55:55.789] INFO: 41600 events read in total (2619ms).
[13:55:55.790] INFO: Test took 3857ms.
[13:55:55.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:56.551] INFO: Expecting 41600 events.
[13:55:59.734] INFO: 41600 events read in total (2657ms).
[13:55:59.735] INFO: Test took 3892ms.
[13:55:59.769] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:00.490] INFO: Expecting 41600 events.
[13:56:03.708] INFO: 41600 events read in total (2691ms).
[13:56:03.709] INFO: Test took 3923ms.
[13:56:03.743] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:04.466] INFO: Expecting 41600 events.
[13:56:07.693] INFO: 41600 events read in total (2700ms).
[13:56:07.694] INFO: Test took 3933ms.
[13:56:07.738] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:08.453] INFO: Expecting 41600 events.
[13:56:11.687] INFO: 41600 events read in total (2707ms).
[13:56:11.688] INFO: Test took 3931ms.
[13:56:11.722] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:12.446] INFO: Expecting 41600 events.
[13:56:15.695] INFO: 41600 events read in total (2722ms).
[13:56:15.696] INFO: Test took 3955ms.
[13:56:15.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:16.450] INFO: Expecting 41600 events.
[13:56:19.682] INFO: 41600 events read in total (2706ms).
[13:56:19.683] INFO: Test took 3934ms.
[13:56:19.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:20.442] INFO: Expecting 41600 events.
[13:56:23.674] INFO: 41600 events read in total (2705ms).
[13:56:23.675] INFO: Test took 3941ms.
[13:56:23.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:24.431] INFO: Expecting 41600 events.
[13:56:27.675] INFO: 41600 events read in total (2717ms).
[13:56:27.676] INFO: Test took 3947ms.
[13:56:27.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:28.436] INFO: Expecting 41600 events.
[13:56:31.667] INFO: 41600 events read in total (2705ms).
[13:56:31.668] INFO: Test took 3940ms.
[13:56:31.702] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:32.426] INFO: Expecting 41600 events.
[13:56:35.676] INFO: 41600 events read in total (2723ms).
[13:56:35.677] INFO: Test took 3956ms.
[13:56:35.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:36.435] INFO: Expecting 41600 events.
[13:56:39.673] INFO: 41600 events read in total (2712ms).
[13:56:39.674] INFO: Test took 3945ms.
[13:56:39.708] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:40.433] INFO: Expecting 41600 events.
[13:56:43.656] INFO: 41600 events read in total (2696ms).
[13:56:43.657] INFO: Test took 3931ms.
[13:56:43.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:44.416] INFO: Expecting 41600 events.
[13:56:47.667] INFO: 41600 events read in total (2724ms).
[13:56:47.668] INFO: Test took 3959ms.
[13:56:47.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:48.429] INFO: Expecting 41600 events.
[13:56:51.686] INFO: 41600 events read in total (2731ms).
[13:56:51.688] INFO: Test took 3968ms.
[13:56:51.722] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:52.447] INFO: Expecting 41600 events.
[13:56:55.704] INFO: 41600 events read in total (2730ms).
[13:56:55.705] INFO: Test took 3965ms.
[13:56:55.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:56.463] INFO: Expecting 41600 events.
[13:56:59.711] INFO: 41600 events read in total (2721ms).
[13:56:59.712] INFO: Test took 3953ms.
[13:56:59.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:00.470] INFO: Expecting 41600 events.
[13:57:03.674] INFO: 41600 events read in total (2677ms).
[13:57:03.675] INFO: Test took 3912ms.
[13:57:03.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:04.436] INFO: Expecting 41600 events.
[13:57:07.506] INFO: 41600 events read in total (2544ms).
[13:57:07.507] INFO: Test took 3782ms.
[13:57:07.539] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:07.898] INFO: enter test to run
[13:57:16.365] INFO: test: HighRate no parameter change
[13:57:16.365] INFO: running: highrate
[13:57:16.366] INFO: ----------------------------------------------------------------------
[13:57:16.366] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:57:16.366] INFO: ----------------------------------------------------------------------
[13:57:16.977] INFO: Expecting 208000 events.
[13:57:28.823] INFO: 208000 events read in total (11319ms).
[13:57:28.826] INFO: Test took 12452ms.
[13:57:28.969] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:29.220] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 2 0 0 0 0 0
[13:57:29.220] INFO: number of red-efficiency pixels: 80 31 83 134 145 157 148 74 76 115 122 75 84 62 28 28
[13:57:29.220] INFO: number of X-ray hits detected: 65127 42490 68087 106059 117356 119963 111496 84337 74124 98457 93345 82988 84633 52761 21008 24683
[13:57:29.220] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:57:29.220] INFO: number of Vcal hits detected: 207917 207969 207916 207863 207853 207841 207752 207924 207920 207882 207779 207923 207913 207933 207972 207972
[13:57:29.220] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[13:57:29.220] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[13:57:29.220] INFO: X-ray hit rate [MHz/cm2]: 19.1 12.5 20.0 31.1 34.4 35.2 32.7 24.7 21.7 28.9 27.4 24.3 24.8 15.5 6.2 7.2
[13:57:29.221] INFO: PixTestHighRate::doXPixelAlive() done
[13:57:29.271] INFO: PixTest:: pg_setup set to default.
[13:57:29.288] INFO: enter test to run
[13:57:47.196] INFO: test: HighRate no parameter change
[13:57:47.196] INFO: running: highrate
[13:57:47.198] INFO: ----------------------------------------------------------------------
[13:57:47.198] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:57:47.198] INFO: ----------------------------------------------------------------------
[13:57:47.814] INFO: Expecting 208000 events.
[13:58:01.375] INFO: 208000 events read in total (13034ms).
[13:58:01.380] INFO: Test took 14171ms.
[13:58:01.665] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:01.963] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 2 0 0 0 0 0
[13:58:01.963] INFO: number of red-efficiency pixels: 199 99 273 443 522 549 490 252 219 362 368 208 304 207 58 57
[13:58:01.963] INFO: number of X-ray hits detected: 133164 85810 139656 214211 237460 243341 226543 171291 151790 199845 190091 168971 172282 107521 42737 50183
[13:58:01.963] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:58:01.963] INFO: number of Vcal hits detected: 207784 207897 207698 207524 207432 207382 207377 207736 207771 207616 207514 207785 207682 207775 207942 207942
[13:58:01.963] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.7 99.7 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[13:58:01.963] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.7 99.7 99.7 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[13:58:01.963] INFO: X-ray hit rate [MHz/cm2]: 39.0 25.2 40.9 62.8 69.6 71.3 66.4 50.2 44.5 58.6 55.7 49.5 50.5 31.5 12.5 14.7
[13:58:01.963] INFO: PixTestHighRate::doXPixelAlive() done
[13:58:02.013] INFO: PixTest:: pg_setup set to default.
[13:58:02.024] INFO: enter test to run
[13:58:25.244] INFO: test: HighRate no parameter change
[13:58:25.244] INFO: running: highrate
[13:58:25.245] INFO: ----------------------------------------------------------------------
[13:58:25.245] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:58:25.245] INFO: ----------------------------------------------------------------------
[13:58:25.874] INFO: Expecting 208000 events.
[13:58:41.131] INFO: 208000 events read in total (14730ms).
[13:58:41.139] INFO: Test took 15883ms.
[13:58:41.578] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:41.928] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 2 0 0 0 0 0
[13:58:41.928] INFO: number of red-efficiency pixels: 407 179 634 1042 1152 1413 1180 576 459 766 856 520 646 424 75 108
[13:58:41.928] INFO: number of X-ray hits detected: 198506 129245 207458 321046 355444 363520 338080 256229 226591 299037 282963 253815 259404 161011 64308 75235
[13:58:41.928] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:58:41.928] INFO: number of Vcal hits detected: 207512 207807 207157 206713 206549 206072 206345 207322 207486 207093 206897 207442 207271 207514 207924 207889
[13:58:41.928] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.4 99.2 99.3 99.7 99.8 99.6 99.6 99.8 99.7 99.8 100.0 99.9
[13:58:41.928] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.4 99.3 99.1 99.2 99.7 99.8 99.6 99.5 99.7 99.6 99.8 100.0 99.9
[13:58:41.928] INFO: X-ray hit rate [MHz/cm2]: 58.2 37.9 60.8 94.1 104.2 106.6 99.1 75.1 66.4 87.6 82.9 74.4 76.0 47.2 18.8 22.1
[13:58:41.928] INFO: PixTestHighRate::doXPixelAlive() done
[13:58:41.975] INFO: PixTest:: pg_setup set to default.
[13:58:41.992] INFO: enter test to run
[13:58:50.444] INFO: test: exit no parameter change
[13:58:50.752] QUIET: Connection to board 32 closed.
[13:58:50.753] INFO: pXar: this is the end, my friend