[15:17:35.775] INFO: *** Welcome to pxar ***
[15:17:35.775] INFO: *** Today: 2016/08/25
[15:17:36.608] INFO: *** Version: v1.9.0-818-g96727
[15:17:36.608] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//dacParameters35_C15.dat
[15:17:36.696] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:17:36.697] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//defaultMaskFile.dat
[15:17:36.701] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C15.dat
[15:17:36.833] INFO: clk: 4
[15:17:36.833] INFO: ctr: 4
[15:17:36.833] INFO: sda: 19
[15:17:36.833] INFO: tin: 9
[15:17:36.833] INFO: level: 15
[15:17:36.833] INFO: triggerdelay: 0
[15:17:36.833] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:17:36.833] INFO: Log level: INFO
[15:17:36.851] QUIET: Connection to board DTB_WREKRL opened.
[15:17:36.854] 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:
------------------------------------------------------
[15:17:36.857] INFO: RPC call hashes of host and DTB match: 398089610
[15:17:38.398] INFO: DUT info:
[15:17:38.399] INFO: The DUT currently contains the following objects:
[15:17:38.399] INFO: 2 TBM Cores tbm08c (2 ON)
[15:17:38.399] INFO: TBM Core alpha (0): 7 registers set
[15:17:38.399] INFO: TBM Core beta (1): 7 registers set
[15:17:38.399] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:17:38.399] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.399] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:17:38.823] INFO: enter 'restricted' command line mode
[15:17:38.823] INFO: enter test to run
[15:17:49.993] INFO: test: PixelAlive no parameter change
[15:17:49.993] INFO: running: pixelalive
[15:17:50.020] INFO: ----------------------------------------------------------------------
[15:17:50.020] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:17:50.020] INFO: ----------------------------------------------------------------------
[15:17:50.337] INFO: Expecting 41600 events.
[15:17:54.648] INFO: 41600 events read in total (3593ms).
[15:17:54.812] INFO: Test took 4788ms.
[15:17:54.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:55.311] INFO: PixTestAlive::aliveTest() done
[15:17:55.311] INFO: number of dead pixels (per ROC): 0 1 0 0 1 0 0 0 0 0 0 0 0 1 0 0
[15:17:55.465] INFO: enter test to run
[15:19:01.304] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:19:01.304] INFO: running: highrate
[15:19:01.438] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:19:03.828] INFO: ----------------------------------------------------------------------
[15:19:03.828] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:19:03.828] INFO: ----------------------------------------------------------------------
[15:19:03.828] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:19:03.828] INFO: edge/corner pixel THR is adjusted
[15:19:03.828] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:19:04.842] INFO: Collecting data for 5 seconds...
[15:19:09.859] INFO: Done with hot pixel readout
[15:19:21.791] INFO: PixTest:: pg_setup set to default.
[15:19:21.792] INFO: 35 hot pixels found in step 0
[15:19:22.808] INFO: Collecting data for 5 seconds...
[15:19:27.824] INFO: Done with hot pixel readout
[15:19:39.805] INFO: PixTest:: pg_setup set to default.
[15:19:39.806] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:19:39.806] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:19:39.806] INFO: 40 hot pixels found in step 1
[15:19:40.796] INFO: Collecting data for 5 seconds...
[15:19:45.812] INFO: Done with hot pixel readout
[15:19:57.738] INFO: PixTest:: pg_setup set to default.
[15:19:57.738] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:19:57.739] INFO: 33 hot pixels found in step 2
[15:19:58.728] INFO: Collecting data for 5 seconds...
[15:20:03.744] INFO: Done with hot pixel readout
[15:20:15.666] INFO: PixTest:: pg_setup set to default.
[15:20:15.666] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:20:15.666] INFO: 28 hot pixels found in step 3
[15:20:16.656] INFO: Collecting data for 5 seconds...
[15:20:21.673] INFO: Done with hot pixel readout
[15:20:33.627] INFO: PixTest:: pg_setup set to default.
[15:20:33.628] INFO: 20 hot pixels found in step 4
[15:20:34.618] INFO: Collecting data for 5 seconds...
[15:20:39.634] INFO: Done with hot pixel readout
[15:20:51.613] INFO: PixTest:: pg_setup set to default.
[15:20:51.614] INFO: 36 hot pixels found in step 5
[15:20:52.604] INFO: Collecting data for 5 seconds...
[15:20:57.620] INFO: Done with hot pixel readout
[15:21:09.533] INFO: PixTest:: pg_setup set to default.
[15:21:09.533] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:21:09.534] INFO: 25 hot pixels found in step 6
[15:21:10.524] INFO: Collecting data for 5 seconds...
[15:21:15.540] INFO: Done with hot pixel readout
[15:21:27.378] INFO: PixTest:: pg_setup set to default.
[15:21:27.378] INFO: 24 hot pixels found in step 7
[15:21:28.369] INFO: Collecting data for 5 seconds...
[15:21:33.385] INFO: Done with hot pixel readout
[15:21:45.328] INFO: PixTest:: pg_setup set to default.
[15:21:45.329] INFO: 17 hot pixels found in step 8
[15:21:46.318] INFO: Collecting data for 5 seconds...
[15:21:51.335] INFO: Done with hot pixel readout
[15:22:03.271] INFO: PixTest:: pg_setup set to default.
[15:22:03.272] INFO: 16 hot pixels found in step 9
[15:22:04.261] INFO: Collecting data for 5 seconds...
[15:22:09.277] INFO: Done with hot pixel readout
[15:22:21.181] INFO: PixTest:: pg_setup set to default.
[15:22:21.182] INFO: 16 hot pixels found in step 10
[15:22:22.172] INFO: Collecting data for 5 seconds...
[15:22:27.188] INFO: Done with hot pixel readout
[15:22:39.124] INFO: PixTest:: pg_setup set to default.
[15:22:39.125] INFO: 23 hot pixels found in step 11
[15:22:40.115] INFO: Collecting data for 5 seconds...
[15:22:45.131] INFO: Done with hot pixel readout
[15:22:57.033] INFO: PixTest:: pg_setup set to default.
[15:22:57.034] INFO: 14 hot pixels found in step 12
[15:22:58.024] INFO: Collecting data for 5 seconds...
[15:23:03.040] INFO: Done with hot pixel readout
[15:23:14.875] INFO: PixTest:: pg_setup set to default.
[15:23:14.876] INFO: 16 hot pixels found in step 13
[15:23:15.866] INFO: Collecting data for 5 seconds...
[15:23:20.881] INFO: Done with hot pixel readout
[15:23:32.778] INFO: PixTest:: pg_setup set to default.
[15:23:32.778] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:23:32.779] INFO: 17 hot pixels found in step 14
[15:23:32.813] INFO: 17 hot pixels could not be trimmed and have been masked.
[15:23:32.842] INFO: PixTest::trimHotPixels() done
[15:23:32.848] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C0.dat
[15:23:32.853] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C1.dat
[15:23:32.858] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C2.dat
[15:23:32.864] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C3.dat
[15:23:32.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C4.dat
[15:23:32.874] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C5.dat
[15:23:32.879] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C6.dat
[15:23:32.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C7.dat
[15:23:32.890] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C8.dat
[15:23:32.895] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C9.dat
[15:23:32.900] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C10.dat
[15:23:32.905] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C11.dat
[15:23:32.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C12.dat
[15:23:32.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C13.dat
[15:23:32.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C14.dat
[15:23:32.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C15.dat
[15:23:32.931] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//defaultMaskFile.dat
[15:23:32.945] INFO: enter test to run
[15:24:19.128] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:24:19.128] INFO: running: highrate
[15:24:19.132] INFO: ----------------------------------------------------------------------
[15:24:19.133] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:24:19.133] INFO: ----------------------------------------------------------------------
[15:24:19.133] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:24:19.133] INFO: edge/corner pixel THR is adjusted
[15:24:19.133] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:24:20.091] INFO: Collecting data for 1 seconds...
[15:24:21.094] INFO: Done with hot pixel readout
[15:24:25.155] INFO: PixTest:: pg_setup set to default.
[15:24:25.156] INFO: 0 hot pixels found in step 0
[15:24:25.161] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:24:25.249] INFO: PixTest::trimHotPixels() done
[15:24:25.249] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C0.dat
[15:24:25.260] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C1.dat
[15:24:25.267] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C2.dat
[15:24:25.272] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C3.dat
[15:24:25.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C4.dat
[15:24:25.283] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C5.dat
[15:24:25.288] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C6.dat
[15:24:25.293] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C7.dat
[15:24:25.299] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C8.dat
[15:24:25.304] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C9.dat
[15:24:25.309] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C10.dat
[15:24:25.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C11.dat
[15:24:25.320] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C12.dat
[15:24:25.325] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C13.dat
[15:24:25.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C14.dat
[15:24:25.336] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//trimParameters35_C15.dat
[15:24:25.341] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-7-18_FPIXTest-17C-FNAL-160819-1322-300V_2016-08-19_13h22m_1471630970/000_FPIXTest_p17//defaultMaskFile.dat
[15:24:25.351] INFO: enter test to run
[15:24:54.848] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:24:54.848] INFO: running: xray
[15:24:54.849] INFO: ----------------------------------------------------------------------
[15:24:54.849] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:24:54.849] INFO: ----------------------------------------------------------------------
[15:24:55.835] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:25:07.120] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:25:36.992] INFO: Resuming triggers.
[15:25:48.283] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:26:17.529] INFO: Resuming triggers.
[15:26:28.814] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:26:58.790] INFO: Resuming triggers.
[15:27:10.077] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:27:40.497] INFO: Resuming triggers.
[15:27:51.787] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:28:21.702] INFO: Resuming triggers.
[15:28:32.998] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:29:02.816] INFO: Resuming triggers.
[15:29:14.117] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[15:29:43.861] INFO: Resuming triggers.
[15:29:55.157] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:30:24.791] INFO: Resuming triggers.
[15:30:34.817] INFO: data taking finished, elapsed time: 100 seconds.
[15:31:01.310] INFO: PixTest:: pg_setup set to default.
[15:31:01.314] INFO: PixTestXray::doPhRun() done
[15:31:01.559] INFO: enter test to run
[15:31:37.893] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:31:37.893] INFO: running: xray
[15:31:37.894] INFO: ----------------------------------------------------------------------
[15:31:37.894] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:31:37.894] INFO: ----------------------------------------------------------------------
[15:31:38.858] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:31:45.481] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:32:15.799] INFO: Resuming triggers.
[15:32:22.419] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:32:52.776] INFO: Resuming triggers.
[15:32:59.406] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:33:29.610] INFO: Resuming triggers.
[15:33:36.240] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:34:06.691] INFO: Resuming triggers.
[15:34:13.315] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:34:43.425] INFO: Resuming triggers.
[15:34:50.050] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:35:20.278] INFO: Resuming triggers.
[15:35:26.898] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:35:57.124] INFO: Resuming triggers.
[15:36:03.746] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[15:36:33.904] INFO: Resuming triggers.
[15:36:40.528] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:37:10.672] INFO: Resuming triggers.
[15:37:17.300] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:37:48.045] INFO: Resuming triggers.
[15:37:54.669] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:38:25.374] INFO: Resuming triggers.
[15:38:31.001] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:39:02.368] INFO: Resuming triggers.
[15:39:08.996] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[15:39:39.956] INFO: Resuming triggers.
[15:39:46.583] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:40:15.262] INFO: Resuming triggers.
[15:40:21.898] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:40:52.681] INFO: Resuming triggers.
[15:40:54.007] INFO: data taking finished, elapsed time: 100 seconds.
[15:40:58.691] INFO: PixTest:: pg_setup set to default.
[15:40:58.694] INFO: PixTestXray::doPhRun() done
[15:40:59.876] INFO: enter test to run
[15:42:42.088] INFO: test: HighRate no parameter change
[15:42:42.088] INFO: running: highrate
[15:42:42.470] INFO: ----------------------------------------------------------------------
[15:42:42.470] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:42:42.470] INFO: ----------------------------------------------------------------------
[15:42:42.612] INFO: Expecting 768 events.
[15:42:43.744] INFO: 768 events read in total (416ms).
[15:42:43.745] INFO: Test took 1268ms.
[15:42:44.833] INFO: Expecting 41600 events.
[15:42:48.017] INFO: 41600 events read in total (2657ms).
[15:42:48.018] INFO: Test took 3818ms.
[15:42:48.059] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:48.766] INFO: Expecting 41600 events.
[15:42:51.985] INFO: 41600 events read in total (2692ms).
[15:42:51.985] INFO: Test took 3886ms.
[15:42:52.021] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:52.742] INFO: Expecting 41600 events.
[15:42:56.029] INFO: 41600 events read in total (2760ms).
[15:42:56.030] INFO: Test took 3989ms.
[15:42:56.067] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:56.785] INFO: Expecting 41600 events.
[15:43:00.075] INFO: 41600 events read in total (2764ms).
[15:43:00.076] INFO: Test took 3991ms.
[15:43:00.112] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:00.833] INFO: Expecting 41600 events.
[15:43:04.142] INFO: 41600 events read in total (2782ms).
[15:43:04.143] INFO: Test took 4014ms.
[15:43:04.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:04.898] INFO: Expecting 41600 events.
[15:43:08.184] INFO: 41600 events read in total (2759ms).
[15:43:08.185] INFO: Test took 3963ms.
[15:43:08.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:08.940] INFO: Expecting 41600 events.
[15:43:12.183] INFO: 41600 events read in total (2716ms).
[15:43:12.183] INFO: Test took 3944ms.
[15:43:12.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:12.943] INFO: Expecting 41600 events.
[15:43:16.187] INFO: 41600 events read in total (2718ms).
[15:43:16.188] INFO: Test took 3952ms.
[15:43:16.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:16.943] INFO: Expecting 41600 events.
[15:43:20.195] INFO: 41600 events read in total (2725ms).
[15:43:20.196] INFO: Test took 3954ms.
[15:43:20.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:20.951] INFO: Expecting 41600 events.
[15:43:24.202] INFO: 41600 events read in total (2724ms).
[15:43:24.203] INFO: Test took 3954ms.
[15:43:24.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:24.958] INFO: Expecting 41600 events.
[15:43:28.204] INFO: 41600 events read in total (2719ms).
[15:43:28.205] INFO: Test took 3949ms.
[15:43:28.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:28.963] INFO: Expecting 41600 events.
[15:43:32.221] INFO: 41600 events read in total (2732ms).
[15:43:32.222] INFO: Test took 3963ms.
[15:43:32.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:32.979] INFO: Expecting 41600 events.
[15:43:36.240] INFO: 41600 events read in total (2734ms).
[15:43:36.241] INFO: Test took 3967ms.
[15:43:36.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:36.999] INFO: Expecting 41600 events.
[15:43:40.261] INFO: 41600 events read in total (2735ms).
[15:43:40.262] INFO: Test took 3966ms.
[15:43:40.296] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:41.020] INFO: Expecting 41600 events.
[15:43:44.270] INFO: 41600 events read in total (2723ms).
[15:43:44.271] INFO: Test took 3956ms.
[15:43:44.306] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:45.028] INFO: Expecting 41600 events.
[15:43:48.293] INFO: 41600 events read in total (2738ms).
[15:43:48.294] INFO: Test took 3970ms.
[15:43:48.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:49.052] INFO: Expecting 41600 events.
[15:43:52.312] INFO: 41600 events read in total (2733ms).
[15:43:52.313] INFO: Test took 3967ms.
[15:43:52.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:53.071] INFO: Expecting 41600 events.
[15:43:56.319] INFO: 41600 events read in total (2721ms).
[15:43:56.320] INFO: Test took 3954ms.
[15:43:56.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:57.080] INFO: Expecting 41600 events.
[15:44:00.327] INFO: 41600 events read in total (2720ms).
[15:44:00.328] INFO: Test took 3956ms.
[15:44:00.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:01.087] INFO: Expecting 41600 events.
[15:44:04.233] INFO: 41600 events read in total (2620ms).
[15:44:04.234] INFO: Test took 3852ms.
[15:44:04.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:04.623] INFO: enter test to run
[15:45:23.287] INFO: test: HighRate no parameter change
[15:45:23.287] INFO: running: highrate
[15:45:23.289] INFO: ----------------------------------------------------------------------
[15:45:23.289] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:45:23.289] INFO: ----------------------------------------------------------------------
[15:45:23.906] INFO: Expecting 208000 events.
[15:45:35.843] INFO: 208000 events read in total (11410ms).
[15:45:35.846] INFO: Test took 12549ms.
[15:45:35.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:36.245] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[15:45:36.260] INFO: number of red-efficiency pixels: 76 69 65 124 156 161 170 97 82 126 126 102 96 55 24 31
[15:45:36.260] INFO: number of X-ray hits detected: 65724 42307 67912 106126 115813 118752 121165 82348 75074 102861 104133 86278 87950 53878 23110 28847
[15:45:36.260] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:45:36.260] INFO: number of Vcal hits detected: 207923 207881 207935 207874 207840 207837 207826 207903 207917 207872 207873 207896 207903 207895 207976 207968
[15:45:36.260] 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
[15:45:36.260] INFO: Vcal hit overall efficiency (%): 100.0 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 99.9 100.0 100.0
[15:45:36.260] INFO: X-ray hit rate [MHz/cm2]: 19.3 12.4 19.9 31.1 33.9 34.8 35.5 24.1 22.0 30.1 30.5 25.3 25.8 15.8 6.8 8.5
[15:45:36.260] INFO: PixTestHighRate::doXPixelAlive() done
[15:45:36.311] INFO: PixTest:: pg_setup set to default.
[15:45:36.327] INFO: enter test to run
[15:46:02.583] INFO: test: HighRate no parameter change
[15:46:02.583] INFO: running: highrate
[15:46:02.584] INFO: ----------------------------------------------------------------------
[15:46:02.584] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:46:02.584] INFO: ----------------------------------------------------------------------
[15:46:03.199] INFO: Expecting 208000 events.
[15:46:16.896] INFO: 208000 events read in total (13170ms).
[15:46:16.902] INFO: Test took 14307ms.
[15:46:17.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:46:17.499] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[15:46:17.499] INFO: number of red-efficiency pixels: 242 143 219 417 573 613 591 293 225 439 433 348 345 190 63 70
[15:46:17.499] INFO: number of X-ray hits detected: 135428 86689 139298 218462 235806 243648 248389 167469 153335 211402 213600 176726 180338 111212 47478 59113
[15:46:17.499] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:46:17.499] INFO: number of Vcal hits detected: 207736 207805 207767 207556 207358 207316 207337 207689 207767 207534 207519 207621 207630 207750 207934 207929
[15:46:17.499] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:46:17.499] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:46:17.499] INFO: X-ray hit rate [MHz/cm2]: 39.7 25.4 40.8 64.0 69.1 71.4 72.8 49.1 44.9 62.0 62.6 51.8 52.9 32.6 13.9 17.3
[15:46:17.499] INFO: PixTestHighRate::doXPixelAlive() done
[15:46:17.545] INFO: PixTest:: pg_setup set to default.
[15:46:17.561] INFO: enter test to run
[15:46:46.863] INFO: test: HighRate no parameter change
[15:46:46.863] INFO: running: highrate
[15:46:46.864] INFO: ----------------------------------------------------------------------
[15:46:46.864] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:46:46.864] INFO: ----------------------------------------------------------------------
[15:46:47.479] INFO: Expecting 208000 events.
[15:47:03.111] INFO: 208000 events read in total (15105ms).
[15:47:03.118] INFO: Test took 16245ms.
[15:47:03.552] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:03.901] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[15:47:03.901] INFO: number of red-efficiency pixels: 539 270 540 1027 1367 1391 1477 646 433 1091 942 784 764 403 83 129
[15:47:03.901] INFO: number of X-ray hits detected: 203411 130970 211559 330813 355846 368134 375290 254368 233083 319613 323386 266254 271869 168389 72349 89750
[15:47:03.902] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:47:03.902] INFO: number of Vcal hits detected: 207304 207659 207327 206742 206184 206073 205912 207221 207513 206638 206831 207061 207100 207493 207916 207870
[15:47:03.902] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.5 99.2 99.2 99.1 99.7 99.8 99.4 99.5 99.6 99.6 99.8 100.0 99.9
[15:47:03.902] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.7 99.4 99.1 99.1 99.0 99.6 99.8 99.3 99.4 99.5 99.6 99.8 100.0 99.9
[15:47:03.902] INFO: X-ray hit rate [MHz/cm2]: 59.6 38.4 62.0 97.0 104.3 107.9 110.0 74.6 68.3 93.7 94.8 78.0 79.7 49.4 21.2 26.3
[15:47:03.902] INFO: PixTestHighRate::doXPixelAlive() done
[15:47:03.951] INFO: PixTest:: pg_setup set to default.
[15:47:03.967] INFO: enter test to run
[15:47:41.718] INFO: test: exit no parameter change
[15:47:42.300] QUIET: Connection to board 33 closed.
[15:47:42.427] INFO: pXar: this is the end, my friend