[10:04:46.842] INFO: *** Welcome to pxar ***
[10:04:46.842] INFO: *** Today: 2016/05/24
[10:04:47.413] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:04:47.430] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//dacParameters35_C15.dat
[10:04:47.491] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:04:47.491] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//defaultMaskFile.dat
[10:04:47.491] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C15.dat
[10:04:47.654] INFO: clk: 4
[10:04:47.654] INFO: ctr: 4
[10:04:47.654] INFO: sda: 19
[10:04:47.654] INFO: tin: 9
[10:04:47.654] INFO: level: 15
[10:04:47.654] INFO: triggerdelay: 0
[10:04:47.654] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:04:47.654] INFO: Log level: INFO
[10:04:47.672] QUIET: Connection to board DTB_WREKRL opened.
[10:04:47.675] 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:
------------------------------------------------------
[10:04:47.678] INFO: RPC call hashes of host and DTB match: 398089610
[10:04:49.216] INFO: DUT info:
[10:04:49.216] INFO: The DUT currently contains the following objects:
[10:04:49.216] INFO: 2 TBM Cores tbm08c (2 ON)
[10:04:49.217] INFO: TBM Core alpha (0): 7 registers set
[10:04:49.217] INFO: TBM Core beta (1): 7 registers set
[10:04:49.217] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:04:49.217] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.217] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:04:49.685] INFO: enter 'restricted' command line mode
[10:04:49.685] INFO: enter test to run
[10:04:59.970] INFO: test: PixelAlive no parameter change
[10:04:59.970] INFO: running: pixelalive
[10:05:00.044] INFO: ----------------------------------------------------------------------
[10:05:00.044] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:05:00.044] INFO: ----------------------------------------------------------------------
[10:05:00.367] INFO: Expecting 41600 events.
[10:05:04.673] INFO: 41600 events read in total (3587ms).
[10:05:04.833] INFO: Test took 4785ms.
[10:05:04.842] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:05:05.412] INFO: PixTestAlive::aliveTest() done
[10:05:05.412] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 1 0 0 3 0 0 0 0 0 0
[10:05:05.577] INFO: enter test to run
[10:05:41.073] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:05:41.073] INFO: running: highrate
[10:05:41.074] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:05:41.348] INFO: ----------------------------------------------------------------------
[10:05:41.348] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:05:41.348] INFO: ----------------------------------------------------------------------
[10:05:41.348] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:05:41.348] INFO: edge/corner pixel THR is adjusted
[10:05:41.348] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:05:42.306] INFO: Collecting data for 5 seconds...
[10:05:47.324] INFO: Done with hot pixel readout
[10:05:58.560] INFO: PixTest:: pg_setup set to default.
[10:05:58.561] INFO: 18 hot pixels found in step 0
[10:05:59.566] INFO: Collecting data for 5 seconds...
[10:06:04.586] INFO: Done with hot pixel readout
[10:06:15.769] INFO: PixTest:: pg_setup set to default.
[10:06:15.770] INFO: 16 hot pixels found in step 1
[10:06:16.754] INFO: Collecting data for 5 seconds...
[10:06:21.773] INFO: Done with hot pixel readout
[10:06:33.121] INFO: PixTest:: pg_setup set to default.
[10:06:33.122] INFO: 17 hot pixels found in step 2
[10:06:34.107] INFO: Collecting data for 5 seconds...
[10:06:39.127] INFO: Done with hot pixel readout
[10:06:50.494] INFO: PixTest:: pg_setup set to default.
[10:06:50.495] INFO: 17 hot pixels found in step 3
[10:06:51.479] INFO: Collecting data for 5 seconds...
[10:06:56.500] INFO: Done with hot pixel readout
[10:07:07.857] INFO: PixTest:: pg_setup set to default.
[10:07:07.858] INFO: 15 hot pixels found in step 4
[10:07:08.843] INFO: Collecting data for 5 seconds...
[10:07:13.864] INFO: Done with hot pixel readout
[10:07:25.190] INFO: PixTest:: pg_setup set to default.
[10:07:25.190] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:07:25.191] INFO: 14 hot pixels found in step 5
[10:07:26.176] INFO: Collecting data for 5 seconds...
[10:07:31.196] INFO: Done with hot pixel readout
[10:07:42.825] INFO: PixTest:: pg_setup set to default.
[10:07:42.825] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:07:42.826] INFO: 14 hot pixels found in step 6
[10:07:43.811] INFO: Collecting data for 5 seconds...
[10:07:48.831] INFO: Done with hot pixel readout
[10:08:00.359] INFO: PixTest:: pg_setup set to default.
[10:08:00.359] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:08:00.360] INFO: 9 hot pixels found in step 7
[10:08:01.344] INFO: Collecting data for 5 seconds...
[10:08:06.364] INFO: Done with hot pixel readout
[10:08:17.728] INFO: PixTest:: pg_setup set to default.
[10:08:17.728] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:08:17.729] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:08:17.729] INFO: 7 hot pixels found in step 8
[10:08:18.715] INFO: Collecting data for 5 seconds...
[10:08:23.732] INFO: Done with hot pixel readout
[10:08:34.972] INFO: PixTest:: pg_setup set to default.
[10:08:34.972] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:08:34.973] INFO: 3 hot pixels found in step 9
[10:08:35.958] INFO: Collecting data for 5 seconds...
[10:08:40.975] INFO: Done with hot pixel readout
[10:08:52.264] INFO: PixTest:: pg_setup set to default.
[10:08:52.264] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:08:52.265] INFO: 3 hot pixels found in step 10
[10:08:53.250] INFO: Collecting data for 5 seconds...
[10:08:58.266] INFO: Done with hot pixel readout
[10:09:09.556] INFO: PixTest:: pg_setup set to default.
[10:09:09.556] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:09:09.557] INFO: 2 hot pixels found in step 11
[10:09:10.541] INFO: Collecting data for 5 seconds...
[10:09:15.557] INFO: Done with hot pixel readout
[10:09:26.830] INFO: PixTest:: pg_setup set to default.
[10:09:26.830] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:09:26.831] INFO: 2 hot pixels found in step 12
[10:09:27.816] INFO: Collecting data for 5 seconds...
[10:09:32.832] INFO: Done with hot pixel readout
[10:09:44.128] INFO: PixTest:: pg_setup set to default.
[10:09:44.128] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:09:44.128] INFO: 4 hot pixels found in step 13
[10:09:45.113] INFO: Collecting data for 5 seconds...
[10:09:50.130] INFO: Done with hot pixel readout
[10:10:01.329] INFO: PixTest:: pg_setup set to default.
[10:10:01.329] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:10:01.330] INFO: 2 hot pixels found in step 14
[10:10:01.358] INFO: 2 hot pixels could not be trimmed and have been masked.
[10:10:01.377] INFO: PixTest::trimHotPixels() done
[10:10:01.377] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C0.dat
[10:10:01.383] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C1.dat
[10:10:01.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C2.dat
[10:10:01.394] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C3.dat
[10:10:01.400] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C4.dat
[10:10:01.405] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C5.dat
[10:10:01.410] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C6.dat
[10:10:01.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C7.dat
[10:10:01.421] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C8.dat
[10:10:01.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C9.dat
[10:10:01.432] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C10.dat
[10:10:01.437] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C11.dat
[10:10:01.442] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C12.dat
[10:10:01.448] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C13.dat
[10:10:01.453] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C14.dat
[10:10:01.459] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C15.dat
[10:10:01.464] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//defaultMaskFile.dat
[10:10:01.474] INFO: enter test to run
[10:10:49.279] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:10:49.279] INFO: running: highrate
[10:10:49.284] INFO: ----------------------------------------------------------------------
[10:10:49.284] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:10:49.284] INFO: ----------------------------------------------------------------------
[10:10:49.284] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:10:49.284] INFO: edge/corner pixel THR is adjusted
[10:10:49.284] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:10:50.250] INFO: Collecting data for 1 seconds...
[10:10:51.253] INFO: Done with hot pixel readout
[10:10:54.975] INFO: PixTest:: pg_setup set to default.
[10:10:54.976] INFO: 0 hot pixels found in step 0
[10:10:54.982] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:10:55.080] INFO: PixTest::trimHotPixels() done
[10:10:55.081] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C0.dat
[10:10:55.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C1.dat
[10:10:55.098] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C2.dat
[10:10:55.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C3.dat
[10:10:55.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C4.dat
[10:10:55.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C5.dat
[10:10:55.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C6.dat
[10:10:55.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C7.dat
[10:10:55.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C8.dat
[10:10:55.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C9.dat
[10:10:55.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C10.dat
[10:10:55.146] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C11.dat
[10:10:55.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C12.dat
[10:10:55.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C13.dat
[10:10:55.161] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C14.dat
[10:10:55.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//trimParameters35_C15.dat
[10:10:55.172] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-12_FPIXTest-17C-FNAL-160512-1153_2016-05-12_11h53m_1463072019/000_FPIXTest_p17//defaultMaskFile.dat
[10:10:55.181] INFO: enter test to run
[10:11:27.751] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:11:27.751] INFO: running: xray
[10:11:27.752] INFO: ----------------------------------------------------------------------
[10:11:27.752] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:11:27.752] INFO: ----------------------------------------------------------------------
[10:11:28.736] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:11:40.895] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[10:12:10.205] INFO: Resuming triggers.
[10:12:22.364] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[10:12:51.525] INFO: Resuming triggers.
[10:13:03.683] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[10:13:32.845] INFO: Resuming triggers.
[10:13:45.008] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[10:14:14.216] INFO: Resuming triggers.
[10:14:26.375] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[10:14:55.569] INFO: Resuming triggers.
[10:15:07.736] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[10:15:36.935] INFO: Resuming triggers.
[10:15:49.093] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[10:16:18.479] INFO: Resuming triggers.
[10:16:30.640] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[10:16:59.007] INFO: Resuming triggers.
[10:17:02.053] INFO: data taking finished, elapsed time: 100 seconds.
[10:17:09.765] INFO: PixTest:: pg_setup set to default.
[10:17:09.768] INFO: PixTestXray::doPhRun() done
[10:17:09.905] INFO: enter test to run
[10:18:17.132] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:18:17.132] INFO: running: xray
[10:18:17.133] INFO: ----------------------------------------------------------------------
[10:18:17.133] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:18:17.133] INFO: ----------------------------------------------------------------------
[10:18:18.096] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:18:25.498] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[10:18:56.772] INFO: Resuming triggers.
[10:19:04.174] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[10:19:34.532] INFO: Resuming triggers.
[10:19:41.935] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[10:20:11.849] INFO: Resuming triggers.
[10:20:19.251] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[10:20:49.082] INFO: Resuming triggers.
[10:20:56.484] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[10:21:26.599] INFO: Resuming triggers.
[10:21:33.000] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:22:04.158] INFO: Resuming triggers.
[10:22:11.562] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[10:22:41.756] INFO: Resuming triggers.
[10:22:49.160] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[10:23:19.363] INFO: Resuming triggers.
[10:23:26.769] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:23:56.944] INFO: Resuming triggers.
[10:24:04.348] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[10:24:34.505] INFO: Resuming triggers.
[10:24:41.912] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:25:12.006] INFO: Resuming triggers.
[10:25:19.414] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:25:49.573] INFO: Resuming triggers.
[10:25:56.978] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[10:26:27.181] INFO: Resuming triggers.
[10:26:31.270] INFO: data taking finished, elapsed time: 100 seconds.
[10:26:48.173] INFO: PixTest:: pg_setup set to default.
[10:26:48.176] INFO: PixTestXray::doPhRun() done
[10:26:48.322] INFO: enter test to run
[10:27:31.192] INFO: test: HighRate no parameter change
[10:27:31.192] INFO: running: highrate
[10:27:31.193] INFO: ----------------------------------------------------------------------
[10:27:31.193] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:27:31.193] INFO: ----------------------------------------------------------------------
[10:27:31.334] INFO: Expecting 768 events.
[10:27:32.468] INFO: 768 events read in total (418ms).
[10:27:32.468] INFO: Test took 1269ms.
[10:27:33.270] INFO: Expecting 41600 events.
[10:27:36.233] INFO: 41600 events read in total (2436ms).
[10:27:36.234] INFO: Test took 3760ms.
[10:27:36.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:36.001] INFO: Expecting 41600 events.
[10:27:40.108] INFO: 41600 events read in total (2580ms).
[10:27:40.109] INFO: Test took 3832ms.
[10:27:40.137] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:40.868] INFO: Expecting 41600 events.
[10:27:44.071] INFO: 41600 events read in total (2676ms).
[10:27:44.072] INFO: Test took 3918ms.
[10:27:44.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:44.837] INFO: Expecting 41600 events.
[10:27:48.098] INFO: 41600 events read in total (2734ms).
[10:27:48.099] INFO: Test took 3982ms.
[10:27:48.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:48.844] INFO: Expecting 41600 events.
[10:27:51.001] INFO: 41600 events read in total (2630ms).
[10:27:52.002] INFO: Test took 3855ms.
[10:27:52.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:52.760] INFO: Expecting 41600 events.
[10:27:55.965] INFO: 41600 events read in total (2678ms).
[10:27:55.966] INFO: Test took 3917ms.
[10:27:55.995] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:56.729] INFO: Expecting 41600 events.
[10:27:59.993] INFO: 41600 events read in total (2738ms).
[10:27:59.993] INFO: Test took 3982ms.
[10:28:00.023] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:00.753] INFO: Expecting 41600 events.
[10:28:03.889] INFO: 41600 events read in total (2609ms).
[10:28:03.890] INFO: Test took 3851ms.
[10:28:03.920] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:04.656] INFO: Expecting 41600 events.
[10:28:07.887] INFO: 41600 events read in total (2704ms).
[10:28:07.887] INFO: Test took 3950ms.
[10:28:07.917] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:08.643] INFO: Expecting 41600 events.
[10:28:11.802] INFO: 41600 events read in total (2632ms).
[10:28:11.803] INFO: Test took 3871ms.
[10:28:11.832] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:12.562] INFO: Expecting 41600 events.
[10:28:15.747] INFO: 41600 events read in total (2659ms).
[10:28:15.748] INFO: Test took 3900ms.
[10:28:15.778] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:16.503] INFO: Expecting 41600 events.
[10:28:19.701] INFO: 41600 events read in total (2671ms).
[10:28:19.702] INFO: Test took 3907ms.
[10:28:19.732] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:20.462] INFO: Expecting 41600 events.
[10:28:23.636] INFO: 41600 events read in total (2647ms).
[10:28:23.637] INFO: Test took 3890ms.
[10:28:23.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:24.397] INFO: Expecting 41600 events.
[10:28:27.598] INFO: 41600 events read in total (2675ms).
[10:28:27.599] INFO: Test took 3916ms.
[10:28:27.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:28.362] INFO: Expecting 41600 events.
[10:28:31.510] INFO: 41600 events read in total (2622ms).
[10:28:31.511] INFO: Test took 3866ms.
[10:28:31.541] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:32.269] INFO: Expecting 41600 events.
[10:28:35.445] INFO: 41600 events read in total (2649ms).
[10:28:35.445] INFO: Test took 3888ms.
[10:28:35.475] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:36.209] INFO: Expecting 41600 events.
[10:28:39.336] INFO: 41600 events read in total (2600ms).
[10:28:39.337] INFO: Test took 3846ms.
[10:28:39.367] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:40.091] INFO: Expecting 41600 events.
[10:28:43.290] INFO: 41600 events read in total (2672ms).
[10:28:43.291] INFO: Test took 3907ms.
[10:28:43.321] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:44.053] INFO: Expecting 41600 events.
[10:28:47.351] INFO: 41600 events read in total (2771ms).
[10:28:47.352] INFO: Test took 4016ms.
[10:28:47.382] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:48.097] INFO: Expecting 41600 events.
[10:28:51.163] INFO: 41600 events read in total (2539ms).
[10:28:51.164] INFO: Test took 3765ms.
[10:28:51.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:51.542] INFO: enter test to run
[10:28:57.607] INFO: test: HighRate no parameter change
[10:28:57.607] INFO: running: highrate
[10:28:57.608] INFO: ----------------------------------------------------------------------
[10:28:57.608] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:28:57.608] INFO: ----------------------------------------------------------------------
[10:28:58.225] INFO: Expecting 208000 events.
[10:29:09.884] INFO: 208000 events read in total (11132ms).
[10:29:09.887] INFO: Test took 12272ms.
[10:29:10.009] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:10.253] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 1 0 0 3 0 0 0 0 0 0
[10:29:10.253] INFO: number of red-efficiency pixels: 54 45 94 119 95 89 101 107 59 73 83 91 84 56 16 26
[10:29:10.253] INFO: number of X-ray hits detected: 53631 36614 55250 86742 90837 87328 90136 64576 55722 73797 73670 68017 74038 44528 20719 24027
[10:29:10.253] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:29:10.253] INFO: number of Vcal hits detected: 207945 207954 207902 207879 207856 207909 207848 207893 207941 207779 207916 207908 207914 207941 207984 207974
[10:29:10.253] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[10:29:10.253] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[10:29:10.253] INFO: X-ray hit rate [MHz/cm2]: 15.7 10.7 16.2 25.4 26.6 25.6 26.4 18.9 16.3 21.6 21.6 19.9 21.7 13.1 6.1 7.0
[10:29:10.253] INFO: PixTestHighRate::doXPixelAlive() done
[10:29:10.298] INFO: PixTest:: pg_setup set to default.
[10:29:10.316] INFO: enter test to run
[10:29:40.038] INFO: test: HighRate no parameter change
[10:29:40.039] INFO: running: highrate
[10:29:40.040] INFO: ----------------------------------------------------------------------
[10:29:40.040] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:29:40.040] INFO: ----------------------------------------------------------------------
[10:29:40.651] INFO: Expecting 208000 events.
[10:29:53.974] INFO: 208000 events read in total (12796ms).
[10:29:53.978] INFO: Test took 13931ms.
[10:29:54.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:54.517] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 1 0 0 3 0 0 0 0 0 0
[10:29:54.517] INFO: number of red-efficiency pixels: 188 108 346 337 316 278 366 230 151 264 221 229 257 161 52 61
[10:29:54.517] INFO: number of X-ray hits detected: 114544 78144 118253 185114 194482 187461 193733 138536 119536 157816 158250 145164 159293 95776 44310 52049
[10:29:54.517] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:29:54.517] INFO: number of Vcal hits detected: 207797 207888 207316 207645 207622 207707 207558 207761 207847 207583 207769 207757 207730 207832 207945 207938
[10:29:54.517] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.7 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[10:29:54.517] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.7 99.8 99.8 99.9 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[10:29:54.517] INFO: X-ray hit rate [MHz/cm2]: 33.6 22.9 34.7 54.3 57.0 54.9 56.8 40.6 35.0 46.3 46.4 42.5 46.7 28.1 13.0 15.3
[10:29:54.517] INFO: PixTestHighRate::doXPixelAlive() done
[10:29:54.562] INFO: PixTest:: pg_setup set to default.
[10:29:54.579] INFO: enter test to run
[10:30:22.078] INFO: test: HighRate no parameter change
[10:30:22.078] INFO: running: highrate
[10:30:22.080] INFO: ----------------------------------------------------------------------
[10:30:22.080] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:30:22.080] INFO: ----------------------------------------------------------------------
[10:30:22.695] INFO: Expecting 208000 events.
[10:30:37.207] INFO: 208000 events read in total (13985ms).
[10:30:37.213] INFO: Test took 15125ms.
[10:30:37.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:37.934] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 1 0 0 3 0 0 0 0 0 0
[10:30:37.934] INFO: number of red-efficiency pixels: 381 224 605 807 757 662 859 509 237 580 493 533 555 311 92 94
[10:30:37.934] INFO: number of X-ray hits detected: 175343 119829 182482 283403 298969 287093 297300 211346 183805 242755 242796 223999 243911 147055 68540 79869
[10:30:37.934] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:30:37.934] INFO: number of Vcal hits detected: 207578 207764 205612 207045 207082 207241 206925 207413 207751 207205 207469 207401 207376 207647 207904 207903
[10:30:37.934] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 98.8 99.6 99.6 99.7 99.6 99.7 99.9 99.7 99.8 99.7 99.7 99.8 100.0 100.0
[10:30:37.934] INFO: Vcal hit overall efficiency (%): 99.8 99.9 98.9 99.5 99.6 99.6 99.5 99.7 99.9 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[10:30:37.934] INFO: X-ray hit rate [MHz/cm2]: 51.4 35.1 53.5 83.1 87.6 84.1 87.1 61.9 53.9 71.2 71.2 65.7 71.5 43.1 20.1 23.4
[10:30:37.934] INFO: PixTestHighRate::doXPixelAlive() done
[10:30:37.979] INFO: PixTest:: pg_setup set to default.
[10:30:37.996] INFO: enter test to run
[10:30:43.238] INFO: test: exit no parameter change
[10:30:43.572] QUIET: Connection to board 33 closed.
[10:30:43.573] INFO: pXar: this is the end, my friend