[13:15:41.950] INFO: *** Welcome to pxar ***
[13:15:41.950] INFO: *** Today: 2016/05/27
[13:15:42.008] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:15:42.009] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//dacParameters35_C15.dat
[13:15:42.037] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:15:42.037] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//defaultMaskFile.dat
[13:15:42.045] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C15.dat
[13:15:42.130] INFO: clk: 4
[13:15:42.130] INFO: ctr: 4
[13:15:42.130] INFO: sda: 19
[13:15:42.130] INFO: tin: 9
[13:15:42.130] INFO: level: 15
[13:15:42.130] INFO: triggerdelay: 0
[13:15:42.130] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:15:42.130] INFO: Log level: INFO
[13:15:42.149] QUIET: Connection to board DTB_WREKRL opened.
[13:15:42.152] 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:
------------------------------------------------------
[13:15:42.155] INFO: RPC call hashes of host and DTB match: 398089610
[13:15:43.695] INFO: DUT info:
[13:15:43.695] INFO: The DUT currently contains the following objects:
[13:15:43.695] INFO: 2 TBM Cores tbm08c (2 ON)
[13:15:43.695] INFO: TBM Core alpha (0): 7 registers set
[13:15:43.695] INFO: TBM Core beta (1): 7 registers set
[13:15:43.695] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:15:43.695] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:43.695] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:15:44.099] INFO: enter 'restricted' command line mode
[13:15:44.099] INFO: enter test to run
[13:15:46.292] INFO: test: PixelAlive no parameter change
[13:15:46.292] INFO: running: pixelalive
[13:15:46.301] INFO: ----------------------------------------------------------------------
[13:15:46.301] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:15:46.301] INFO: ----------------------------------------------------------------------
[13:15:46.617] INFO: Expecting 41600 events.
[13:15:50.966] INFO: 41600 events read in total (3630ms).
[13:15:51.133] INFO: Test took 4829ms.
[13:15:51.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:51.407] INFO: PixTestAlive::aliveTest() done
[13:15:51.407] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 3 1 0 0 0 1
[13:15:51.441] INFO: enter test to run
[13:16:40.123] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:16:40.123] INFO: running: highrate
[13:16:40.124] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:16:40.333] INFO: ----------------------------------------------------------------------
[13:16:40.333] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:16:40.333] INFO: ----------------------------------------------------------------------
[13:16:40.333] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:16:40.333] INFO: edge/corner pixel THR is adjusted
[13:16:40.333] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:16:41.291] INFO: Collecting data for 5 seconds...
[13:16:46.309] INFO: Done with hot pixel readout
[13:16:58.008] INFO: PixTest:: pg_setup set to default.

[13:16:58.009] INFO: 13 hot pixels found in step 0
[13:16:58.998] INFO: Collecting data for 5 seconds...
[13:17:04.016] INFO: Done with hot pixel readout
[13:17:15.579] INFO: PixTest:: pg_setup set to default.
[13:17:15.580] INFO: 11 hot pixels found in step 1
[13:17:16.574] INFO: Collecting data for 5 seconds...
[13:17:21.593] INFO: Done with hot pixel readout
[13:17:33.351] INFO: PixTest:: pg_setup set to default.

[13:17:33.352] INFO: 14 hot pixels found in step 2
[13:17:34.345] INFO: Collecting data for 5 seconds...
[13:17:39.366] INFO: Done with hot pixel readout
[13:17:51.222] INFO: PixTest:: pg_setup set to default.
[13:17:51.223] INFO: 15 hot pixels found in step 3
[13:17:52.217] INFO: Collecting data for 5 seconds...
[13:17:57.238] INFO: Done with hot pixel readout
[13:18:09.249] INFO: PixTest:: pg_setup set to default.

[13:18:09.250] INFO: 18 hot pixels found in step 4
[13:18:10.243] INFO: Collecting data for 5 seconds...
[13:18:15.264] INFO: Done with hot pixel readout
[13:18:27.135] INFO: PixTest:: pg_setup set to default.
[13:18:27.136] INFO: 16 hot pixels found in step 5
[13:18:28.129] INFO: Collecting data for 5 seconds...
[13:18:33.153] INFO: Done with hot pixel readout
[13:18:45.071] INFO: PixTest:: pg_setup set to default.
[13:18:45.072] INFO: 12 hot pixels found in step 6
[13:18:46.065] INFO: Collecting data for 5 seconds...
[13:18:51.085] INFO: Done with hot pixel readout
[13:19:03.038] INFO: PixTest:: pg_setup set to default.
[13:19:03.039] INFO: 8 hot pixels found in step 7
[13:19:04.032] INFO: Collecting data for 5 seconds...
[13:19:09.051] INFO: Done with hot pixel readout
[13:19:21.038] INFO: PixTest:: pg_setup set to default.

