[10:24:38.002] INFO: *** Welcome to pxar ***
[10:24:38.003] INFO: *** Today: 2016/07/21
[10:24:38.768] INFO: *** Version: v1.9.0-814-g7497
[10:24:38.768] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//dacParameters35_C15.dat
[10:24:38.866] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:24:38.866] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//defaultMaskFile.dat
[10:24:38.868] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C15.dat
[10:24:38.976] INFO: clk: 4
[10:24:38.976] INFO: ctr: 4
[10:24:38.976] INFO: sda: 19
[10:24:38.976] INFO: tin: 9
[10:24:38.976] INFO: level: 15
[10:24:38.976] INFO: triggerdelay: 0
[10:24:38.976] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[10:24:38.976] INFO: Log level: INFO
[10:24:38.991] QUIET: Connection to board DTB_WREKRL opened.
[10:24:38.995] 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:24:38.997] INFO: RPC call hashes of host and DTB match: 398089610
[10:24:40.537] INFO: DUT info:
[10:24:40.537] INFO: The DUT currently contains the following objects:
[10:24:40.537] INFO: 2 TBM Cores tbm08c (2 ON)
[10:24:40.552] INFO: TBM Core alpha (0): 7 registers set
[10:24:40.552] INFO: TBM Core beta (1): 7 registers set
[10:24:40.552] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:24:40.552] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.552] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:24:40.996] INFO: enter 'restricted' command line mode
[10:24:40.996] INFO: enter test to run
[10:24:49.747] INFO: test: PixelAlive no parameter change
[10:24:49.747] INFO: running: pixelalive
[10:24:49.816] INFO: ----------------------------------------------------------------------
[10:24:49.816] 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:24:49.816] INFO: ----------------------------------------------------------------------
[10:24:50.137] INFO: Expecting 41600 events.
[10:24:54.529] INFO: 41600 events read in total (3673ms).
[10:24:54.693] INFO: Test took 4875ms.
[10:24:54.702] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:54.991] INFO: PixTestAlive::aliveTest() done
[10:24:54.991] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 3 0 0
[10:24:55.020] INFO: enter test to run
[10:25:34.459] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:25:34.459] INFO: running: highrate
[10:25:34.486] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:25:34.733] INFO: ----------------------------------------------------------------------
[10:25:34.733] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:25:34.733] INFO: ----------------------------------------------------------------------
[10:25:34.733] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:25:34.733] INFO: edge/corner pixel THR is adjusted
[10:25:34.733] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:25:35.715] INFO: Collecting data for 5 seconds...
[10:25:40.734] INFO: Done with hot pixel readout
[10:25:53.793] INFO: PixTest:: pg_setup set to default.
























[10:25:53.826] INFO: 585 hot pixels found in step 0
[10:25:54.822] INFO: Collecting data for 5 seconds...
[10:25:59.839] INFO: Done with hot pixel readout
[10:26:13.086] INFO: PixTest:: pg_setup set to default.





































[10:26:13.088] INFO: 598 hot pixels found in step 1
[10:26:14.087] INFO: Collecting data for 5 seconds...
[10:26:19.104] INFO: Done with hot pixel readout
[10:26:32.522] INFO: PixTest:: pg_setup set to default.

































































[10:26:32.525] INFO: 543 hot pixels found in step 2
[10:26:33.526] INFO: Collecting data for 5 seconds...
[10:26:38.543] INFO: Done with hot pixel readout
[10:26:51.888] INFO: PixTest:: pg_setup set to default.




























































































[10:26:51.891] INFO: 540 hot pixels found in step 3
[10:26:52.894] INFO: Collecting data for 5 seconds...
[10:26:57.910] INFO: Done with hot pixel readout
[10:27:11.202] INFO: PixTest:: pg_setup set to default.










































































































[10:27:11.205] INFO: 473 hot pixels found in step 4
[10:27:12.207] INFO: Collecting data for 5 seconds...
[10:27:17.224] INFO: Done with hot pixel readout
[10:27:30.440] INFO: PixTest:: pg_setup set to default.
















































































































[10:27:30.443] INFO: 445 hot pixels found in step 5
[10:27:31.445] INFO: Collecting data for 5 seconds...
[10:27:36.462] INFO: Done with hot pixel readout
[10:27:49.844] INFO: PixTest:: pg_setup set to default.



































































































































[10:27:49.847] INFO: 389 hot pixels found in step 6
[10:27:50.849] INFO: Collecting data for 5 seconds...
[10:27:55.866] INFO: Done with hot pixel readout
[10:28:09.230] INFO: PixTest:: pg_setup set to default.






































































































































