[15:14:12.145] INFO: *** Welcome to pxar ***
[15:14:12.145] INFO: *** Today: 2016/04/04
[15:14:12.166] INFO: *** Version: v1.9.0-793-ge521-dirty
[15:14:12.166] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//dacParameters35_C15.dat
[15:14:12.170] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:14:12.170] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//defaultMaskFile.dat
[15:14:12.170] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C15.dat
[15:14:12.270] INFO: clk: 4
[15:14:12.270] INFO: ctr: 4
[15:14:12.270] INFO: sda: 19
[15:14:12.270] INFO: tin: 9
[15:14:12.270] INFO: level: 15
[15:14:12.270] INFO: triggerdelay: 0
[15:14:12.270] QUIET: Instanciating API for pxar v1.9.0+793~ge5211a7
[15:14:12.270] INFO: Log level: INFO
[15:14:12.288] QUIET: Connection to board DTB_WREKRL opened.
[15:14:12.291] 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:14:12.294] INFO: RPC call hashes of host and DTB match: 398089610
[15:14:13.821] INFO: DUT info:
[15:14:13.821] INFO: The DUT currently contains the following objects:
[15:14:13.821] INFO: 2 TBM Cores tbm08c (2 ON)
[15:14:13.821] INFO: TBM Core alpha (0): 7 registers set
[15:14:13.821] INFO: TBM Core beta (1): 7 registers set
[15:14:13.822] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:14:13.822] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:13.822] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:14:14.226] INFO: enter 'restricted' command line mode
[15:14:14.226] INFO: enter test to run
[15:14:24.628] INFO: test: PixelAlive no parameter change
[15:14:24.628] INFO: running: pixelalive
[15:14:24.638] INFO: ----------------------------------------------------------------------
[15:14:24.638] 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:14:24.638] INFO: ----------------------------------------------------------------------
[15:14:24.958] INFO: Expecting 41600 events.
[15:14:29.312] INFO: 41600 events read in total (3636ms).
[15:14:29.482] INFO: Test took 4840ms.
[15:14:29.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:29.753] INFO: PixTestAlive::aliveTest() done
[15:14:29.753] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:14:29.785] INFO: enter test to run
[15:15:13.652] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:15:13.652] INFO: running: highrate
[15:15:13.652] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:15:13.882] INFO: ----------------------------------------------------------------------
[15:15:13.882] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:15:13.882] INFO: ----------------------------------------------------------------------
[15:15:13.882] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:15:13.882] INFO: edge/corner pixel THR is adjusted
[15:15:13.882] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:15:14.841] INFO: Collecting data for 5 seconds...
[15:15:19.860] INFO: Done with hot pixel readout
[15:15:32.651] INFO: PixTest:: pg_setup set to default.








[15:15:32.680] INFO: 400 hot pixels found in step 0
[15:15:33.675] INFO: Collecting data for 5 seconds...
[15:15:38.691] INFO: Done with hot pixel readout
[15:15:51.482] INFO: PixTest:: pg_setup set to default.













[15:15:51.484] INFO: 359 hot pixels found in step 1
[15:15:52.480] INFO: Collecting data for 5 seconds...
[15:15:57.496] INFO: Done with hot pixel readout
[15:16:10.268] INFO: PixTest:: pg_setup set to default.


















[15:16:10.269] INFO: 315 hot pixels found in step 2
[15:16:11.269] INFO: Collecting data for 5 seconds...
[15:16:16.287] INFO: Done with hot pixel readout
[15:16:29.092] INFO: PixTest:: pg_setup set to default.






















[15:16:29.094] INFO: 303 hot pixels found in step 3
[15:16:30.093] INFO: Collecting data for 5 seconds...
[15:16:35.110] INFO: Done with hot pixel readout
[15:16:47.903] INFO: PixTest:: pg_setup set to default.
































[15:16:47.905] INFO: 272 hot pixels found in step 4
[15:16:48.905] INFO: Collecting data for 5 seconds...
[15:16:53.921] INFO: Done with hot pixel readout
[15:17:06.752] INFO: PixTest:: pg_setup set to default.










































[15:17:06.754] INFO: 258 hot pixels found in step 5
[15:17:07.753] INFO: Collecting data for 5 seconds...
[15:17:12.771] INFO: Done with hot pixel readout
[15:17:25.590] INFO: PixTest:: pg_setup set to default.