[13:19:21.039] INFO: 17 hot pixels found in step 8
[13:19:22.032] INFO: Collecting data for 5 seconds...
[13:19:27.053] INFO: Done with hot pixel readout
[13:19:38.830] INFO: PixTest:: pg_setup set to default.
[13:19:38.831] INFO: 12 hot pixels found in step 9
[13:19:39.824] INFO: Collecting data for 5 seconds...
[13:19:44.842] INFO: Done with hot pixel readout
[13:19:56.590] INFO: PixTest:: pg_setup set to default.
[13:19:56.590] INFO: 10 hot pixels found in step 10
[13:19:57.582] INFO: Collecting data for 5 seconds...
[13:20:02.599] INFO: Done with hot pixel readout
[13:20:13.917] INFO: PixTest:: pg_setup set to default.

[13:20:13.918] INFO: 6 hot pixels found in step 11
[13:20:14.911] INFO: Collecting data for 5 seconds...
[13:20:19.928] INFO: Done with hot pixel readout
[13:20:31.404] INFO: PixTest:: pg_setup set to default.



[13:20:31.405] INFO: 8 hot pixels found in step 12
[13:20:32.398] INFO: Collecting data for 5 seconds...
[13:20:37.414] INFO: Done with hot pixel readout
[13:20:49.173] INFO: PixTest:: pg_setup set to default.

[13:20:49.174] INFO: 11 hot pixels found in step 13
[13:20:50.167] INFO: Collecting data for 5 seconds...
[13:20:55.184] INFO: Done with hot pixel readout
[13:21:06.968] INFO: PixTest:: pg_setup set to default.

