[12:43:05.652] INFO: *** Welcome to pxar ***
[12:43:05.652] INFO: *** Today: 2016/05/11
[12:43:05.671] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:43:05.671] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//dacParameters35_C15.dat
[12:43:06.185] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:43:06.185] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//defaultMaskFile.dat
[12:43:06.209] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C15.dat
[12:43:07.328] INFO: clk: 4
[12:43:07.329] INFO: ctr: 4
[12:43:07.329] INFO: sda: 19
[12:43:07.329] INFO: tin: 9
[12:43:07.329] INFO: level: 15
[12:43:07.329] INFO: triggerdelay: 0
[12:43:07.329] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:43:07.329] INFO: Log level: INFO
[12:43:07.346] QUIET: Connection to board DTB_WREKRL opened.
[12:43:07.349] 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:
------------------------------------------------------
[12:43:07.352] INFO: RPC call hashes of host and DTB match: 398089610
[12:43:08.884] INFO: DUT info:
[12:43:08.884] INFO: The DUT currently contains the following objects:
[12:43:08.884] INFO: 2 TBM Cores tbm08c (2 ON)
[12:43:08.884] INFO: TBM Core alpha (0): 7 registers set
[12:43:08.884] INFO: TBM Core beta (1): 7 registers set
[12:43:08.885] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:43:08.885] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:08.885] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:43:09.362] INFO: enter 'restricted' command line mode
[12:43:09.362] INFO: enter test to run
[12:43:23.597] INFO: test: PixelAlive no parameter change
[12:43:23.597] INFO: running: pixelalive
[12:43:23.606] INFO: ----------------------------------------------------------------------
[12:43:23.606] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:43:23.606] INFO: ----------------------------------------------------------------------
[12:43:23.924] INFO: Expecting 41600 events.
[12:43:28.223] INFO: 41600 events read in total (3580ms).
[12:43:28.388] INFO: Test took 4780ms.
[12:43:28.397] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:28.668] INFO: PixTestAlive::aliveTest() done
[12:43:28.668] INFO: number of dead pixels (per ROC): 0 0 0 11 0 0 0 0 0 0 0 0 0 0 0 0
[12:43:28.701] INFO: enter test to run
[12:43:46.596] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:43:46.596] INFO: running: highrate
[12:43:46.597] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:43:47.874] INFO: ----------------------------------------------------------------------
[12:43:47.874] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:43:47.874] INFO: ----------------------------------------------------------------------
[12:43:47.874] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:43:47.874] INFO: edge/corner pixel THR is adjusted
[12:43:47.875] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:43:48.833] INFO: Collecting data for 5 seconds...
[12:43:53.850] INFO: Done with hot pixel readout
[12:44:05.826] INFO: PixTest:: pg_setup set to default.
[12:44:05.828] INFO: 10 hot pixels found in step 0
[12:44:06.821] INFO: Collecting data for 5 seconds...
[12:44:11.838] INFO: Done with hot pixel readout
[12:44:23.959] INFO: PixTest:: pg_setup set to default.
[12:44:23.960] INFO: 16 hot pixels found in step 1
[12:44:24.959] INFO: Collecting data for 5 seconds...
[12:44:29.976] INFO: Done with hot pixel readout
[12:44:42.141] INFO: PixTest:: pg_setup set to default.



[12:44:42.142] INFO: 17 hot pixels found in step 2
[12:44:43.140] INFO: Collecting data for 5 seconds...
[12:44:48.157] INFO: Done with hot pixel readout
[12:45:00.341] INFO: PixTest:: pg_setup set to default.
[12:45:00.342] INFO: 13 hot pixels found in step 3
[12:45:01.338] INFO: Collecting data for 5 seconds...
[12:45:06.355] INFO: Done with hot pixel readout
[12:45:18.728] INFO: PixTest:: pg_setup set to default.
[12:45:18.729] INFO: 13 hot pixels found in step 4
[12:45:19.726] INFO: Collecting data for 5 seconds...
[12:45:24.743] INFO: Done with hot pixel readout
[12:45:37.077] INFO: PixTest:: pg_setup set to default.
[12:45:37.078] INFO: 14 hot pixels found in step 5
[12:45:38.074] INFO: Collecting data for 5 seconds...
[12:45:43.091] INFO: Done with hot pixel readout
[12:45:55.430] INFO: PixTest:: pg_setup set to default.