[15:17:25.591] INFO: 215 hot pixels found in step 6
[15:17:26.592] INFO: Collecting data for 5 seconds...
[15:17:31.610] INFO: Done with hot pixel readout
[15:17:44.393] INFO: PixTest:: pg_setup set to default.




















































[15:17:44.396] INFO: 222 hot pixels found in step 7
[15:17:45.395] INFO: Collecting data for 5 seconds...
[15:17:50.411] INFO: Done with hot pixel readout
[15:18:03.201] INFO: PixTest:: pg_setup set to default.


















































[15:18:03.203] INFO: 189 hot pixels found in step 8
[15:18:04.203] INFO: Collecting data for 5 seconds...
[15:18:09.220] INFO: Done with hot pixel readout
[15:18:22.004] INFO: PixTest:: pg_setup set to default.

































































[15:18:22.006] INFO: 196 hot pixels found in step 9
[15:18:23.005] INFO: Collecting data for 5 seconds...
[15:18:28.021] INFO: Done with hot pixel readout
[15:18:40.798] INFO: PixTest:: pg_setup set to default.













































































[15:18:40.800] INFO: 214 hot pixels found in step 10
[15:18:41.800] INFO: Collecting data for 5 seconds...
[15:18:46.816] INFO: Done with hot pixel readout
[15:18:59.614] INFO: PixTest:: pg_setup set to default.





































































[15:18:59.616] INFO: 184 hot pixels found in step 11
[15:19:00.615] INFO: Collecting data for 5 seconds...
[15:19:05.631] INFO: Done with hot pixel readout
[15:19:18.439] INFO: PixTest:: pg_setup set to default.




























































[15:19:18.441] INFO: 158 hot pixels found in step 12
[15:19:19.440] INFO: Collecting data for 5 seconds...
[15:19:24.457] INFO: Done with hot pixel readout
[15:19:34.840] INFO: PixTest:: pg_setup set to default.


































































[15:19:34.843] INFO: 155 hot pixels found in step 13
[15:19:35.841] INFO: Collecting data for 5 seconds...
[15:19:40.856] INFO: Done with hot pixel readout
[15:19:52.195] INFO: PixTest:: pg_setup set to default.














































