[10:28:09.233] INFO: 397 hot pixels found in step 7
[10:28:10.239] INFO: Collecting data for 5 seconds...
[10:28:15.256] INFO: Done with hot pixel readout
[10:28:28.592] INFO: PixTest:: pg_setup set to default.


























































































































































[10:28:28.603] INFO: 353 hot pixels found in step 8
[10:28:29.605] INFO: Collecting data for 5 seconds...
[10:28:34.622] INFO: Done with hot pixel readout
[10:28:47.997] INFO: PixTest:: pg_setup set to default.















































































































































[10:28:48.009] INFO: 368 hot pixels found in step 9
[10:28:49.012] INFO: Collecting data for 5 seconds...
[10:28:54.028] INFO: Done with hot pixel readout
[10:29:07.474] INFO: PixTest:: pg_setup set to default.

























































































































































[10:29:07.490] INFO: 325 hot pixels found in step 10
[10:29:08.496] INFO: Collecting data for 5 seconds...
[10:29:13.512] INFO: Done with hot pixel readout
[10:29:26.915] INFO: PixTest:: pg_setup set to default.





























































































































































[10:29:26.931] INFO: 332 hot pixels found in step 11
[10:29:27.936] INFO: Collecting data for 5 seconds...
[10:29:32.952] INFO: Done with hot pixel readout
[10:29:46.244] INFO: PixTest:: pg_setup set to default.












































































































































































[10:29:46.260] INFO: 317 hot pixels found in step 12
[10:29:47.268] INFO: Collecting data for 5 seconds...
[10:29:52.284] INFO: Done with hot pixel readout
[10:30:05.580] INFO: PixTest:: pg_setup set to default.









































































































































































[10:30:05.596] INFO: 309 hot pixels found in step 13
[10:30:06.601] INFO: Collecting data for 5 seconds...
[10:30:11.618] INFO: Done with hot pixel readout
[10:30:25.088] INFO: PixTest:: pg_setup set to default.





































































































































































