[15:05:51.785] INFO: *** Welcome to pxar ***
[15:05:51.785] INFO: *** Today: 2016/04/13
[15:05:51.803] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:05:51.803] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//dacParameters35_C15.dat
[15:05:51.823] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:05:51.823] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//defaultMaskFile.dat
[15:05:51.827] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C15.dat
[15:05:51.924] INFO: clk: 4
[15:05:51.924] INFO: ctr: 4
[15:05:51.924] INFO: sda: 19
[15:05:51.924] INFO: tin: 9
[15:05:51.924] INFO: level: 15
[15:05:51.924] INFO: triggerdelay: 0
[15:05:51.924] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:05:51.924] INFO: Log level: INFO
[15:05:51.943] QUIET: Connection to board DTB_WREKRL opened.
[15:05:51.946] 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:05:51.949] INFO: RPC call hashes of host and DTB match: 398089610
[15:05:53.480] INFO: DUT info:
[15:05:53.480] INFO: The DUT currently contains the following objects:
[15:05:53.480] INFO: 2 TBM Cores tbm08c (2 ON)
[15:05:53.480] INFO: TBM Core alpha (0): 7 registers set
[15:05:53.480] INFO: TBM Core beta (1): 7 registers set
[15:05:53.480] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:05:53.480] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.481] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:05:53.884] INFO: enter 'restricted' command line mode
[15:05:53.884] INFO: enter test to run
[15:08:48.968] INFO: test: PixelAlive no parameter change
[15:08:48.968] INFO: running: pixelalive
[15:08:48.978] INFO: ----------------------------------------------------------------------
[15:08:48.978] 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:08:48.978] INFO: ----------------------------------------------------------------------
[15:08:49.308] INFO: Expecting 41600 events.
[15:08:53.646] INFO: 41600 events read in total (3620ms).
[15:08:53.812] INFO: Test took 4832ms.
[15:08:53.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:54.088] INFO: PixTestAlive::aliveTest() done
[15:08:54.088] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:08:54.121] INFO: enter test to run
[15:10:37.752] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:10:37.752] INFO: running: highrate
[15:10:37.752] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:10:37.985] INFO: ----------------------------------------------------------------------
[15:10:37.985] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:10:37.985] INFO: ----------------------------------------------------------------------
[15:10:37.985] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:10:37.985] INFO: edge/corner pixel THR is adjusted
[15:10:37.985] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:10:38.944] INFO: Collecting data for 5 seconds...
[15:10:43.961] INFO: Done with hot pixel readout
[15:10:55.856] INFO: PixTest:: pg_setup set to default.
[15:10:55.857] INFO: 7 hot pixels found in step 0
[15:10:56.847] INFO: Collecting data for 5 seconds...
[15:11:01.864] INFO: Done with hot pixel readout
[15:11:13.672] INFO: PixTest:: pg_setup set to default.
[15:11:13.673] INFO: 10 hot pixels found in step 1
[15:11:14.669] INFO: Collecting data for 5 seconds...
[15:11:19.686] INFO: Done with hot pixel readout
[15:11:31.578] INFO: PixTest:: pg_setup set to default.
[15:11:31.579] INFO: 6 hot pixels found in step 2
[15:11:32.571] INFO: Collecting data for 5 seconds...
[15:11:37.588] INFO: Done with hot pixel readout
[15:11:49.443] INFO: PixTest:: pg_setup set to default.

[15:11:49.444] INFO: 9 hot pixels found in step 3
[15:11:50.436] INFO: Collecting data for 5 seconds...
[15:11:55.452] INFO: Done with hot pixel readout
[15:12:07.352] INFO: PixTest:: pg_setup set to default.
[15:12:07.353] INFO: 7 hot pixels found in step 4
[15:12:08.346] INFO: Collecting data for 5 seconds...
[15:12:13.363] INFO: Done with hot pixel readout
[15:12:25.268] INFO: PixTest:: pg_setup set to default.
[15:12:25.269] INFO: 4 hot pixels found in step 5
[15:12:26.262] INFO: Collecting data for 5 seconds...
[15:12:31.279] INFO: Done with hot pixel readout
[15:12:43.243] INFO: PixTest:: pg_setup set to default.
[15:12:43.244] INFO: 7 hot pixels found in step 6
[15:12:44.237] INFO: Collecting data for 5 seconds...
[15:12:49.253] INFO: Done with hot pixel readout
[15:13:01.052] INFO: PixTest:: pg_setup set to default.
[15:13:01.053] INFO: 3 hot pixels found in step 7
[15:13:02.048] INFO: Collecting data for 5 seconds...
[15:13:07.065] INFO: Done with hot pixel readout
[15:13:18.820] INFO: PixTest:: pg_setup set to default.
[15:13:18.821] INFO: 4 hot pixels found in step 8
[15:13:19.815] INFO: Collecting data for 5 seconds...
[15:13:24.833] INFO: Done with hot pixel readout
[15:13:36.575] INFO: PixTest:: pg_setup set to default.