[15:19:52.197] INFO: 161 hot pixels found in step 14
[15:19:52.240] INFO: 161 hot pixels could not be trimmed and have been masked.
[15:19:52.244] INFO: PixTest::trimHotPixels() done
[15:19:52.244] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C0.dat
[15:19:52.255] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C1.dat
[15:19:52.260] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C2.dat
[15:19:52.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C3.dat
[15:19:52.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C4.dat
[15:19:52.276] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C5.dat
[15:19:52.281] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C6.dat
[15:19:52.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C7.dat
[15:19:52.292] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C8.dat
[15:19:52.297] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C9.dat
[15:19:52.303] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C10.dat
[15:19:52.308] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C11.dat
[15:19:52.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C12.dat
[15:19:52.318] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C13.dat
[15:19:52.324] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C14.dat
[15:19:52.329] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C15.dat
[15:19:52.334] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//defaultMaskFile.dat
[15:19:52.346] INFO: enter test to run
[15:22:45.680] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:22:45.680] INFO: running: highrate
[15:22:45.685] INFO: ----------------------------------------------------------------------
[15:22:45.685] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:22:45.685] INFO: ----------------------------------------------------------------------
[15:22:45.685] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:22:45.685] INFO: edge/corner pixel THR is adjusted
[15:22:45.685] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:22:46.643] INFO: Collecting data for 1 seconds...
[15:22:47.647] INFO: Done with hot pixel readout
[15:22:51.967] INFO: PixTest:: pg_setup set to default.
[15:22:51.968] INFO: 0 hot pixels found in step 0
[15:22:51.973] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:22:52.051] INFO: PixTest::trimHotPixels() done
[15:22:52.051] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C0.dat
[15:22:52.062] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C1.dat
[15:22:52.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C2.dat
[15:22:52.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C3.dat
[15:22:52.079] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C4.dat
[15:22:52.084] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C5.dat
[15:22:52.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C6.dat
[15:22:52.095] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C7.dat
[15:22:52.100] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C8.dat
[15:22:52.105] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C9.dat
[15:22:52.111] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C10.dat
[15:22:52.116] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C11.dat
[15:22:52.121] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C12.dat
[15:22:52.127] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C13.dat
[15:22:52.132] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C14.dat
[15:22:52.138] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//trimParameters35_C15.dat
[15:22:52.143] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-45_FPIXTest-17C-FNAL-160401-0926_2016-04-01_09h26m_1459520774/000_FPIXTest_p17//defaultMaskFile.dat
[15:22:52.153] INFO: enter test to run
[15:23:11.056] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:23:11.056] INFO: running: xray
[15:23:11.057] INFO: ----------------------------------------------------------------------
[15:23:11.057] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:23:11.057] INFO: ----------------------------------------------------------------------
[15:23:12.020] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:23:22.432] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[15:23:51.872] INFO: Resuming triggers.
[15:24:02.290] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:24:31.991] INFO: Resuming triggers.
[15:24:42.405] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[15:25:12.051] INFO: Resuming triggers.
[15:25:22.463] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[15:25:52.065] INFO: Resuming triggers.
[15:26:02.482] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[15:26:32.106] INFO: Resuming triggers.
[15:26:42.519] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[15:27:12.224] INFO: Resuming triggers.
[15:27:22.645] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:27:52.238] INFO: Resuming triggers.
[15:28:02.651] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:28:32.169] INFO: Resuming triggers.
[15:28:42.581] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:29:12.172] INFO: Resuming triggers.
[15:29:18.782] INFO: data taking finished, elapsed time: 100 seconds.
[15:29:37.618] INFO: PixTest:: pg_setup set to default.
[15:29:37.621] INFO: PixTestXray::doPhRun() done
[15:29:37.761] INFO: enter test to run
[15:30:02.397] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:30:02.397] INFO: running: xray
[15:30:02.399] INFO: ----------------------------------------------------------------------
[15:30:02.399] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:30:02.399] INFO: ----------------------------------------------------------------------
[15:30:03.363] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:30:09.302] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[15:30:39.358] INFO: Resuming triggers.
[15:30:45.299] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:31:15.352] INFO: Resuming triggers.
[15:31:21.294] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[15:31:51.374] INFO: Resuming triggers.
[15:31:57.315] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:32:27.461] INFO: Resuming triggers.
[15:32:33.404] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[15:33:03.538] INFO: Resuming triggers.
[15:33:09.476] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[15:33:39.555] INFO: Resuming triggers.
[15:33:45.495] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[15:34:15.596] INFO: Resuming triggers.
[15:34:21.538] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[15:34:51.684] INFO: Resuming triggers.
[15:34:57.624] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:35:27.776] INFO: Resuming triggers.
[15:35:33.718] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:36:03.803] INFO: Resuming triggers.
[15:36:09.745] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[15:36:39.840] INFO: Resuming triggers.
[15:36:45.783] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[15:37:15.938] INFO: Resuming triggers.
[15:37:21.882] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[15:37:52.045] INFO: Resuming triggers.
[15:37:57.986] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[15:38:28.061] INFO: Resuming triggers.
[15:38:34.003] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[15:39:04.140] INFO: Resuming triggers.
[15:39:10.087] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[15:39:40.321] INFO: Resuming triggers.
[15:39:45.582] INFO: data taking finished, elapsed time: 100 seconds.
[15:40:10.349] INFO: PixTest:: pg_setup set to default.
[15:40:10.352] INFO: PixTestXray::doPhRun() done
[15:40:10.501] INFO: enter test to run
[15:41:45.520] INFO: test: HighRate no parameter change
[15:41:45.520] INFO: running: highrate
[15:41:45.521] INFO: ----------------------------------------------------------------------
[15:41:45.521] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:41:45.521] INFO: ----------------------------------------------------------------------
[15:41:45.663] INFO: Expecting 768 events.
[15:41:46.797] INFO: 768 events read in total (419ms).
[15:41:46.797] INFO: Test took 1269ms.
[15:41:47.600] INFO: Expecting 41600 events.
[15:41:50.787] INFO: 41600 events read in total (2660ms).
[15:41:50.788] INFO: Test took 3983ms.
[15:41:50.826] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:51.543] INFO: Expecting 41600 events.
[15:41:54.812] INFO: 41600 events read in total (2742ms).
[15:41:54.813] INFO: Test took 3968ms.
[15:41:54.851] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:55.569] INFO: Expecting 41600 events.
[15:41:58.832] INFO: 41600 events read in total (2736ms).
[15:41:58.833] INFO: Test took 3964ms.
[15:41:58.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:59.587] INFO: Expecting 41600 events.
[15:42:02.850] INFO: 41600 events read in total (2736ms).
[15:42:02.851] INFO: Test took 3961ms.
[15:42:02.888] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:03.605] INFO: Expecting 41600 events.
[15:42:06.884] INFO: 41600 events read in total (2752ms).
[15:42:06.885] INFO: Test took 3978ms.
[15:42:06.923] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:07.642] INFO: Expecting 41600 events.
[15:42:10.925] INFO: 41600 events read in total (2757ms).
[15:42:10.926] INFO: Test took 3983ms.
[15:42:10.964] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:11.679] INFO: Expecting 41600 events.
[15:42:14.961] INFO: 41600 events read in total (2755ms).
[15:42:14.962] INFO: Test took 3978ms.
[15:42:14.000] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:15.717] INFO: Expecting 41600 events.
[15:42:19.014] INFO: 41600 events read in total (2770ms).
[15:42:19.015] INFO: Test took 3997ms.
[15:42:19.054] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:19.768] INFO: Expecting 41600 events.
[15:42:23.058] INFO: 41600 events read in total (2763ms).
[15:42:23.059] INFO: Test took 3987ms.
[15:42:23.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:23.813] INFO: Expecting 41600 events.
[15:42:27.104] INFO: 41600 events read in total (2764ms).
[15:42:27.105] INFO: Test took 3988ms.
[15:42:27.142] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:27.861] INFO: Expecting 41600 events.
[15:42:31.139] INFO: 41600 events read in total (2752ms).
[15:42:31.140] INFO: Test took 3978ms.
[15:42:31.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:31.895] INFO: Expecting 41600 events.
[15:42:35.190] INFO: 41600 events read in total (2768ms).
[15:42:35.191] INFO: Test took 3993ms.
[15:42:35.229] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:35.945] INFO: Expecting 41600 events.
[15:42:39.235] INFO: 41600 events read in total (2764ms).
[15:42:39.237] INFO: Test took 3988ms.
[15:42:39.274] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:39.993] INFO: Expecting 41600 events.
[15:42:43.266] INFO: 41600 events read in total (2746ms).
[15:42:43.267] INFO: Test took 3973ms.
[15:42:43.305] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:44.021] INFO: Expecting 41600 events.
[15:42:47.310] INFO: 41600 events read in total (2762ms).
[15:42:47.311] INFO: Test took 3987ms.
[15:42:47.350] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:48.064] INFO: Expecting 41600 events.
[15:42:51.355] INFO: 41600 events read in total (2764ms).
[15:42:51.356] INFO: Test took 3987ms.
[15:42:51.393] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:52.110] INFO: Expecting 41600 events.
[15:42:55.409] INFO: 41600 events read in total (2772ms).
[15:42:55.410] INFO: Test took 3998ms.
[15:42:55.449] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:56.162] INFO: Expecting 41600 events.
[15:42:59.453] INFO: 41600 events read in total (2764ms).
[15:42:59.454] INFO: Test took 3986ms.
[15:42:59.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:00.206] INFO: Expecting 41600 events.
[15:43:03.439] INFO: 41600 events read in total (2706ms).
[15:43:03.440] INFO: Test took 3928ms.
[15:43:03.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:04.195] INFO: Expecting 41600 events.
[15:43:07.309] INFO: 41600 events read in total (2588ms).
[15:43:07.310] INFO: Test took 3814ms.
[15:43:07.347] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:07.697] INFO: enter test to run
[15:44:42.871] INFO: test: HighRate no parameter change
[15:44:42.871] INFO: running: highrate
[15:44:42.872] INFO: ----------------------------------------------------------------------
[15:44:42.872] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:44:42.872] INFO: ----------------------------------------------------------------------
[15:44:43.489] INFO: Expecting 208000 events.
[15:44:55.624] INFO: 208000 events read in total (11608ms).
[15:44:55.628] INFO: Test took 12746ms.
[15:44:55.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:56.052] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:44:56.052] INFO: number of red-efficiency pixels: 81 50 67 182 176 196 179 150 125 161 103 146 129 75 31 25
[15:44:56.052] INFO: number of X-ray hits detected: 70951 49116 71299 123058 130779 138517 137710 101606 92941 111333 105124 94920 99710 59802 26449 28301
[15:44:56.052] 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:44:56.052] INFO: number of Vcal hits detected: 207918 207946 207932 207811 207818 207796 207816 207847 207871 207835 207894 207852 207869 207922 207969 207975
[15:44:56.052] INFO: Vcal hit fiducial efficiency (%): 100.0 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
[15:44:56.052] INFO: Vcal hit overall efficiency (%): 100.0 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
[15:44:56.053] INFO: X-ray hit rate [MHz/cm2]: 20.8 14.4 20.9 36.1 38.3 40.6 40.4 29.8 27.2 32.6 30.8 27.8 29.2 17.5 7.8 8.3
[15:44:56.053] INFO: PixTestHighRate::doXPixelAlive() done
[15:44:56.101] INFO: PixTest:: pg_setup set to default.
[15:44:56.111] INFO: enter test to run
[15:45:08.558] INFO: test: HighRate no parameter change
[15:45:08.558] INFO: running: highrate
[15:45:08.560] INFO: ----------------------------------------------------------------------
[15:45:08.560] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:45:08.560] INFO: ----------------------------------------------------------------------
[15:45:09.177] INFO: Expecting 208000 events.
[15:45:23.631] INFO: 208000 events read in total (13927ms).
[15:45:23.637] INFO: Test took 15069ms.
[15:45:23.979] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:24.303] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:45:24.303] INFO: number of red-efficiency pixels: 245 183 299 765 791 650 656 549 445 584 406 478 382 285 71 79
[15:45:24.303] INFO: number of X-ray hits detected: 155985 107721 156709 269865 286412 303770 301274 222818 203650 242436 230659 207266 219074 131142 57635 62141
[15:45:24.303] 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:24.303] INFO: number of Vcal hits detected: 207732 207812 207668 207098 207095 207253 207264 207367 207517 207346 207565 207472 207592 207694 207927 207920
[15:45:24.303] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.6 99.6 99.7 99.7 99.7 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[15:45:24.303] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.6 99.6 99.6 99.6 99.7 99.8 99.7 99.8 99.7 99.8 99.9 100.0 100.0
[15:45:24.303] INFO: X-ray hit rate [MHz/cm2]: 45.7 31.6 45.9 79.1 83.9 89.0 88.3 65.3 59.7 71.1 67.6 60.8 64.2 38.4 16.9 18.2
[15:45:24.303] INFO: PixTestHighRate::doXPixelAlive() done
[15:45:24.352] INFO: PixTest:: pg_setup set to default.
[15:45:24.368] INFO: enter test to run
[15:45:40.622] INFO: test: HighRate no parameter change
[15:45:40.622] INFO: running: highrate
[15:45:40.623] INFO: ----------------------------------------------------------------------
[15:45:40.623] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:45:40.623] INFO: ----------------------------------------------------------------------
[15:45:41.236] INFO: Expecting 208000 events.
[15:45:57.909] INFO: 208000 events read in total (16146ms).
[15:45:57.917] INFO: Test took 17285ms.
[15:45:58.468] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:58.845] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:45:58.845] INFO: number of red-efficiency pixels: 594 332 573 1565 1809 1429 1472 1196 923 1249 876 997 733 629 120 126
[15:45:58.845] INFO: number of X-ray hits detected: 227654 156715 229314 393576 418478 442419 442108 327034 299314 356005 338132 304666 321150 191943 84782 90985
[15:45:58.845] 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:58.845] INFO: number of Vcal hits detected: 207310 207638 207232 205770 205289 205971 205902 206224 206842 206352 206987 206745 207156 207198 207871 207872
[15:45:58.845] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.7 99.0 98.8 99.1 99.1 99.2 99.5 99.3 99.6 99.5 99.6 99.7 99.9 99.9
[15:45:58.845] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 98.9 98.7 99.0 99.0 99.1 99.4 99.2 99.5 99.4 99.6 99.6 99.9 99.9
[15:45:58.845] INFO: X-ray hit rate [MHz/cm2]: 66.7 45.9 67.2 115.4 122.7 129.7 129.6 95.9 87.7 104.3 99.1 89.3 94.1 56.3 24.9 26.7
[15:45:58.845] INFO: PixTestHighRate::doXPixelAlive() done
[15:45:58.898] INFO: PixTest:: pg_setup set to default.
[15:45:58.910] INFO: enter test to run
[15:46:08.878] INFO: test: exit no parameter change
[15:46:09.257] QUIET: Connection to board 33 closed.
[15:46:09.258] INFO: pXar: this is the end, my friend