[10:30:25.104] INFO: 300 hot pixels found in step 14
[10:30:25.156] INFO: 300 hot pixels could not be trimmed and have been masked.
[10:30:25.174] INFO: PixTest::trimHotPixels() done
[10:30:25.174] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C0.dat
[10:30:25.186] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C1.dat
[10:30:25.193] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C2.dat
[10:30:25.199] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C3.dat
[10:30:25.204] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C4.dat
[10:30:25.209] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C5.dat
[10:30:25.215] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C6.dat
[10:30:25.220] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C7.dat
[10:30:25.225] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C8.dat
[10:30:25.230] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C9.dat
[10:30:25.236] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C10.dat
[10:30:25.241] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C11.dat
[10:30:25.246] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C12.dat
[10:30:25.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C13.dat
[10:30:25.257] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C14.dat
[10:30:25.262] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C15.dat
[10:30:25.267] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//defaultMaskFile.dat
[10:30:25.279] INFO: enter test to run
[10:31:13.592] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:31:13.592] INFO: running: highrate
[10:31:13.597] INFO: ----------------------------------------------------------------------
[10:31:13.597] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:31:13.597] INFO: ----------------------------------------------------------------------
[10:31:13.597] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:31:13.597] INFO: edge/corner pixel THR is adjusted
[10:31:13.597] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:31:14.555] INFO: Collecting data for 1 seconds...
[10:31:15.559] INFO: Done with hot pixel readout
[10:31:20.447] INFO: PixTest:: pg_setup set to default.
[10:31:20.448] INFO: 0 hot pixels found in step 0
[10:31:20.454] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:31:20.512] INFO: PixTest::trimHotPixels() done
[10:31:20.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C0.dat
[10:31:20.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C1.dat
[10:31:20.535] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C2.dat
[10:31:20.540] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C3.dat
[10:31:20.545] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C4.dat
[10:31:20.551] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C5.dat
[10:31:20.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C6.dat
[10:31:20.561] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C7.dat
[10:31:20.566] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C8.dat
[10:31:20.571] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C9.dat
[10:31:20.576] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C10.dat
[10:31:20.582] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C11.dat
[10:31:20.587] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C12.dat
[10:31:20.592] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C13.dat
[10:31:20.597] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C14.dat
[10:31:20.602] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C15.dat
[10:31:20.608] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-M-NT_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//defaultMaskFile.dat
[10:31:20.617] INFO: enter test to run
[10:32:15.032] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:32:15.032] INFO: running: xray
[10:32:15.033] INFO: ----------------------------------------------------------------------
[10:32:15.033] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:32:15.033] INFO: ----------------------------------------------------------------------
[10:32:15.996] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:32:25.885] INFO: run duration 9 seconds, buffer almost full (81%), pausing triggers.
[10:32:55.549] INFO: Resuming triggers.
[10:33:05.440] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[10:33:35.285] INFO: Resuming triggers.
[10:33:45.176] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[10:34:15.278] INFO: Resuming triggers.
[10:34:25.165] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[10:34:54.108] INFO: Resuming triggers.
[10:35:03.997] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[10:35:33.898] INFO: Resuming triggers.
[10:35:43.789] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[10:36:14.429] INFO: Resuming triggers.
[10:36:24.318] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[10:36:54.726] INFO: Resuming triggers.
[10:37:04.615] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[10:37:35.169] INFO: Resuming triggers.
[10:37:45.057] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:38:14.737] INFO: Resuming triggers.
[10:38:24.630] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[10:38:54.204] INFO: Resuming triggers.
[10:38:55.668] INFO: data taking finished, elapsed time: 100 seconds.
[10:39:00.472] INFO: PixTest:: pg_setup set to default.
[10:39:00.476] INFO: PixTestXray::doPhRun() done
[10:39:00.617] INFO: enter test to run
[10:39:56.125] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:39:56.125] INFO: running: xray
[10:39:56.126] INFO: ----------------------------------------------------------------------
[10:39:56.126] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:39:56.126] INFO: ----------------------------------------------------------------------
[10:39:57.097] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:40:02.356] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[10:40:32.554] INFO: Resuming triggers.
[10:40:37.813] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[10:41:07.984] INFO: Resuming triggers.
[10:41:13.244] INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[10:41:43.449] INFO: Resuming triggers.
[10:41:48.712] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[10:42:18.878] INFO: Resuming triggers.
[10:42:24.134] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[10:42:54.446] INFO: Resuming triggers.
[10:42:59.706] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[10:43:29.888] INFO: Resuming triggers.
[10:43:35.144] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[10:44:05.678] INFO: Resuming triggers.
[10:44:10.938] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[10:44:41.104] INFO: Resuming triggers.
[10:44:46.360] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[10:45:16.652] INFO: Resuming triggers.
[10:45:21.904] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[10:45:52.170] INFO: Resuming triggers.
[10:45:57.424] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[10:46:28.837] INFO: Resuming triggers.
[10:46:34.097] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[10:47:04.863] INFO: Resuming triggers.
[10:47:10.120] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[10:47:40.920] INFO: Resuming triggers.
[10:47:46.177] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[10:48:17.997] INFO: Resuming triggers.
[10:48:23.252] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[10:48:54.820] INFO: Resuming triggers.
[10:49:00.078] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[10:49:30.998] INFO: Resuming triggers.
[10:49:36.252] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[10:50:06.423] INFO: Resuming triggers.
[10:50:11.686] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[10:50:41.830] INFO: Resuming triggers.
[10:50:47.091] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[10:51:17.149] INFO: Resuming triggers.
[10:51:17.595] INFO: data taking finished, elapsed time: 100 seconds.
[10:51:20.530] INFO: PixTest:: pg_setup set to default.
[10:51:20.533] INFO: PixTestXray::doPhRun() done
[10:51:20.687] INFO: enter test to run
[10:51:51.504] INFO: test: HighRate no parameter change
[10:51:51.504] INFO: running: highrate
[10:51:51.520] INFO: ----------------------------------------------------------------------
[10:51:51.521] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:51:51.521] INFO: ----------------------------------------------------------------------
[10:51:51.662] INFO: Expecting 768 events.
[10:51:52.797] INFO: 768 events read in total (419ms).
[10:51:52.797] INFO: Test took 1269ms.
[10:51:53.600] INFO: Expecting 41600 events.
[10:51:56.801] INFO: 41600 events read in total (2674ms).
[10:51:56.802] INFO: Test took 3997ms.
[10:51:56.846] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:57.552] INFO: Expecting 41600 events.
[10:52:00.853] INFO: 41600 events read in total (2774ms).
[10:52:00.854] INFO: Test took 3987ms.
[10:52:00.899] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:01.604] INFO: Expecting 41600 events.
[10:52:04.942] INFO: 41600 events read in total (2811ms).
[10:52:04.943] INFO: Test took 4022ms.
[10:52:04.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:05.689] INFO: Expecting 41600 events.
[10:52:09.059] INFO: 41600 events read in total (2844ms).
[10:52:09.060] INFO: Test took 4047ms.
[10:52:09.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:09.808] INFO: Expecting 41600 events.
[10:52:13.167] INFO: 41600 events read in total (2832ms).
[10:52:13.168] INFO: Test took 4038ms.
[10:52:13.216] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:13.917] INFO: Expecting 41600 events.
[10:52:17.231] INFO: 41600 events read in total (2787ms).
[10:52:17.232] INFO: Test took 3994ms.
[10:52:17.279] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:17.979] INFO: Expecting 41600 events.
[10:52:21.345] INFO: 41600 events read in total (2839ms).
[10:52:21.346] INFO: Test took 4044ms.
[10:52:21.393] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:22.092] INFO: Expecting 41600 events.
[10:52:25.467] INFO: 41600 events read in total (2848ms).
[10:52:25.468] INFO: Test took 4052ms.
[10:52:25.514] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:26.216] INFO: Expecting 41600 events.
[10:52:29.581] INFO: 41600 events read in total (2839ms).
[10:52:29.583] INFO: Test took 4046ms.
[10:52:29.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:30.331] INFO: Expecting 41600 events.
[10:52:33.720] INFO: 41600 events read in total (2863ms).
[10:52:33.721] INFO: Test took 4069ms.
[10:52:33.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:34.469] INFO: Expecting 41600 events.
[10:52:37.834] INFO: 41600 events read in total (2838ms).
[10:52:37.836] INFO: Test took 4047ms.
[10:52:37.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:38.581] INFO: Expecting 41600 events.
[10:52:41.940] INFO: 41600 events read in total (2832ms).
[10:52:41.941] INFO: Test took 4035ms.
[10:52:41.988] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:42.689] INFO: Expecting 41600 events.
[10:52:46.053] INFO: 41600 events read in total (2837ms).
[10:52:46.054] INFO: Test took 4044ms.
[10:52:46.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:46.799] INFO: Expecting 41600 events.
[10:52:50.180] INFO: 41600 events read in total (2854ms).
[10:52:50.182] INFO: Test took 4059ms.
[10:52:50.229] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:50.925] INFO: Expecting 41600 events.
[10:52:54.288] INFO: 41600 events read in total (2836ms).
[10:52:54.289] INFO: Test took 4039ms.
[10:52:54.337] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:55.036] INFO: Expecting 41600 events.
[10:52:58.404] INFO: 41600 events read in total (2841ms).
[10:52:58.405] INFO: Test took 4046ms.
[10:52:58.450] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:59.154] INFO: Expecting 41600 events.
[10:53:02.510] INFO: 41600 events read in total (2829ms).
[10:53:02.511] INFO: Test took 4038ms.
[10:53:02.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:03.260] INFO: Expecting 41600 events.
[10:53:06.637] INFO: 41600 events read in total (2850ms).
[10:53:06.638] INFO: Test took 4057ms.
[10:53:06.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:07.386] INFO: Expecting 41600 events.
[10:53:10.727] INFO: 41600 events read in total (2814ms).
[10:53:10.728] INFO: Test took 4020ms.
[10:53:10.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:11.475] INFO: Expecting 41600 events.
[10:53:14.684] INFO: 41600 events read in total (2682ms).
[10:53:14.685] INFO: Test took 3885ms.
[10:53:14.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:15.080] INFO: enter test to run
[10:53:35.247] INFO: test: HighRate no parameter change
[10:53:35.247] INFO: running: highrate
[10:53:35.249] INFO: ----------------------------------------------------------------------
[10:53:35.249] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:53:35.249] INFO: ----------------------------------------------------------------------
[10:53:35.864] INFO: Expecting 208000 events.
[10:53:48.406] INFO: 208000 events read in total (12016ms).
[10:53:48.410] INFO: Test took 13151ms.
[10:53:48.622] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:48.896] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 1 0 3 0 0
[10:53:48.896] INFO: number of red-efficiency pixels: 127 67 103 217 228 199 255 173 146 160 215 172 162 107 30 46
[10:53:48.896] INFO: number of X-ray hits detected: 88154 60411 103280 160364 165690 163339 163055 126601 121757 137990 138885 128927 125791 79654 30726 35027
[10:53:48.896] 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:53:48.896] INFO: number of Vcal hits detected: 207869 207931 207897 207775 207765 207792 207730 207773 207851 207833 207776 207777 207808 207743 207970 207954
[10:53:48.896] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:53:48.897] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[10:53:48.897] INFO: X-ray hit rate [MHz/cm2]: 25.8 17.7 30.3 47.0 48.6 47.9 47.8 37.1 35.7 40.4 40.7 37.8 36.9 23.3 9.0 10.3
[10:53:48.897] INFO: PixTestHighRate::doXPixelAlive() done
[10:53:48.942] INFO: PixTest:: pg_setup set to default.
[10:53:48.960] INFO: enter test to run
[10:54:17.295] INFO: test: HighRate no parameter change
[10:54:17.295] INFO: running: highrate
[10:54:17.296] INFO: ----------------------------------------------------------------------
[10:54:17.296] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:54:17.296] INFO: ----------------------------------------------------------------------
[10:54:17.914] INFO: Expecting 208000 events.
[10:54:33.120] INFO: 208000 events read in total (14679ms).
[10:54:33.127] INFO: Test took 15822ms.
[10:54:33.551] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:33.895] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 1 0 3 0 0
[10:54:33.895] INFO: number of red-efficiency pixels: 403 228 446 866 874 823 1086 770 500 574 814 541 509 344 62 98
[10:54:33.895] INFO: number of X-ray hits detected: 179913 124943 209460 327098 338145 333423 333200 258785 250304 283543 284128 262560 258535 164723 62717 72377
[10:54:33.895] 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:54:33.895] INFO: number of Vcal hits detected: 207530 207747 207472 206978 206941 207044 206655 207030 207456 207370 207041 207344 207393 207470 207936 207901
[10:54:33.895] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.5 99.6 99.4 99.6 99.7 99.7 99.6 99.7 99.7 99.8 100.0 100.0
[10:54:33.895] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.5 99.5 99.5 99.4 99.5 99.7 99.7 99.5 99.7 99.7 99.7 100.0 100.0
[10:54:33.895] INFO: X-ray hit rate [MHz/cm2]: 52.7 36.6 61.4 95.9 99.1 97.7 97.7 75.9 73.4 83.1 83.3 77.0 75.8 48.3 18.4 21.2
[10:54:33.895] INFO: PixTestHighRate::doXPixelAlive() done
[10:54:33.946] INFO: PixTest:: pg_setup set to default.
[10:54:33.964] INFO: enter test to run
[10:55:00.415] INFO: test: HighRate no parameter change
[10:55:00.415] INFO: running: highrate
[10:55:00.416] INFO: ----------------------------------------------------------------------
[10:55:00.416] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:55:00.416] INFO: ----------------------------------------------------------------------
[10:55:01.033] INFO: Expecting 208000 events.
[10:55:19.376] INFO: 208000 events read in total (17816ms).
[10:55:19.386] INFO: Test took 18961ms.
[10:55:20.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:55:20.445] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 1 0 3 0 0
[10:55:20.445] INFO: number of red-efficiency pixels: 799 482 1018 1886 2018 1900 2372 1679 1240 1409 1833 1262 1143 783 134 158
[10:55:20.445] INFO: number of X-ray hits detected: 271278 187766 317343 491803 510110 500081 502123 390399 377312 426056 428117 397164 388960 248794 95386 108854
[10:55:20.445] 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:55:20.445] INFO: number of Vcal hits detected: 206808 207384 206434 205037 204738 204985 203596 205300 206406 206058 205181 206161 206462 206745 207861 207835
[10:55:20.445] INFO: Vcal hit fiducial efficiency (%): 99.5 99.7 99.3 98.7 98.6 98.7 98.1 98.8 99.3 99.2 98.8 99.3 99.3 99.5 99.9 99.9
[10:55:20.445] INFO: Vcal hit overall efficiency (%): 99.4 99.7 99.2 98.6 98.4 98.6 97.9 98.7 99.2 99.1 98.6 99.1 99.3 99.4 99.9 99.9
[10:55:20.445] INFO: X-ray hit rate [MHz/cm2]: 79.5 55.0 93.0 144.2 149.5 146.6 147.2 114.4 110.6 124.9 125.5 116.4 114.0 72.9 28.0 31.9
[10:55:20.445] INFO: PixTestHighRate::doXPixelAlive() done
[10:55:20.490] INFO: PixTest:: pg_setup set to default.
[10:55:20.505] INFO: enter test to run
[10:55:49.334] INFO: test: exit no parameter change
[10:55:49.718] QUIET: Connection to board 33 closed.
[10:55:49.733] INFO: pXar: this is the end, my friend