[15:13:36.576] INFO: 6 hot pixels found in step 9
[15:13:37.573] INFO: Collecting data for 5 seconds...
[15:13:42.590] INFO: Done with hot pixel readout
[15:13:54.555] INFO: PixTest:: pg_setup set to default.
[15:13:54.556] INFO: 1 hot pixels found in step 10
[15:13:55.552] INFO: Collecting data for 5 seconds...
[15:14:00.569] INFO: Done with hot pixel readout
[15:14:12.443] INFO: PixTest:: pg_setup set to default.
[15:14:12.444] INFO: 0 hot pixels found in step 11
[15:14:12.483] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:14:12.486] INFO: PixTest::trimHotPixels() done
[15:14:12.487] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C0.dat
[15:14:12.492] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C1.dat
[15:14:12.498] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C2.dat
[15:14:12.503] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C3.dat
[15:14:12.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C4.dat
[15:14:12.535] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C5.dat
[15:14:12.540] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C6.dat
[15:14:12.546] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C7.dat
[15:14:12.552] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C8.dat
[15:14:12.557] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C9.dat
[15:14:12.562] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C10.dat
[15:14:12.568] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C11.dat
[15:14:12.573] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C12.dat
[15:14:12.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C13.dat
[15:14:12.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C14.dat
[15:14:12.589] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C15.dat
[15:14:12.594] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//defaultMaskFile.dat
[15:14:12.604] INFO: enter test to run
[15:17:03.797] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:17:03.797] INFO: running: highrate
[15:17:03.801] INFO: ----------------------------------------------------------------------
[15:17:03.801] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:17:03.801] INFO: ----------------------------------------------------------------------
[15:17:03.801] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:17:03.801] INFO: edge/corner pixel THR is adjusted
[15:17:03.801] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:17:04.759] INFO: Collecting data for 1 seconds...
[15:17:05.763] INFO: Done with hot pixel readout
[15:17:09.861] INFO: PixTest:: pg_setup set to default.
[15:17:09.862] INFO: 0 hot pixels found in step 0
[15:17:09.867] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:17:09.952] INFO: PixTest::trimHotPixels() done
[15:17:09.952] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C0.dat
[15:17:09.962] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C1.dat
[15:17:09.970] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C2.dat
[15:17:09.975] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C3.dat
[15:17:09.980] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C4.dat
[15:17:09.986] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C5.dat
[15:17:09.992] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C6.dat
[15:17:09.998] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C7.dat
[15:17:10.003] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C8.dat
[15:17:10.009] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C9.dat
[15:17:10.014] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C10.dat
[15:17:10.020] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C11.dat
[15:17:10.025] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C12.dat
[15:17:10.030] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C13.dat
[15:17:10.035] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C14.dat
[15:17:10.041] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C15.dat
[15:17:10.046] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-49_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//defaultMaskFile.dat
[15:17:10.057] INFO: enter test to run
[15:17:51.548] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:17:51.548] INFO: running: xray
[15:17:51.550] INFO: ----------------------------------------------------------------------
[15:17:51.550] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:17:51.550] INFO: ----------------------------------------------------------------------
[15:17:52.513] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:18:04.012] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:18:28.956] INFO: Resuming triggers.
[15:18:40.454] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:19:09.953] INFO: Resuming triggers.
[15:19:21.446] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:19:51.031] INFO: Resuming triggers.
[15:20:02.529] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:20:32.004] INFO: Resuming triggers.
[15:20:43.499] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:21:12.985] INFO: Resuming triggers.
[15:21:24.484] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:21:53.902] INFO: Resuming triggers.
[15:22:05.402] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:22:34.886] INFO: Resuming triggers.
[15:22:46.381] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[15:23:15.864] INFO: Resuming triggers.
[15:23:24.212] INFO: data taking finished, elapsed time: 100 seconds.
[15:23:45.685] INFO: PixTest:: pg_setup set to default.
[15:23:45.689] INFO: PixTestXray::doPhRun() done
[15:23:45.860] INFO: enter test to run
[15:28:19.239] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:28:19.239] INFO: running: xray
[15:28:19.240] INFO: ----------------------------------------------------------------------
[15:28:19.240] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:28:19.240] INFO: ----------------------------------------------------------------------
[15:28:20.201] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:28:26.646] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:28:55.203] INFO: Resuming triggers.
[15:29:01.644] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[15:29:31.812] INFO: Resuming triggers.
[15:29:38.256] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:30:08.395] INFO: Resuming triggers.
[15:30:14.839] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[15:30:44.885] INFO: Resuming triggers.
[15:30:51.329] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[15:31:21.461] INFO: Resuming triggers.
[15:31:27.908] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[15:31:58.055] INFO: Resuming triggers.
[15:32:04.497] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:32:34.676] INFO: Resuming triggers.
[15:32:41.117] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[15:33:11.271] INFO: Resuming triggers.
[15:33:17.711] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:33:47.839] INFO: Resuming triggers.
[15:33:54.282] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[15:34:24.402] INFO: Resuming triggers.
[15:34:30.843] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[15:35:00.907] INFO: Resuming triggers.
[15:35:07.351] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[15:35:37.416] INFO: Resuming triggers.
[15:35:43.859] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:36:14.071] INFO: Resuming triggers.
[15:36:20.514] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:36:50.555] INFO: Resuming triggers.
[15:36:56.998] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[15:37:27.250] INFO: Resuming triggers.
[15:37:30.917] INFO: data taking finished, elapsed time: 100 seconds.
[15:37:48.366] INFO: PixTest:: pg_setup set to default.
[15:37:48.370] INFO: PixTestXray::doPhRun() done
[15:37:48.518] INFO: enter test to run
[15:38:14.603] INFO: test: HighRate no parameter change
[15:38:14.603] INFO: running: highrate
[15:38:14.604] INFO: ----------------------------------------------------------------------
[15:38:14.604] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:38:14.604] INFO: ----------------------------------------------------------------------
[15:38:14.745] INFO: Expecting 768 events.
[15:38:15.875] INFO: 768 events read in total (414ms).
[15:38:15.875] INFO: Test took 1264ms.
[15:38:16.679] INFO: Expecting 41600 events.
[15:38:19.769] INFO: 41600 events read in total (2563ms).
[15:38:19.770] INFO: Test took 3889ms.
[15:38:19.803] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:20.530] INFO: Expecting 41600 events.
[15:38:23.368] INFO: 41600 events read in total (2311ms).
[15:38:23.370] INFO: Test took 3549ms.
[15:38:23.406] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:24.130] INFO: Expecting 41600 events.
[15:38:26.985] INFO: 41600 events read in total (2328ms).
[15:38:26.986] INFO: Test took 3563ms.
[15:38:27.021] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:27.748] INFO: Expecting 41600 events.
[15:38:30.678] INFO: 41600 events read in total (2404ms).
[15:38:30.679] INFO: Test took 3640ms.
[15:38:30.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:31.441] INFO: Expecting 41600 events.
[15:38:34.372] INFO: 41600 events read in total (2405ms).
[15:38:34.373] INFO: Test took 3642ms.
[15:38:34.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:35.132] INFO: Expecting 41600 events.
[15:38:37.971] INFO: 41600 events read in total (2312ms).
[15:38:37.972] INFO: Test took 3546ms.
[15:38:38.006] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:38.733] INFO: Expecting 41600 events.
[15:38:41.964] INFO: 41600 events read in total (2704ms).
[15:38:41.965] INFO: Test took 3940ms.
[15:38:41.000] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:42.718] INFO: Expecting 41600 events.
[15:38:45.954] INFO: 41600 events read in total (2709ms).
[15:38:45.956] INFO: Test took 3937ms.
[15:38:45.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:46.715] INFO: Expecting 41600 events.
[15:38:49.959] INFO: 41600 events read in total (2718ms).
[15:38:49.960] INFO: Test took 3951ms.
[15:38:49.994] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:50.716] INFO: Expecting 41600 events.
[15:38:53.978] INFO: 41600 events read in total (2735ms).
[15:38:53.979] INFO: Test took 3968ms.
[15:38:54.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:54.734] INFO: Expecting 41600 events.
[15:38:57.974] INFO: 41600 events read in total (2713ms).
[15:38:57.975] INFO: Test took 3943ms.
[15:38:58.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:58.729] INFO: Expecting 41600 events.
[15:39:01.973] INFO: 41600 events read in total (2717ms).
[15:39:01.974] INFO: Test took 3947ms.
[15:39:02.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:02.732] INFO: Expecting 41600 events.
[15:39:05.969] INFO: 41600 events read in total (2710ms).
[15:39:05.970] INFO: Test took 3943ms.
[15:39:06.004] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:06.729] INFO: Expecting 41600 events.
[15:39:09.986] INFO: 41600 events read in total (2731ms).
[15:39:09.987] INFO: Test took 3964ms.
[15:39:10.022] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:10.744] INFO: Expecting 41600 events.
[15:39:13.973] INFO: 41600 events read in total (2702ms).
[15:39:13.973] INFO: Test took 3933ms.
[15:39:14.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:14.732] INFO: Expecting 41600 events.
[15:39:17.969] INFO: 41600 events read in total (2710ms).
[15:39:17.970] INFO: Test took 3945ms.
[15:39:18.004] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:18.729] INFO: Expecting 41600 events.
[15:39:21.977] INFO: 41600 events read in total (2721ms).
[15:39:21.977] INFO: Test took 3954ms.
[15:39:22.011] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:22.735] INFO: Expecting 41600 events.
[15:39:25.975] INFO: 41600 events read in total (2713ms).
[15:39:25.976] INFO: Test took 3946ms.
[15:39:26.010] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:26.736] INFO: Expecting 41600 events.
[15:39:29.966] INFO: 41600 events read in total (2703ms).
[15:39:29.967] INFO: Test took 3938ms.
[15:39:29.000] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:30.722] INFO: Expecting 41600 events.
[15:39:33.818] INFO: 41600 events read in total (2569ms).
[15:39:33.819] INFO: Test took 3799ms.
[15:39:33.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:34.215] INFO: enter test to run
[15:41:38.410] INFO: test: HighRate no parameter change
[15:41:38.410] INFO: running: highrate
[15:41:38.411] INFO: ----------------------------------------------------------------------
[15:41:38.411] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:41:38.411] INFO: ----------------------------------------------------------------------
[15:41:39.024] INFO: Expecting 208000 events.
[15:41:50.882] INFO: 208000 events read in total (11331ms).
[15:41:50.885] INFO: Test took 12465ms.
[15:41:51.030] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:51.282] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:41:51.282] INFO: number of red-efficiency pixels: 63 43 90 131 128 183 182 129 102 119 122 98 89 62 16 22
[15:41:51.282] INFO: number of X-ray hits detected: 66829 43440 67900 107659 110593 118481 118658 88128 90758 96305 97357 80341 85155 50146 20167 21922
[15:41:51.282] 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:41:51.282] INFO: number of Vcal hits detected: 207936 207954 207906 207865 207871 207814 207815 207869 207896 207878 207875 207902 207910 207937 207983 207978
[15:41:51.282] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:41:51.282] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:41:51.282] INFO: X-ray hit rate [MHz/cm2]: 19.6 12.7 19.9 31.6 32.4 34.7 34.8 25.8 26.6 28.2 28.5 23.5 25.0 14.7 5.9 6.4
[15:41:51.282] INFO: PixTestHighRate::doXPixelAlive() done
[15:41:51.328] INFO: PixTest:: pg_setup set to default.
[15:41:51.343] INFO: enter test to run
[15:42:37.793] INFO: test: HighRate no parameter change
[15:42:37.793] INFO: running: highrate
[15:42:37.795] INFO: ----------------------------------------------------------------------
[15:42:37.795] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:42:37.795] INFO: ----------------------------------------------------------------------
[15:42:38.410] INFO: Expecting 208000 events.
[15:42:52.176] INFO: 208000 events read in total (13239ms).
[15:42:52.182] INFO: Test took 14379ms.
[15:42:52.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:52.793] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:42:52.793] INFO: number of red-efficiency pixels: 209 126 264 431 557 616 698 404 327 448 310 241 278 196 52 53
[15:42:52.793] INFO: number of X-ray hits detected: 142935 92709 144395 228218 235064 252227 251933 187793 193989 204562 207293 170270 181760 106799 42724 46328
[15:42:52.793] 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:42:52.793] INFO: number of Vcal hits detected: 207777 207869 207704 207530 207383 207315 207225 207545 207656 207518 207670 207749 207714 207794 207945 207947
[15:42:52.793] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.8 99.8 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[15:42:52.793] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.6 99.8 99.8 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:42:52.793] INFO: X-ray hit rate [MHz/cm2]: 41.9 27.2 42.3 66.9 68.9 73.9 73.8 55.0 56.9 60.0 60.8 49.9 53.3 31.3 12.5 13.6
[15:42:52.793] INFO: PixTestHighRate::doXPixelAlive() done
[15:42:52.845] INFO: PixTest:: pg_setup set to default.
[15:42:52.859] INFO: enter test to run
[15:43:05.522] INFO: test: HighRate no parameter change
[15:43:05.522] INFO: running: highrate
[15:43:05.523] INFO: ----------------------------------------------------------------------
[15:43:05.523] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:43:05.523] INFO: ----------------------------------------------------------------------
[15:43:06.142] INFO: Expecting 208000 events.
[15:43:19.918] INFO: 208000 events read in total (13249ms).
[15:43:19.923] INFO: Test took 14389ms.
[15:43:20.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:20.532] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:43:20.532] INFO: number of red-efficiency pixels: 200 121 274 407 559 611 637 418 321 421 335 228 264 183 73 54
[15:43:20.532] INFO: number of X-ray hits detected: 142803 93448 144309 228033 234838 253187 252918 188647 193688 204466 208289 169188 182067 106664 42723 46718
[15:43:20.532] 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:43:20.532] INFO: number of Vcal hits detected: 207787 207869 207697 207573 207384 207313 207286 207539 207653 207542 207649 207762 207726 207808 207926 207946
[15:43:20.532] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.8 99.8 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:43:20.532] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.8 99.8 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:43:20.532] INFO: X-ray hit rate [MHz/cm2]: 41.9 27.4 42.3 66.8 68.8 74.2 74.1 55.3 56.8 59.9 61.1 49.6 53.4 31.3 12.5 13.7
[15:43:20.532] INFO: PixTestHighRate::doXPixelAlive() done
[15:43:20.577] INFO: PixTest:: pg_setup set to default.
[15:43:20.590] INFO: enter test to run
[15:43:45.537] INFO: test: HighRate no parameter change
[15:43:45.537] INFO: running: highrate
[15:43:45.538] INFO: ----------------------------------------------------------------------
[15:43:45.538] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:43:45.538] INFO: ----------------------------------------------------------------------
[15:43:46.154] INFO: Expecting 208000 events.
[15:44:02.027] INFO: 208000 events read in total (15346ms).
[15:44:02.035] INFO: Test took 16486ms.
[15:44:02.528] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:02.889] 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:02.889] INFO: number of red-efficiency pixels: 426 225 615 1047 1341 1533 1559 989 651 1034 746 511 632 473 100 98
[15:44:02.889] INFO: number of X-ray hits detected: 220357 144091 222956 351440 362717 389338 390595 290630 300105 316118 320494 262134 281351 165100 66889 72042
[15:44:02.889] 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:02.889] INFO: number of Vcal hits detected: 207513 207760 207177 206678 206204 205895 205755 206673 207238 206713 207134 207429 207298 207445 207898 207899
[15:44:02.889] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.2 99.1 99.0 99.4 99.7 99.4 99.6 99.8 99.7 99.8 100.0 100.0
[15:44:02.889] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.4 99.1 99.0 98.9 99.4 99.6 99.4 99.6 99.7 99.7 99.7 100.0 100.0
[15:44:02.889] INFO: X-ray hit rate [MHz/cm2]: 64.6 42.2 65.4 103.0 106.3 114.1 114.5 85.2 88.0 92.7 93.9 76.8 82.5 48.4 19.6 21.1
[15:44:02.889] INFO: PixTestHighRate::doXPixelAlive() done
[15:44:02.934] INFO: PixTest:: pg_setup set to default.
[15:44:02.948] INFO: enter test to run
[15:44:05.328] INFO: test: exit no parameter change
[15:44:05.606] QUIET: Connection to board 33 closed.
[15:44:05.607] INFO: pXar: this is the end, my friend