[12:45:55.431] INFO: 15 hot pixels found in step 6
[12:45:56.430] INFO: Collecting data for 5 seconds...
[12:46:01.446] INFO: Done with hot pixel readout
[12:46:13.739] INFO: PixTest:: pg_setup set to default.
[12:46:13.740] INFO: 7 hot pixels found in step 7
[12:46:14.736] INFO: Collecting data for 5 seconds...
[12:46:19.753] INFO: Done with hot pixel readout
[12:46:32.071] INFO: PixTest:: pg_setup set to default.


[12:46:32.072] INFO: 12 hot pixels found in step 8
[12:46:33.069] INFO: Collecting data for 5 seconds...
[12:46:38.086] INFO: Done with hot pixel readout
[12:46:50.402] INFO: PixTest:: pg_setup set to default.


[12:46:50.403] INFO: 16 hot pixels found in step 9
[12:46:51.399] INFO: Collecting data for 5 seconds...
[12:46:56.416] INFO: Done with hot pixel readout
[12:47:08.708] INFO: PixTest:: pg_setup set to default.
[12:47:08.709] INFO: 12 hot pixels found in step 10
[12:47:09.706] INFO: Collecting data for 5 seconds...
[12:47:14.722] INFO: Done with hot pixel readout
[12:47:27.057] INFO: PixTest:: pg_setup set to default.


[12:47:27.058] INFO: 9 hot pixels found in step 11
[12:47:28.053] INFO: Collecting data for 5 seconds...
[12:47:33.070] INFO: Done with hot pixel readout
[12:47:45.414] INFO: PixTest:: pg_setup set to default.

[12:47:45.415] INFO: 11 hot pixels found in step 12
[12:47:46.411] INFO: Collecting data for 5 seconds...
[12:47:51.428] INFO: Done with hot pixel readout
[12:48:03.813] INFO: PixTest:: pg_setup set to default.

[12:48:03.814] INFO: 9 hot pixels found in step 13
[12:48:04.812] INFO: Collecting data for 5 seconds...
[12:48:09.829] INFO: Done with hot pixel readout
[12:48:22.192] INFO: PixTest:: pg_setup set to default.


