[13:18:39.509] INFO: *** Welcome to pxar ***
[13:18:39.509] INFO: *** Today: 2016/08/29
[13:18:40.398] INFO: *** Version: v1.9.0-818-g96727
[13:18:40.398] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//dacParameters35_C15.dat
[13:18:40.416] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:18:40.416] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//defaultMaskFile.dat
[13:18:40.420] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C15.dat
[13:18:40.527] INFO: clk: 4
[13:18:40.527] INFO: ctr: 4
[13:18:40.527] INFO: sda: 19
[13:18:40.527] INFO: tin: 9
[13:18:40.527] INFO: level: 15
[13:18:40.527] INFO: triggerdelay: 0
[13:18:40.527] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:18:40.527] INFO: Log level: INFO
[13:18:40.543] QUIET: Connection to board DTB_WREKRL opened.
[13:18:40.546] 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:
------------------------------------------------------
[13:18:40.549] INFO: RPC call hashes of host and DTB match: 398089610
[13:18:42.084] INFO: DUT info:
[13:18:42.084] INFO: The DUT currently contains the following objects:
[13:18:42.084] INFO: 2 TBM Cores tbm08c (2 ON)
[13:18:42.084] INFO: TBM Core alpha (0): 7 registers set
[13:18:42.084] INFO: TBM Core beta (1): 7 registers set
[13:18:42.084] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:18:42.084] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.084] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.085] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.085] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.085] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:18:42.488] INFO: enter 'restricted' command line mode
[13:18:42.488] INFO: enter test to run
[13:19:03.609] INFO: test: PixelAlive no parameter change
[13:19:03.609] INFO: running: pixelalive
[13:19:03.632] INFO: ----------------------------------------------------------------------
[13:19:03.632] 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:19:03.632] INFO: ----------------------------------------------------------------------
[13:19:03.959] INFO: Expecting 41600 events.
[13:19:08.161] INFO: 41600 events read in total (3484ms).
[13:19:08.326] INFO: Test took 4686ms.
[13:19:08.335] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:08.599] INFO: PixTestAlive::aliveTest() done
[13:19:08.599] INFO: number of dead pixels (per ROC): 1 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:19:08.629] INFO: enter test to run
[13:19:42.625] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:19:42.625] INFO: running: highrate
[13:19:42.625] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:19:42.879] INFO: ----------------------------------------------------------------------
[13:19:42.879] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:19:42.879] INFO: ----------------------------------------------------------------------
[13:19:42.879] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:19:42.879] INFO: edge/corner pixel THR is adjusted
[13:19:42.879] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:19:43.837] INFO: Collecting data for 5 seconds...
[13:19:48.859] INFO: Done with hot pixel readout
[13:20:00.816] INFO: PixTest:: pg_setup set to default.
[13:20:00.817] INFO: 1 hot pixels found in step 0
[13:20:01.806] INFO: Collecting data for 5 seconds...
[13:20:06.826] INFO: Done with hot pixel readout
[13:20:18.768] INFO: PixTest:: pg_setup set to default.
[13:20:18.769] INFO: 7 hot pixels found in step 1
[13:20:19.763] INFO: Collecting data for 5 seconds...
[13:20:24.781] INFO: Done with hot pixel readout
[13:20:36.719] INFO: PixTest:: pg_setup set to default.
[13:20:36.719] INFO: 2 hot pixels found in step 2
[13:20:37.712] INFO: Collecting data for 5 seconds...
[13:20:42.733] INFO: Done with hot pixel readout
[13:20:54.671] INFO: PixTest:: pg_setup set to default.
[13:20:54.672] INFO: 3 hot pixels found in step 3
[13:20:55.665] INFO: Collecting data for 5 seconds...
[13:21:00.686] INFO: Done with hot pixel readout
[13:21:12.686] INFO: PixTest:: pg_setup set to default.
[13:21:12.687] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:21:12.687] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:21:12.687] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:21:12.687] INFO: 3 hot pixels found in step 4
[13:21:12.724] INFO: 3 hot pixels could not be trimmed and have been masked.
[13:21:12.728] INFO: PixTest::trimHotPixels() done
[13:21:12.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C0.dat
[13:21:12.733] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C1.dat
[13:21:12.739] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C2.dat
[13:21:12.746] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C3.dat
[13:21:12.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C4.dat
[13:21:12.757] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C5.dat
[13:21:12.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C6.dat
[13:21:12.767] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C7.dat
[13:21:12.773] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C8.dat
[13:21:12.778] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C9.dat
[13:21:12.783] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C10.dat
[13:21:12.789] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C11.dat
[13:21:12.794] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C12.dat
[13:21:12.799] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C13.dat
[13:21:12.805] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C14.dat
[13:21:12.810] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C15.dat
[13:21:12.815] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//defaultMaskFile.dat
[13:21:12.843] INFO: enter test to run
[13:21:51.976] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:21:51.976] INFO: running: highrate
[13:21:51.980] INFO: ----------------------------------------------------------------------
[13:21:51.981] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:21:51.981] INFO: ----------------------------------------------------------------------
[13:21:51.981] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:21:51.981] INFO: edge/corner pixel THR is adjusted
[13:21:51.981] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:21:52.939] INFO: Collecting data for 1 seconds...
[13:21:53.942] INFO: Done with hot pixel readout
[13:21:58.060] INFO: PixTest:: pg_setup set to default.
[13:21:58.061] INFO: 0 hot pixels found in step 0
[13:21:58.066] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:21:58.152] INFO: PixTest::trimHotPixels() done
[13:21:58.152] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C0.dat
[13:21:58.164] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C1.dat
[13:21:58.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C2.dat
[13:21:58.176] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C3.dat
[13:21:58.181] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C4.dat
[13:21:58.186] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C5.dat
[13:21:58.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C6.dat
[13:21:58.215] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C7.dat
[13:21:58.226] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C8.dat
[13:21:58.231] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C9.dat
[13:21:58.237] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C10.dat
[13:21:58.242] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C11.dat
[13:21:58.247] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C12.dat
[13:21:58.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C13.dat
[13:21:58.258] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C14.dat
[13:21:58.263] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//trimParameters35_C15.dat
[13:21:58.268] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-25_FPIXTest-17C-FNAL-160816-1258-300V_2016-08-16_12h58m_1471370324/000_FPIXTest_p17//defaultMaskFile.dat
[13:21:58.285] INFO: enter test to run
[13:22:59.856] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:22:59.856] INFO: running: xray
[13:22:59.857] INFO: ----------------------------------------------------------------------
[13:22:59.857] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:22:59.857] INFO: ----------------------------------------------------------------------
[13:23:00.821] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:23:12.235] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:23:41.640] INFO: Resuming triggers.
[13:23:53.063] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:24:22.529] INFO: Resuming triggers.
[13:24:33.951] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:25:03.329] INFO: Resuming triggers.
[13:25:14.753] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:25:44.142] INFO: Resuming triggers.
[13:25:55.562] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:26:24.960] INFO: Resuming triggers.
[13:26:36.381] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:27:05.763] INFO: Resuming triggers.
[13:27:17.187] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:27:46.568] INFO: Resuming triggers.
[13:27:57.989] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:28:27.129] INFO: Resuming triggers.
[13:28:36.084] INFO: data taking finished, elapsed time: 100 seconds.
[13:28:59.239] INFO: PixTest:: pg_setup set to default.
[13:28:59.242] INFO: PixTestXray::doPhRun() done
[13:28:59.379] INFO: enter test to run
[13:29:46.277] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:29:46.277] INFO: running: xray
[13:29:46.278] INFO: ----------------------------------------------------------------------
[13:29:46.278] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:29:46.278] INFO: ----------------------------------------------------------------------
[13:29:47.244] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:29:53.727] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:30:24.711] INFO: Resuming triggers.
[13:30:31.198] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:31:02.246] INFO: Resuming triggers.
[13:31:08.729] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[13:31:39.404] INFO: Resuming triggers.
[13:31:45.891] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[13:32:17.738] INFO: Resuming triggers.
[13:32:24.225] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:32:55.556] INFO: Resuming triggers.
[13:33:02.039] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[13:33:33.992] INFO: Resuming triggers.
[13:33:40.478] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:34:10.724] INFO: Resuming triggers.
[13:34:17.210] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[13:34:47.311] INFO: Resuming triggers.
[13:34:53.799] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:35:23.915] INFO: Resuming triggers.
[13:35:30.398] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[13:36:00.555] INFO: Resuming triggers.
[13:36:07.042] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:36:37.151] INFO: Resuming triggers.
[13:36:43.636] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[13:37:13.709] INFO: Resuming triggers.
[13:37:20.196] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[13:37:50.334] INFO: Resuming triggers.
[13:37:56.826] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[13:38:26.893] INFO: Resuming triggers.
[13:38:33.380] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[13:39:03.403] INFO: Resuming triggers.
[13:39:06.462] INFO: data taking finished, elapsed time: 100 seconds.
[13:39:20.945] INFO: PixTest:: pg_setup set to default.
[13:39:20.948] INFO: PixTestXray::doPhRun() done
[13:39:21.096] INFO: enter test to run
[13:39:46.745] INFO: test: HighRate no parameter change
[13:39:46.745] INFO: running: highrate
[13:39:46.766] INFO: ----------------------------------------------------------------------
[13:39:46.767] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:39:46.767] INFO: ----------------------------------------------------------------------
[13:39:46.913] INFO: Expecting 768 events.
[13:39:48.047] INFO: 768 events read in total (418ms).
[13:39:48.048] INFO: Test took 1270ms.
[13:39:48.851] INFO: Expecting 41600 events.
[13:39:51.957] INFO: 41600 events read in total (2579ms).
[13:39:51.958] INFO: Test took 3904ms.
[13:39:51.991] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:52.718] INFO: Expecting 41600 events.
[13:39:55.941] INFO: 41600 events read in total (2696ms).
[13:39:55.942] INFO: Test took 3934ms.
[13:39:55.976] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:56.699] INFO: Expecting 41600 events.
[13:39:59.928] INFO: 41600 events read in total (2702ms).
[13:39:59.929] INFO: Test took 3936ms.
[13:39:59.963] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:00.686] INFO: Expecting 41600 events.
[13:40:03.903] INFO: 41600 events read in total (2690ms).
[13:40:03.904] INFO: Test took 3924ms.
[13:40:03.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:04.664] INFO: Expecting 41600 events.
[13:40:07.895] INFO: 41600 events read in total (2704ms).
[13:40:07.896] INFO: Test took 3940ms.
[13:40:07.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:08.653] INFO: Expecting 41600 events.
[13:40:11.887] INFO: 41600 events read in total (2708ms).
[13:40:11.888] INFO: Test took 3940ms.
[13:40:11.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:12.639] INFO: Expecting 41600 events.
[13:40:15.875] INFO: 41600 events read in total (2710ms).
[13:40:15.876] INFO: Test took 3936ms.
[13:40:15.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:16.632] INFO: Expecting 41600 events.
[13:40:19.861] INFO: 41600 events read in total (2702ms).
[13:40:19.861] INFO: Test took 3933ms.
[13:40:19.896] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:20.620] INFO: Expecting 41600 events.
[13:40:23.866] INFO: 41600 events read in total (2719ms).
[13:40:23.867] INFO: Test took 3953ms.
[13:40:23.900] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:24.623] INFO: Expecting 41600 events.
[13:40:27.855] INFO: 41600 events read in total (2705ms).
[13:40:27.856] INFO: Test took 3937ms.
[13:40:27.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:28.616] INFO: Expecting 41600 events.
[13:40:31.846] INFO: 41600 events read in total (2703ms).
[13:40:31.847] INFO: Test took 3940ms.
[13:40:31.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:32.605] INFO: Expecting 41600 events.
[13:40:35.854] INFO: 41600 events read in total (2722ms).
[13:40:35.855] INFO: Test took 3956ms.
[13:40:35.891] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:36.610] INFO: Expecting 41600 events.
[13:40:39.855] INFO: 41600 events read in total (2718ms).
[13:40:39.856] INFO: Test took 3945ms.
[13:40:39.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:40.616] INFO: Expecting 41600 events.
[13:40:43.861] INFO: 41600 events read in total (2718ms).
[13:40:43.862] INFO: Test took 3953ms.
[13:40:43.896] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:44.621] INFO: Expecting 41600 events.
[13:40:47.865] INFO: 41600 events read in total (2717ms).
[13:40:47.866] INFO: Test took 3952ms.
[13:40:47.900] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:48.621] INFO: Expecting 41600 events.
[13:40:51.879] INFO: 41600 events read in total (2731ms).
[13:40:51.880] INFO: Test took 3961ms.
[13:40:51.914] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:52.639] INFO: Expecting 41600 events.
[13:40:55.896] INFO: 41600 events read in total (2730ms).
[13:40:55.897] INFO: Test took 3966ms.
[13:40:55.931] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:56.654] INFO: Expecting 41600 events.
[13:40:59.892] INFO: 41600 events read in total (2711ms).
[13:40:59.893] INFO: Test took 3944ms.
[13:40:59.927] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:00.651] INFO: Expecting 41600 events.
[13:41:03.886] INFO: 41600 events read in total (2708ms).
[13:41:03.887] INFO: Test took 3942ms.
[13:41:03.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:04.644] INFO: Expecting 41600 events.
[13:41:07.703] INFO: 41600 events read in total (2532ms).
[13:41:07.704] INFO: Test took 3765ms.
[13:41:07.736] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:08.101] INFO: enter test to run
[13:41:45.312] INFO: test: HighRate no parameter change
[13:41:45.312] INFO: running: highrate
[13:41:45.313] INFO: ----------------------------------------------------------------------
[13:41:45.313] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:41:45.313] INFO: ----------------------------------------------------------------------
[13:41:45.928] INFO: Expecting 208000 events.
[13:41:57.929] INFO: 208000 events read in total (11474ms).
[13:41:57.932] INFO: Test took 12610ms.
[13:41:58.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:58.332] INFO: number of dead pixels (per ROC): 1 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:41:58.332] INFO: number of red-efficiency pixels: 72 47 89 156 129 143 142 106 96 129 123 110 116 54 28 23
[13:41:58.332] INFO: number of X-ray hits detected: 61435 39439 68018 108798 112446 117438 116720 79019 75949 99928 98877 84927 88029 51265 20215 24379
[13:41:58.332] 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:41:58.332] INFO: number of Vcal hits detected: 207878 207952 207859 207841 207868 207853 207855 207892 207903 207868 207875 207885 207880 207946 207972 207977
[13:41:58.332] 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 99.9 99.9 100.0 100.0 100.0
[13:41:58.332] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:41:58.333] INFO: X-ray hit rate [MHz/cm2]: 18.0 11.6 19.9 31.9 33.0 34.4 34.2 23.2 22.3 29.3 29.0 24.9 25.8 15.0 5.9 7.1
[13:41:58.333] INFO: PixTestHighRate::doXPixelAlive() done
[13:41:58.378] INFO: PixTest:: pg_setup set to default.
[13:41:58.395] INFO: enter test to run
[13:42:56.136] INFO: test: HighRate no parameter change
[13:42:56.136] INFO: running: highrate
[13:42:56.137] INFO: ----------------------------------------------------------------------
[13:42:56.137] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:42:56.137] INFO: ----------------------------------------------------------------------
[13:42:56.749] INFO: Expecting 208000 events.
[13:43:10.641] INFO: 208000 events read in total (13365ms).
[13:43:10.646] INFO: Test took 14502ms.
[13:43:10.965] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:11.274] INFO: number of dead pixels (per ROC): 1 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:43:11.274] INFO: number of red-efficiency pixels: 222 146 315 600 487 549 489 417 343 524 450 412 402 145 51 57
[13:43:11.274] INFO: number of X-ray hits detected: 134704 86764 149734 238434 247725 256297 255203 173101 167910 220837 217168 187442 192340 112763 43910 54187
[13:43:11.275] 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:43:11.275] INFO: number of Vcal hits detected: 207717 207849 207598 207327 207475 207391 207465 207524 207630 207441 207503 207564 207570 207846 207949 207940
[13:43:11.275] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[13:43:11.275] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[13:43:11.275] INFO: X-ray hit rate [MHz/cm2]: 39.5 25.4 43.9 69.9 72.6 75.1 74.8 50.7 49.2 64.7 63.7 54.9 56.4 33.1 12.9 15.9
[13:43:11.275] INFO: PixTestHighRate::doXPixelAlive() done
[13:43:11.320] INFO: PixTest:: pg_setup set to default.
[13:43:11.335] INFO: enter test to run
[13:44:08.487] INFO: test: HighRate no parameter change
[13:44:08.487] INFO: running: highrate
[13:44:08.488] INFO: ----------------------------------------------------------------------
[13:44:08.488] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:44:08.488] INFO: ----------------------------------------------------------------------
[13:44:09.107] INFO: Expecting 208000 events.
[13:44:25.360] INFO: 208000 events read in total (15727ms).
[13:44:25.367] INFO: Test took 16870ms.
[13:44:25.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:26.231] INFO: number of dead pixels (per ROC): 1 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:44:26.231] INFO: number of red-efficiency pixels: 386 249 662 1476 1198 1306 1133 886 738 1204 1129 915 933 411 83 78
[13:44:26.231] INFO: number of X-ray hits detected: 205175 132422 226802 362941 375718 390261 387294 263183 255686 335205 330117 284306 291893 172557 67520 82701
[13:44:26.231] 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:44:26.231] INFO: number of Vcal hits detected: 207509 207729 207035 205957 206476 206227 206559 206759 207125 206454 206561 206854 206857 207520 207912 207922
[13:44:26.231] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.1 99.3 99.2 99.4 99.5 99.6 99.3 99.4 99.5 99.5 99.8 100.0 100.0
[13:44:26.231] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.5 99.0 99.3 99.1 99.3 99.4 99.6 99.3 99.3 99.4 99.5 99.8 100.0 100.0
[13:44:26.231] INFO: X-ray hit rate [MHz/cm2]: 60.1 38.8 66.5 106.4 110.1 114.4 113.5 77.1 74.9 98.3 96.8 83.3 85.6 50.6 19.8 24.2
[13:44:26.231] INFO: PixTestHighRate::doXPixelAlive() done
[13:44:26.282] INFO: PixTest:: pg_setup set to default.
[13:44:26.298] INFO: enter test to run
[13:44:43.879] INFO: test: exit no parameter change
[13:44:44.206] QUIET: Connection to board 33 closed.
[13:44:44.219] INFO: pXar: this is the end, my friend