[13:21:06.969] INFO: 9 hot pixels found in step 14
[13:21:07.005] INFO: 9 hot pixels could not be trimmed and have been masked.
[13:21:07.009] INFO: PixTest::trimHotPixels() done
[13:21:07.009] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C0.dat
[13:21:07.015] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C1.dat
[13:21:07.022] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C2.dat
[13:21:07.027] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C3.dat
[13:21:07.032] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C4.dat
[13:21:07.037] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C5.dat
[13:21:07.042] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C6.dat
[13:21:07.048] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C7.dat
[13:21:07.053] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C8.dat
[13:21:07.058] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C9.dat
[13:21:07.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C10.dat
[13:21:07.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C11.dat
[13:21:07.074] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C12.dat
[13:21:07.079] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C13.dat
[13:21:07.084] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C14.dat
[13:21:07.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C15.dat
[13:21:07.110] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//defaultMaskFile.dat
[13:21:07.126] INFO: enter test to run
[13:21:40.369] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:21:40.369] INFO: running: highrate
[13:21:40.374] INFO: ----------------------------------------------------------------------
[13:21:40.374] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:21:40.374] INFO: ----------------------------------------------------------------------
[13:21:40.374] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:21:40.374] INFO: edge/corner pixel THR is adjusted
[13:21:40.374] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:21:41.332] INFO: Collecting data for 1 seconds...
[13:21:42.336] INFO: Done with hot pixel readout
[13:21:46.285] INFO: PixTest:: pg_setup set to default.
[13:21:46.286] INFO: 0 hot pixels found in step 0
[13:21:46.291] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:21:46.388] INFO: PixTest::trimHotPixels() done
[13:21:46.388] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C0.dat
[13:21:46.395] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C1.dat
[13:21:46.401] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C2.dat
[13:21:46.406] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C3.dat
[13:21:46.411] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C4.dat
[13:21:46.416] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C5.dat
[13:21:46.422] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C6.dat
[13:21:46.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C7.dat
[13:21:46.432] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C8.dat
[13:21:46.437] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C9.dat
[13:21:46.442] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C10.dat
[13:21:46.448] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C11.dat
[13:21:46.453] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C12.dat
[13:21:46.458] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C13.dat
[13:21:46.463] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C14.dat
[13:21:46.468] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//trimParameters35_C15.dat
[13:21:46.474] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-3-10_FPIXTest-17C-FNAL-160520-1330_2016-05-20_13h30m_1463769035/000_FPIXTest_p17//defaultMaskFile.dat
[13:21:46.484] INFO: enter test to run
[13:22:38.873] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:22:38.873] INFO: running: xray
[13:22:38.874] INFO: ----------------------------------------------------------------------
[13:22:38.874] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:22:38.874] INFO: ----------------------------------------------------------------------
[13:22:39.837] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:22:51.274] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:23:20.678] INFO: Resuming triggers.
[13:23:32.117] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:24:01.590] INFO: Resuming triggers.
[13:24:13.029] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:24:42.164] INFO: Resuming triggers.
[13:24:53.607] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:25:23.001] INFO: Resuming triggers.
[13:25:34.445] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:26:03.850] INFO: Resuming triggers.
[13:26:15.293] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:26:44.660] INFO: Resuming triggers.
[13:26:56.103] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:27:25.495] INFO: Resuming triggers.
[13:27:36.938] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:28:05.692] INFO: Resuming triggers.
[13:28:14.507] INFO: data taking finished, elapsed time: 100 seconds.
[13:28:37.357] INFO: PixTest:: pg_setup set to default.
[13:28:37.360] INFO: PixTestXray::doPhRun() done
[13:28:37.498] INFO: enter test to run
[13:29:14.374] INFO: test: Xray setting parameters: ->source=DCHighRate\<-
[13:29:14.374] INFO: running: xray
[13:29:14.375] INFO: ----------------------------------------------------------------------
[13:29:14.375] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:29:14.375] INFO: ----------------------------------------------------------------------
[13:29:15.338] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:29:22.129] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:29:53.137] INFO: Resuming triggers.
[13:29:59.930] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:30:30.955] INFO: Resuming triggers.
[13:30:37.750] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:31:07.244] INFO: Resuming triggers.
[13:31:14.041] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:31:43.134] INFO: Resuming triggers.
[13:31:49.933] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:32:19.536] INFO: Resuming triggers.
[13:32:26.335] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[13:32:55.753] INFO: Resuming triggers.
[13:33:02.555] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:33:31.862] INFO: Resuming triggers.
[13:33:38.664] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:34:08.498] INFO: Resuming triggers.
[13:34:15.302] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[13:34:44.417] INFO: Resuming triggers.
[13:34:51.223] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:35:20.967] INFO: Resuming triggers.
[13:35:27.773] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:35:57.445] INFO: Resuming triggers.
[13:36:04.252] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:36:33.953] INFO: Resuming triggers.
[13:36:40.758] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[13:37:10.347] INFO: Resuming triggers.
[13:37:17.154] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[13:37:46.325] INFO: Resuming triggers.
[13:37:51.446] INFO: data taking finished, elapsed time: 100 seconds.
[13:38:13.796] INFO: PixTest:: pg_setup set to default.
[13:38:13.799] INFO: PixTestXray::doPhRun() done
[13:38:13.948] INFO: enter test to run
[13:39:19.489] INFO: test: HighRate no parameter change
[13:39:19.490] INFO: running: highrate
[13:39:19.503] INFO: ----------------------------------------------------------------------
[13:39:19.503] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:39:19.503] INFO: ----------------------------------------------------------------------
[13:39:19.643] INFO: Expecting 768 events.
[13:39:20.777] INFO: 768 events read in total (418ms).
[13:39:20.777] INFO: Test took 1268ms.
[13:39:21.580] INFO: Expecting 41600 events.
[13:39:24.497] INFO: 41600 events read in total (2390ms).
[13:39:24.498] INFO: Test took 3715ms.
[13:39:24.531] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:25.262] INFO: Expecting 41600 events.
[13:39:28.364] INFO: 41600 events read in total (2575ms).
[13:39:28.365] INFO: Test took 3816ms.
[13:39:28.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:29.121] INFO: Expecting 41600 events.
[13:39:32.278] INFO: 41600 events read in total (2630ms).
[13:39:32.279] INFO: Test took 3862ms.
[13:39:32.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:33.039] INFO: Expecting 41600 events.
[13:39:36.198] INFO: 41600 events read in total (2632ms).
[13:39:36.199] INFO: Test took 3868ms.
[13:39:36.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:36.958] INFO: Expecting 41600 events.
[13:39:40.010] INFO: 41600 events read in total (2525ms).
[13:39:40.011] INFO: Test took 3759ms.
[13:39:40.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:40.769] INFO: Expecting 41600 events.
[13:39:43.961] INFO: 41600 events read in total (2665ms).
[13:39:43.962] INFO: Test took 3899ms.
[13:39:44.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:44.697] INFO: Expecting 41600 events.
[13:39:47.843] INFO: 41600 events read in total (2619ms).
[13:39:47.844] INFO: Test took 3817ms.
[13:39:47.878] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:48.598] INFO: Expecting 41600 events.
[13:39:51.783] INFO: 41600 events read in total (2658ms).
[13:39:51.784] INFO: Test took 3888ms.
[13:39:51.818] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:52.542] INFO: Expecting 41600 events.
[13:39:55.751] INFO: 41600 events read in total (2683ms).
[13:39:55.752] INFO: Test took 3916ms.
[13:39:55.786] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:56.507] INFO: Expecting 41600 events.
[13:39:59.697] INFO: 41600 events read in total (2663ms).
[13:39:59.698] INFO: Test took 3894ms.
[13:39:59.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:00.452] INFO: Expecting 41600 events.
[13:40:03.704] INFO: 41600 events read in total (2726ms).
[13:40:03.705] INFO: Test took 3955ms.
[13:40:03.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:04.464] INFO: Expecting 41600 events.
[13:40:07.293] INFO: 41600 events read in total (2302ms).
[13:40:07.294] INFO: Test took 3536ms.
[13:40:07.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:08.052] INFO: Expecting 41600 events.
[13:40:11.274] INFO: 41600 events read in total (2695ms).
[13:40:11.275] INFO: Test took 3929ms.
[13:40:11.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:12.027] INFO: Expecting 41600 events.
[13:40:15.167] INFO: 41600 events read in total (2613ms).
[13:40:15.168] INFO: Test took 3841ms.
[13:40:15.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:15.929] INFO: Expecting 41600 events.
[13:40:19.095] INFO: 41600 events read in total (2639ms).
[13:40:19.096] INFO: Test took 3875ms.
[13:40:19.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:19.855] INFO: Expecting 41600 events.
[13:40:22.943] INFO: 41600 events read in total (2561ms).
[13:40:22.944] INFO: Test took 3793ms.
[13:40:22.979] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:23.696] INFO: Expecting 41600 events.
[13:40:26.820] INFO: 41600 events read in total (2597ms).
[13:40:26.821] INFO: Test took 3823ms.
[13:40:26.856] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:27.574] INFO: Expecting 41600 events.
[13:40:30.720] INFO: 41600 events read in total (2619ms).
[13:40:30.721] INFO: Test took 3847ms.
[13:40:30.755] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:31.479] INFO: Expecting 41600 events.
[13:40:34.675] INFO: 41600 events read in total (2669ms).
[13:40:34.676] INFO: Test took 3903ms.
[13:40:34.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:35.421] INFO: Expecting 41600 events.
[13:40:38.616] INFO: 41600 events read in total (2668ms).
[13:40:38.617] INFO: Test took 3889ms.
[13:40:38.650] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:39.010] INFO: enter test to run
[13:41:02.073] INFO: test: HighRate no parameter change
[13:41:02.073] INFO: running: highrate
[13:41:02.074] INFO: ----------------------------------------------------------------------
[13:41:02.074] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:41:02.074] INFO: ----------------------------------------------------------------------
[13:41:02.697] INFO: Expecting 208000 events.
[13:41:14.744] INFO: 208000 events read in total (11520ms).
[13:41:14.747] INFO: Test took 12665ms.
[13:41:14.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:15.148] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 3 1 0 0 0 2
[13:41:15.148] INFO: number of red-efficiency pixels: 86 49 67 123 116 172 127 84 81 140 112 84 108 56 25 21
[13:41:15.148] INFO: number of X-ray hits detected: 68196 41548 63161 108113 110969 117149 113285 85864 83463 97014 92490 76300 82151 47272 22126 26246
[13:41:15.148] 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:41:15.148] INFO: number of Vcal hits detected: 207913 207949 207933 207871 207884 207824 207867 207914 207918 207859 207740 207866 207890 207944 207974 207881
[13:41:15.148] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0
[13:41:15.148] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9
[13:41:15.148] INFO: X-ray hit rate [MHz/cm2]: 20.0 12.2 18.5 31.7 32.5 34.3 33.2 25.2 24.5 28.4 27.1 22.4 24.1 13.9 6.5 7.7
[13:41:15.149] INFO: PixTestHighRate::doXPixelAlive() done
[13:41:15.195] INFO: PixTest:: pg_setup set to default.
[13:41:15.208] INFO: enter test to run
[13:41:48.696] INFO: test: HighRate no parameter change
[13:41:48.696] INFO: running: highrate
[13:41:48.697] INFO: ----------------------------------------------------------------------
[13:41:48.697] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:41:48.698] INFO: ----------------------------------------------------------------------
[13:41:49.322] INFO: Expecting 208000 events.
[13:42:02.816] INFO: 208000 events read in total (12967ms).
[13:42:02.822] INFO: Test took 14115ms.
[13:42:03.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:03.418] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 3 1 0 0 0 2
[13:42:03.419] INFO: number of red-efficiency pixels: 239 126 205 375 370 575 351 268 228 380 356 217 310 162 75 49
[13:42:03.419] INFO: number of X-ray hits detected: 139269 86027 129454 221329 226445 240269 230624 176237 170361 198729 189365 156488 169274 97202 45196 53755
[13:42:03.419] 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:42:03.419] INFO: number of Vcal hits detected: 207749 207863 207779 207591 207614 207371 207605 207711 207764 207598 207471 207723 207678 207827 207920 207852
[13:42:03.419] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[13:42:03.419] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.9 99.9 99.8 99.7 99.9 99.8 99.9 100.0 99.9
[13:42:03.419] INFO: X-ray hit rate [MHz/cm2]: 40.8 25.2 37.9 64.9 66.4 70.4 67.6 51.7 49.9 58.2 55.5 45.9 49.6 28.5 13.2 15.8
[13:42:03.419] INFO: PixTestHighRate::doXPixelAlive() done
[13:42:03.463] INFO: PixTest:: pg_setup set to default.
[13:42:03.475] INFO: enter test to run
[13:43:20.744] INFO: test: HighRate no parameter change
[13:43:20.744] INFO: running: highrate
[13:43:20.745] INFO: ----------------------------------------------------------------------
[13:43:20.745] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:43:20.745] INFO: ----------------------------------------------------------------------
[13:43:21.365] INFO: Expecting 208000 events.
[13:43:36.277] INFO: 208000 events read in total (14386ms).
[13:43:36.284] INFO: Test took 15531ms.
[13:43:36.713] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:37.058] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 3 1 0 0 0 2
[13:43:37.058] INFO: number of red-efficiency pixels: 493 226 452 794 885 1264 884 638 473 883 723 427 621 356 100 104
[13:43:37.058] INFO: number of X-ray hits detected: 206737 127587 192911 328438 338051 356835 344938 262210 253601 295936 281152 233383 251653 144402 67784 80581
[13:43:37.058] 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:43:37.058] INFO: number of Vcal hits detected: 207428 207748 207464 207059 206945 206381 206905 207257 207477 206946 207016 207494 207312 207604 207896 207795
[13:43:37.058] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.5 99.3 99.5 99.7 99.8 99.5 99.6 99.8 99.7 99.8 100.0 100.0
[13:43:37.058] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.5 99.5 99.2 99.5 99.6 99.7 99.5 99.5 99.8 99.7 99.8 100.0 99.9
[13:43:37.058] INFO: X-ray hit rate [MHz/cm2]: 60.6 37.4 56.5 96.3 99.1 104.6 101.1 76.9 74.3 86.7 82.4 68.4 73.8 42.3 19.9 23.6
[13:43:37.058] INFO: PixTestHighRate::doXPixelAlive() done
[13:43:37.107] INFO: PixTest:: pg_setup set to default.
[13:43:37.122] INFO: enter test to run
[13:43:39.351] INFO: test: exit no parameter change
[13:43:39.623] QUIET: Connection to board 33 closed.
[13:43:39.624] INFO: pXar: this is the end, my friend