[12:48:22.192] INFO: 11 hot pixels found in step 14
[12:48:22.232] INFO: 11 hot pixels could not be trimmed and have been masked.
[12:48:22.236] INFO: PixTest::trimHotPixels() done
[12:48:22.236] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C0.dat
[12:48:22.242] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C1.dat
[12:48:22.249] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C2.dat
[12:48:22.254] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C3.dat
[12:48:22.260] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C4.dat
[12:48:22.265] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C5.dat
[12:48:22.270] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C6.dat
[12:48:22.275] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C7.dat
[12:48:22.281] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C8.dat
[12:48:22.286] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C9.dat
[12:48:22.291] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C10.dat
[12:48:22.297] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C11.dat
[12:48:22.302] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C12.dat
[12:48:22.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C13.dat
[12:48:22.312] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C14.dat
[12:48:22.318] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C15.dat
[12:48:22.323] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//defaultMaskFile.dat
[12:48:22.332] INFO: enter test to run
[12:48:47.570] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:48:47.570] INFO: running: highrate
[12:48:47.575] INFO: ----------------------------------------------------------------------
[12:48:47.575] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:48:47.575] INFO: ----------------------------------------------------------------------
[12:48:47.575] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:48:47.575] INFO: edge/corner pixel THR is adjusted
[12:48:47.575] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:48:48.532] INFO: Collecting data for 1 seconds...
[12:48:49.536] INFO: Done with hot pixel readout
[12:48:53.977] INFO: PixTest:: pg_setup set to default.
[12:48:53.978] INFO: 0 hot pixels found in step 0
[12:48:53.983] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:48:54.060] INFO: PixTest::trimHotPixels() done
[12:48:54.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C0.dat
[12:48:54.066] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C1.dat
[12:48:54.072] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C2.dat
[12:48:54.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C3.dat
[12:48:54.084] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C4.dat
[12:48:54.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C5.dat
[12:48:54.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C6.dat
[12:48:54.100] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C7.dat
[12:48:54.105] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C8.dat
[12:48:54.110] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C9.dat
[12:48:54.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C10.dat
[12:48:54.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C11.dat
[12:48:54.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C12.dat
[12:48:54.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C13.dat
[12:48:54.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C14.dat
[12:48:54.142] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C15.dat
[12:48:54.147] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-F-NA_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//defaultMaskFile.dat
[12:48:54.160] INFO: enter test to run
[12:49:08.698] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:49:08.698] INFO: running: xray
[12:49:08.700] INFO: ----------------------------------------------------------------------
[12:49:08.700] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:49:08.700] INFO: ----------------------------------------------------------------------
[12:49:09.662] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:49:20.540] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:49:49.839] INFO: Resuming triggers.
[12:50:00.718] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:50:29.459] INFO: Resuming triggers.
[12:50:40.339] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:51:10.040] INFO: Resuming triggers.
[12:51:20.926] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:51:51.258] INFO: Resuming triggers.
[12:52:02.142] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:52:31.881] INFO: Resuming triggers.
[12:52:42.765] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:53:12.459] INFO: Resuming triggers.
[12:53:23.339] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[12:53:52.878] INFO: Resuming triggers.
[12:54:03.757] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[12:54:33.383] INFO: Resuming triggers.
[12:54:44.260] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[12:55:13.746] INFO: Resuming triggers.
[12:55:16.185] INFO: data taking finished, elapsed time: 100 seconds.
[12:55:23.085] INFO: PixTest:: pg_setup set to default.
[12:55:23.088] INFO: PixTestXray::doPhRun() done
[12:55:23.227] INFO: enter test to run
[12:56:37.151] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:56:37.151] INFO: running: xray
[12:56:37.152] INFO: ----------------------------------------------------------------------
[12:56:37.152] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:56:37.152] INFO: ----------------------------------------------------------------------
[12:56:38.131] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:56:44.065] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[12:57:14.209] INFO: Resuming triggers.
[12:57:20.143] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:57:50.286] INFO: Resuming triggers.
[12:57:56.219] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[12:58:26.376] INFO: Resuming triggers.
[12:58:32.312] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:59:02.491] INFO: Resuming triggers.
[12:59:08.427] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[12:59:38.564] INFO: Resuming triggers.
[12:59:44.498] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:00:14.517] INFO: Resuming triggers.
[13:00:20.451] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[13:00:51.207] INFO: Resuming triggers.
[13:00:57.140] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:01:27.769] INFO: Resuming triggers.
[13:01:33.702] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[13:02:05.004] INFO: Resuming triggers.
[13:02:10.935] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[13:02:42.053] INFO: Resuming triggers.
[13:02:47.984] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[13:03:18.476] INFO: Resuming triggers.
[13:03:24.407] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:03:54.499] INFO: Resuming triggers.
[13:04:00.428] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[13:04:30.534] INFO: Resuming triggers.
[13:04:36.464] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:05:06.653] INFO: Resuming triggers.
[13:05:12.584] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[13:05:42.712] INFO: Resuming triggers.
[13:05:48.644] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[13:06:18.834] INFO: Resuming triggers.
[13:06:24.263] INFO: data taking finished, elapsed time: 100 seconds.
[13:06:52.107] INFO: PixTest:: pg_setup set to default.
[13:06:52.110] INFO: PixTestXray::doPhRun() done
[13:06:52.260] INFO: enter test to run
[13:07:21.626] INFO: test: HighRate no parameter change
[13:07:21.626] INFO: running: highrate
[13:07:21.627] INFO: ----------------------------------------------------------------------
[13:07:21.627] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:07:21.627] INFO: ----------------------------------------------------------------------
[13:07:21.769] INFO: Expecting 768 events.
[13:07:22.903] INFO: 768 events read in total (418ms).
[13:07:22.903] INFO: Test took 1268ms.
[13:07:23.706] INFO: Expecting 41600 events.
[13:07:26.853] INFO: 41600 events read in total (2620ms).
[13:07:26.854] INFO: Test took 3943ms.
[13:07:26.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:27.609] INFO: Expecting 41600 events.
[13:07:30.842] INFO: 41600 events read in total (2706ms).
[13:07:30.843] INFO: Test took 3932ms.
[13:07:30.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:31.597] INFO: Expecting 41600 events.
[13:07:34.850] INFO: 41600 events read in total (2726ms).
[13:07:34.851] INFO: Test took 3950ms.
[13:07:34.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:35.605] INFO: Expecting 41600 events.
[13:07:38.846] INFO: 41600 events read in total (2714ms).
[13:07:38.847] INFO: Test took 3939ms.
[13:07:38.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:39.598] INFO: Expecting 41600 events.
[13:07:42.881] INFO: 41600 events read in total (2756ms).
[13:07:42.882] INFO: Test took 3976ms.
[13:07:42.921] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:43.635] INFO: Expecting 41600 events.
[13:07:46.914] INFO: 41600 events read in total (2752ms).
[13:07:46.915] INFO: Test took 3973ms.
[13:07:46.955] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:47.669] INFO: Expecting 41600 events.
[13:07:50.953] INFO: 41600 events read in total (2757ms).
[13:07:50.954] INFO: Test took 3979ms.
[13:07:50.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:51.706] INFO: Expecting 41600 events.
[13:07:54.976] INFO: 41600 events read in total (2744ms).
[13:07:54.977] INFO: Test took 3965ms.
[13:07:55.015] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:55.730] INFO: Expecting 41600 events.
[13:07:59.020] INFO: 41600 events read in total (2763ms).
[13:07:59.021] INFO: Test took 3985ms.
[13:07:59.060] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:59.767] INFO: Expecting 41600 events.
[13:08:03.050] INFO: 41600 events read in total (2756ms).
[13:08:03.051] INFO: Test took 3971ms.
[13:08:03.089] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:03.802] INFO: Expecting 41600 events.
[13:08:07.095] INFO: 41600 events read in total (2766ms).
[13:08:07.096] INFO: Test took 3988ms.
[13:08:07.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:07.850] INFO: Expecting 41600 events.
[13:08:11.137] INFO: 41600 events read in total (2761ms).
[13:08:11.138] INFO: Test took 3984ms.
[13:08:11.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:11.890] INFO: Expecting 41600 events.
[13:08:15.161] INFO: 41600 events read in total (2744ms).
[13:08:15.162] INFO: Test took 3966ms.
[13:08:15.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:15.917] INFO: Expecting 41600 events.
[13:08:19.195] INFO: 41600 events read in total (2751ms).
[13:08:19.196] INFO: Test took 3976ms.
[13:08:19.234] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:19.951] INFO: Expecting 41600 events.
[13:08:23.200] INFO: 41600 events read in total (2722ms).
[13:08:23.201] INFO: Test took 3947ms.
[13:08:23.240] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:23.956] INFO: Expecting 41600 events.
[13:08:27.254] INFO: 41600 events read in total (2771ms).
[13:08:27.255] INFO: Test took 3994ms.
[13:08:27.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:28.007] INFO: Expecting 41600 events.
[13:08:31.299] INFO: 41600 events read in total (2765ms).
[13:08:31.300] INFO: Test took 3988ms.
[13:08:31.338] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:32.052] INFO: Expecting 41600 events.
[13:08:35.348] INFO: 41600 events read in total (2769ms).
[13:08:35.349] INFO: Test took 3992ms.
[13:08:35.388] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:36.104] INFO: Expecting 41600 events.
[13:08:39.375] INFO: 41600 events read in total (2744ms).
[13:08:39.376] INFO: Test took 3969ms.
[13:08:39.415] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:40.132] INFO: Expecting 41600 events.
[13:08:43.286] INFO: 41600 events read in total (2627ms).
[13:08:43.287] INFO: Test took 3853ms.
[13:08:43.326] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:43.680] INFO: enter test to run
[13:08:51.674] INFO: test: HighRate no parameter change
[13:08:51.674] INFO: running: highrate
[13:08:51.675] INFO: ----------------------------------------------------------------------
[13:08:51.675] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:08:51.675] INFO: ----------------------------------------------------------------------
[13:08:52.291] INFO: Expecting 208000 events.
[13:09:04.422] INFO: 208000 events read in total (11604ms).
[13:09:04.425] INFO: Test took 12742ms.
[13:09:04.592] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:04.851] INFO: number of dead pixels (per ROC): 0 0 0 10 0 0 0 0 0 0 0 0 0 0 0 0
[13:09:04.851] INFO: number of red-efficiency pixels: 86 47 107 212 190 181 195 116 113 132 110 120 111 76 29 27
[13:09:04.851] INFO: number of X-ray hits detected: 80823 53618 78143 130151 134594 139627 140764 99704 89297 110317 105078 94294 94319 57930 25434 25934
[13:09:04.851] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:09:04.851] INFO: number of Vcal hits detected: 207911 207948 207887 207245 207805 207784 207799 207883 207886 207864 207886 207876 207889 207922 207971 207973
[13:09:04.851] 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
[13:09:04.851] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.6 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:09:04.851] INFO: X-ray hit rate [MHz/cm2]: 23.7 15.7 22.9 38.1 39.5 40.9 41.3 29.2 26.2 32.3 30.8 27.6 27.6 17.0 7.5 7.6
[13:09:04.851] INFO: PixTestHighRate::doXPixelAlive() done
[13:09:04.898] INFO: PixTest:: pg_setup set to default.
[13:09:04.912] INFO: enter test to run
[13:09:17.281] INFO: test: HighRate no parameter change
[13:09:17.281] INFO: running: highrate
[13:09:17.283] INFO: ----------------------------------------------------------------------
[13:09:17.283] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:09:17.283] INFO: ----------------------------------------------------------------------
[13:09:17.899] INFO: Expecting 208000 events.
[13:09:32.256] INFO: 208000 events read in total (13830ms).
[13:09:32.262] INFO: Test took 14971ms.
[13:09:32.627] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:32.948] INFO: number of dead pixels (per ROC): 0 0 0 11 0 0 0 0 0 0 0 0 0 0 0 0
[13:09:32.948] INFO: number of red-efficiency pixels: 370 164 429 761 815 612 838 396 393 527 410 427 318 280 79 67
[13:09:32.949] INFO: number of X-ray hits detected: 173198 115115 168181 278096 287573 297572 302861 212549 192703 236531 226012 202346 203971 126430 54184 56472
[13:09:32.949] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:09:32.949] INFO: number of Vcal hits detected: 207582 207827 207498 206592 207053 207252 207020 207564 207568 207427 207559 207541 207659 207689 207919 207933
[13:09:32.949] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.7 99.6 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[13:09:32.949] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.3 99.5 99.6 99.5 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[13:09:32.949] INFO: X-ray hit rate [MHz/cm2]: 50.8 33.7 49.3 81.5 84.3 87.2 88.8 62.3 56.5 69.3 66.2 59.3 59.8 37.1 15.9 16.6
[13:09:32.949] INFO: PixTestHighRate::doXPixelAlive() done
[13:09:32.994] INFO: PixTest:: pg_setup set to default.
[13:09:33.008] INFO: enter test to run
[13:09:45.146] INFO: test: HighRate no parameter change
[13:09:45.146] INFO: running: highrate
[13:09:45.147] INFO: ----------------------------------------------------------------------
[13:09:45.147] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:09:45.147] INFO: ----------------------------------------------------------------------
[13:09:45.763] INFO: Expecting 208000 events.
[13:10:02.796] INFO: 208000 events read in total (16507ms).
[13:10:02.805] INFO: Test took 17649ms.
[13:10:03.377] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:03.764] INFO: number of dead pixels (per ROC): 0 0 0 10 0 0 0 0 0 0 0 0 0 0 0 0
[13:10:03.764] INFO: number of red-efficiency pixels: 822 340 997 1857 2025 1649 1947 939 939 1301 925 1018 814 675 103 102
[13:10:03.764] INFO: number of X-ray hits detected: 268590 178722 260633 429949 445674 461415 466703 328733 298755 367592 350978 314400 316787 195714 84765 87877
[13:10:03.764] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:10:03.764] INFO: number of Vcal hits detected: 206910 207621 206377 204627 204765 205508 204871 206762 206870 206317 206898 206705 207044 207130 207893 207896
[13:10:03.764] INFO: Vcal hit fiducial efficiency (%): 99.5 99.8 99.3 98.8 98.6 98.9 98.7 99.5 99.5 99.3 99.5 99.5 99.6 99.6 99.9 100.0
[13:10:03.764] INFO: Vcal hit overall efficiency (%): 99.5 99.8 99.2 98.4 98.4 98.8 98.5 99.4 99.5 99.2 99.5 99.4 99.5 99.6 99.9 100.0
[13:10:03.764] INFO: X-ray hit rate [MHz/cm2]: 78.7 52.4 76.4 126.0 130.6 135.2 136.8 96.4 87.6 107.7 102.9 92.2 92.9 57.4 24.8 25.8
[13:10:03.764] INFO: PixTestHighRate::doXPixelAlive() done
[13:10:03.812] INFO: PixTest:: pg_setup set to default.
[13:10:03.825] INFO: enter test to run
[13:10:06.001] INFO: test: exit no parameter change
[13:10:07.348] QUIET: Connection to board 33 closed.
[13:10:07.349] INFO: pXar: this is the end, my friend