[15:09:07.472] INFO: *** Welcome to pxar ***
[15:09:07.472] INFO: *** Today: 2016/06/20
[15:09:07.497] INFO: *** Version: v1.9.0-814-g7497
[15:09:07.497] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//dacParameters35_C15.dat
[15:09:07.544] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:09:07.544] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//defaultMaskFile.dat
[15:09:07.546] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C15.dat
[15:09:07.695] INFO: clk: 4
[15:09:07.695] INFO: ctr: 4
[15:09:07.695] INFO: sda: 19
[15:09:07.695] INFO: tin: 9
[15:09:07.695] INFO: level: 15
[15:09:07.695] INFO: triggerdelay: 0
[15:09:07.695] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:09:07.695] INFO: Log level: INFO
[15:09:07.712] QUIET: Connection to board DTB_WREKRL opened.
[15:09:07.715] 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:09:07.718] INFO: RPC call hashes of host and DTB match: 398089610
[15:09:09.256] INFO: DUT info:
[15:09:09.256] INFO: The DUT currently contains the following objects:
[15:09:09.256] INFO: 2 TBM Cores tbm08c (2 ON)
[15:09:09.256] INFO: TBM Core alpha (0): 7 registers set
[15:09:09.256] INFO: TBM Core beta (1): 7 registers set
[15:09:09.256] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:09:09.256] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.256] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.257] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.257] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:09.680] INFO: enter 'restricted' command line mode
[15:09:09.680] INFO: enter test to run
[15:09:12.470] INFO: test: PixelAlive no parameter change
[15:09:12.470] INFO: running: pixelalive
[15:09:12.479] INFO: ----------------------------------------------------------------------
[15:09:12.479] 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:09:12.479] INFO: ----------------------------------------------------------------------
[15:09:12.801] INFO: Expecting 41600 events.
[15:09:17.168] INFO: 41600 events read in total (3648ms).
[15:09:17.334] INFO: Test took 4852ms.
[15:09:17.345] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:17.606] INFO: PixTestAlive::aliveTest() done
[15:09:17.606] INFO: number of dead pixels (per ROC): 2 0 1 0 0 0 0 0 2 0 0 0 0 0 0 0
[15:09:17.642] INFO: enter test to run
[15:09:32.221] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:09:32.222] INFO: running: highrate
[15:09:32.222] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:09:32.450] INFO: ----------------------------------------------------------------------
[15:09:32.450] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:09:32.450] INFO: ----------------------------------------------------------------------
[15:09:32.450] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:09:32.450] INFO: edge/corner pixel THR is adjusted
[15:09:32.450] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:09:33.409] INFO: Collecting data for 5 seconds...
[15:09:38.428] INFO: Done with hot pixel readout
[15:09:50.633] INFO: PixTest:: pg_setup set to default.
[15:09:50.634] INFO: 20 hot pixels found in step 0
[15:09:51.624] INFO: Collecting data for 5 seconds...
[15:09:56.645] INFO: Done with hot pixel readout
[15:10:08.665] INFO: PixTest:: pg_setup set to default.
[15:10:08.666] INFO: 15 hot pixels found in step 1
[15:10:09.664] INFO: Collecting data for 5 seconds...
[15:10:14.684] INFO: Done with hot pixel readout
[15:10:26.545] INFO: PixTest:: pg_setup set to default.
[15:10:26.546] INFO: 17 hot pixels found in step 2
[15:10:27.540] INFO: Collecting data for 5 seconds...
[15:10:32.559] INFO: Done with hot pixel readout
[15:10:44.444] INFO: PixTest:: pg_setup set to default.
[15:10:44.445] INFO: 15 hot pixels found in step 3
[15:10:45.439] INFO: Collecting data for 5 seconds...
[15:10:50.457] INFO: Done with hot pixel readout
[15:11:02.441] INFO: PixTest:: pg_setup set to default.
[15:11:02.442] INFO: 13 hot pixels found in step 4
[15:11:03.437] INFO: Collecting data for 5 seconds...
[15:11:08.452] INFO: Done with hot pixel readout
[15:11:20.390] INFO: PixTest:: pg_setup set to default.
[15:11:20.390] INFO: 13 hot pixels found in step 5
[15:11:21.385] INFO: Collecting data for 5 seconds...
[15:11:26.401] INFO: Done with hot pixel readout
[15:11:38.365] INFO: PixTest:: pg_setup set to default.
[15:11:38.366] INFO: 16 hot pixels found in step 6
[15:11:39.359] INFO: Collecting data for 5 seconds...
[15:11:44.375] INFO: Done with hot pixel readout
[15:11:56.367] INFO: PixTest:: pg_setup set to default.

[15:11:56.368] INFO: 22 hot pixels found in step 7
[15:11:57.361] INFO: Collecting data for 5 seconds...
[15:12:02.378] INFO: Done with hot pixel readout
[15:12:14.327] INFO: PixTest:: pg_setup set to default.
[15:12:14.328] INFO: 12 hot pixels found in step 8
[15:12:15.322] INFO: Collecting data for 5 seconds...
[15:12:20.338] INFO: Done with hot pixel readout
[15:12:32.317] INFO: PixTest:: pg_setup set to default.
[15:12:32.318] INFO: 9 hot pixels found in step 9
[15:12:33.312] INFO: Collecting data for 5 seconds...
[15:12:38.328] INFO: Done with hot pixel readout
[15:12:50.041] INFO: PixTest:: pg_setup set to default.
[15:12:50.042] INFO: 10 hot pixels found in step 10
[15:12:51.035] INFO: Collecting data for 5 seconds...
[15:12:56.051] INFO: Done with hot pixel readout
[15:13:08.004] INFO: PixTest:: pg_setup set to default.
[15:13:08.005] INFO: 5 hot pixels found in step 11
[15:13:08.998] INFO: Collecting data for 5 seconds...
[15:13:14.013] INFO: Done with hot pixel readout
[15:13:25.992] INFO: PixTest:: pg_setup set to default.

[15:13:25.993] INFO: 11 hot pixels found in step 12
[15:13:26.987] INFO: Collecting data for 5 seconds...
[15:13:32.003] INFO: Done with hot pixel readout
[15:13:43.920] INFO: PixTest:: pg_setup set to default.
[15:13:43.921] INFO: 6 hot pixels found in step 13
[15:13:44.915] INFO: Collecting data for 5 seconds...
[15:13:49.931] INFO: Done with hot pixel readout
[15:14:01.901] INFO: PixTest:: pg_setup set to default.
[15:14:01.901] INFO: 12 hot pixels found in step 14
[15:14:01.939] INFO: 12 hot pixels could not be trimmed and have been masked.
[15:14:01.943] INFO: PixTest::trimHotPixels() done
[15:14:01.943] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C0.dat
[15:14:01.949] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C1.dat
[15:14:01.955] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C2.dat
[15:14:01.961] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C3.dat
[15:14:01.966] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C4.dat
[15:14:01.971] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C5.dat
[15:14:01.976] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C6.dat
[15:14:01.982] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C7.dat
[15:14:01.987] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C8.dat
[15:14:01.992] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C9.dat
[15:14:01.997] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C10.dat
[15:14:02.003] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C11.dat
[15:14:02.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C12.dat
[15:14:02.013] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C13.dat
[15:14:02.018] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C14.dat
[15:14:02.024] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C15.dat
[15:14:02.029] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//defaultMaskFile.dat
[15:14:02.040] INFO: enter test to run
[15:15:16.299] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:15:16.299] INFO: running: highrate
[15:15:16.304] INFO: ----------------------------------------------------------------------
[15:15:16.304] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:15:16.304] INFO: ----------------------------------------------------------------------
[15:15:16.304] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:15:16.304] INFO: edge/corner pixel THR is adjusted
[15:15:16.304] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:15:17.261] INFO: Collecting data for 1 seconds...
[15:15:18.265] INFO: Done with hot pixel readout
[15:15:22.346] INFO: PixTest:: pg_setup set to default.
[15:15:22.347] INFO: 0 hot pixels found in step 0
[15:15:22.352] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:15:22.438] INFO: PixTest::trimHotPixels() done
[15:15:22.438] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C0.dat
[15:15:22.445] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C1.dat
[15:15:22.455] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C2.dat
[15:15:22.460] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C3.dat
[15:15:22.466] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C4.dat
[15:15:22.471] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C5.dat
[15:15:22.476] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C6.dat
[15:15:22.482] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C7.dat
[15:15:22.487] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C8.dat
[15:15:22.492] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C9.dat
[15:15:22.497] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C10.dat
[15:15:22.503] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C11.dat
[15:15:22.508] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C12.dat
[15:15:22.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C13.dat
[15:15:22.518] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C14.dat
[15:15:22.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//trimParameters35_C15.dat
[15:15:22.529] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-29_FPIXTest-17C-FNAL-160616-1221_2016-06-16_12h21m_1466097708/000_FPIXTest_p17//defaultMaskFile.dat
[15:15:22.538] INFO: enter test to run
[15:15:36.403] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:15:36.403] INFO: running: xray
[15:15:36.404] INFO: ----------------------------------------------------------------------
[15:15:36.404] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:15:36.404] INFO: ----------------------------------------------------------------------
[15:15:37.368] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:15:48.568] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:16:18.325] INFO: Resuming triggers.
[15:16:29.533] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:16:59.145] INFO: Resuming triggers.
[15:17:10.355] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:17:40.061] INFO: Resuming triggers.
[15:17:51.264] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:18:20.901] INFO: Resuming triggers.
[15:18:32.109] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:19:02.233] INFO: Resuming triggers.
[15:19:13.443] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:19:43.646] INFO: Resuming triggers.
[15:19:54.850] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[15:20:24.416] INFO: Resuming triggers.
[15:20:35.623] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:21:06.045] INFO: Resuming triggers.
[15:21:16.723] INFO: data taking finished, elapsed time: 100 seconds.
[15:21:45.540] INFO: PixTest:: pg_setup set to default.
[15:21:45.543] INFO: PixTestXray::doPhRun() done
[15:21:45.684] INFO: enter test to run
[15:24:01.831] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:24:01.832] INFO: running: xray
[15:24:01.833] INFO: ----------------------------------------------------------------------
[15:24:01.833] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:24:01.833] INFO: ----------------------------------------------------------------------
[15:24:02.804] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:24:09.339] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:24:39.777] INFO: Resuming triggers.
[15:24:46.310] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:25:16.491] INFO: Resuming triggers.
[15:25:23.026] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:25:53.229] INFO: Resuming triggers.
[15:25:59.765] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:26:29.948] INFO: Resuming triggers.
[15:26:36.490] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[15:27:06.685] INFO: Resuming triggers.
[15:27:13.221] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:27:43.359] INFO: Resuming triggers.
[15:27:49.902] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:28:20.163] INFO: Resuming triggers.
[15:28:26.700] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[15:28:56.909] INFO: Resuming triggers.
[15:29:03.449] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[15:29:33.615] INFO: Resuming triggers.
[15:29:40.153] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[15:30:10.311] INFO: Resuming triggers.
[15:30:16.851] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[15:30:48.147] INFO: Resuming triggers.
[15:30:54.684] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[15:31:25.364] INFO: Resuming triggers.
[15:31:31.906] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[15:32:02.625] INFO: Resuming triggers.
[15:32:09.161] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[15:32:41.006] INFO: Resuming triggers.
[15:32:47.546] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[15:33:19.086] INFO: Resuming triggers.
[15:33:21.345] INFO: data taking finished, elapsed time: 100 seconds.
[15:33:32.580] INFO: PixTest:: pg_setup set to default.
[15:33:32.583] INFO: PixTestXray::doPhRun() done
[15:33:32.736] INFO: enter test to run
[15:35:04.803] INFO: test: HighRate no parameter change
[15:35:04.803] INFO: running: highrate
[15:35:04.804] INFO: ----------------------------------------------------------------------
[15:35:04.804] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:35:04.804] INFO: ----------------------------------------------------------------------
[15:35:04.945] INFO: Expecting 768 events.
[15:35:06.079] INFO: 768 events read in total (418ms).
[15:35:06.080] INFO: Test took 1269ms.
[15:35:06.883] INFO: Expecting 41600 events.
[15:35:10.017] INFO: 41600 events read in total (2607ms).
[15:35:10.018] INFO: Test took 3930ms.
[15:35:10.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:10.774] INFO: Expecting 41600 events.
[15:35:13.993] INFO: 41600 events read in total (2693ms).
[15:35:13.994] INFO: Test took 3923ms.
[15:35:14.030] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:14.750] INFO: Expecting 41600 events.
[15:35:17.999] INFO: 41600 events read in total (2722ms).
[15:35:17.000] INFO: Test took 3951ms.
[15:35:18.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:18.754] INFO: Expecting 41600 events.
[15:35:21.999] INFO: 41600 events read in total (2718ms).
[15:35:21.000] INFO: Test took 3946ms.
[15:35:22.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:22.757] INFO: Expecting 41600 events.
[15:35:26.006] INFO: 41600 events read in total (2722ms).
[15:35:26.007] INFO: Test took 3953ms.
[15:35:26.043] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:26.765] INFO: Expecting 41600 events.
[15:35:30.013] INFO: 41600 events read in total (2721ms).
[15:35:30.014] INFO: Test took 3954ms.
[15:35:30.049] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:30.770] INFO: Expecting 41600 events.
[15:35:33.682] INFO: 41600 events read in total (2385ms).
[15:35:33.684] INFO: Test took 3617ms.
[15:35:33.726] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:34.436] INFO: Expecting 41600 events.
[15:35:37.682] INFO: 41600 events read in total (2720ms).
[15:35:37.683] INFO: Test took 3937ms.
[15:35:37.719] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:38.441] INFO: Expecting 41600 events.
[15:35:41.582] INFO: 41600 events read in total (2614ms).
[15:35:41.583] INFO: Test took 3847ms.
[15:35:41.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:42.340] INFO: Expecting 41600 events.
[15:35:45.600] INFO: 41600 events read in total (2733ms).
[15:35:45.601] INFO: Test took 3965ms.
[15:35:45.638] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:46.355] INFO: Expecting 41600 events.
[15:35:49.621] INFO: 41600 events read in total (2739ms).
[15:35:49.622] INFO: Test took 3966ms.
[15:35:49.658] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:50.377] INFO: Expecting 41600 events.
[15:35:53.616] INFO: 41600 events read in total (2712ms).
[15:35:53.617] INFO: Test took 3938ms.
[15:35:53.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:54.370] INFO: Expecting 41600 events.
[15:35:57.666] INFO: 41600 events read in total (2769ms).
[15:35:57.667] INFO: Test took 3995ms.
[15:35:57.704] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:58.424] INFO: Expecting 41600 events.
[15:36:01.667] INFO: 41600 events read in total (2716ms).
[15:36:01.668] INFO: Test took 3946ms.
[15:36:01.703] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:02.422] INFO: Expecting 41600 events.
[15:36:05.687] INFO: 41600 events read in total (2738ms).
[15:36:05.688] INFO: Test took 3967ms.
[15:36:05.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:06.442] INFO: Expecting 41600 events.
[15:36:09.720] INFO: 41600 events read in total (2752ms).
[15:36:09.721] INFO: Test took 3978ms.
[15:36:09.758] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:10.473] INFO: Expecting 41600 events.
[15:36:13.721] INFO: 41600 events read in total (2721ms).
[15:36:13.722] INFO: Test took 3946ms.
[15:36:13.759] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:14.471] INFO: Expecting 41600 events.
[15:36:17.723] INFO: 41600 events read in total (2725ms).
[15:36:17.724] INFO: Test took 3945ms.
[15:36:17.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:18.478] INFO: Expecting 41600 events.
[15:36:21.711] INFO: 41600 events read in total (2707ms).
[15:36:21.712] INFO: Test took 3933ms.
[15:36:21.747] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:22.472] INFO: Expecting 41600 events.
[15:36:25.535] INFO: 41600 events read in total (2536ms).
[15:36:25.536] INFO: Test took 3770ms.
[15:36:25.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:25.933] INFO: enter test to run
[15:38:18.746] INFO: test: HighRate no parameter change
[15:38:18.746] INFO: running: highrate
[15:38:18.747] INFO: ----------------------------------------------------------------------
[15:38:18.747] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:38:18.747] INFO: ----------------------------------------------------------------------
[15:38:19.366] INFO: Expecting 208000 events.
[15:38:31.307] INFO: 208000 events read in total (11414ms).
[15:38:31.310] INFO: Test took 12554ms.
[15:38:31.459] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:31.713] INFO: number of dead pixels (per ROC): 1 0 1 0 0 0 0 0 2 0 0 0 0 0 0 0
[15:38:31.713] INFO: number of red-efficiency pixels: 104 52 80 126 142 160 145 104 120 121 113 96 96 62 19 27
[15:38:31.713] INFO: number of X-ray hits detected: 76740 47970 73473 112573 122643 126418 126581 90578 83926 96912 96752 85040 83660 52762 21545 24291
[15:38:31.713] 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:38:31.713] INFO: number of Vcal hits detected: 207847 207946 207864 207871 207850 207835 207851 207894 207780 207876 207883 207901 207903 207938 207981 207973
[15:38:31.713] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:38:31.713] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:38:31.713] INFO: X-ray hit rate [MHz/cm2]: 22.5 14.1 21.5 33.0 35.9 37.1 37.1 26.5 24.6 28.4 28.4 24.9 24.5 15.5 6.3 7.1
[15:38:31.713] INFO: PixTestHighRate::doXPixelAlive() done
[15:38:31.759] INFO: PixTest:: pg_setup set to default.
[15:38:31.769] INFO: enter test to run
[15:39:29.937] INFO: test: HighRate no parameter change
[15:39:29.937] INFO: running: highrate
[15:39:29.939] INFO: ----------------------------------------------------------------------
[15:39:29.939] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:39:29.939] INFO: ----------------------------------------------------------------------
[15:39:30.550] INFO: Expecting 208000 events.
[15:39:44.303] INFO: 208000 events read in total (13226ms).
[15:39:44.309] INFO: Test took 14360ms.
[15:39:44.622] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:44.927] INFO: number of dead pixels (per ROC): 1 0 1 0 0 0 0 0 2 0 0 0 0 0 0 0
[15:39:44.928] INFO: number of red-efficiency pixels: 283 156 297 363 477 618 470 325 322 341 304 345 284 191 53 69
[15:39:44.928] INFO: number of X-ray hits detected: 154206 97662 148697 226833 248713 255537 256113 183895 170858 196622 198092 172377 171190 106343 44070 49444
[15:39:44.928] 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:39:44.928] INFO: number of Vcal hits detected: 207641 207833 207620 207604 207476 207293 207489 207651 207556 207641 207673 207633 207704 207796 207947 207931
[15:39:44.928] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.8 99.8 99.8 99.9 99.8 99.9 99.9 100.0 100.0
[15:39:44.928] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.8 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[15:39:44.928] INFO: X-ray hit rate [MHz/cm2]: 45.2 28.6 43.6 66.5 72.9 74.9 75.1 53.9 50.1 57.6 58.1 50.5 50.2 31.2 12.9 14.5
[15:39:44.928] INFO: PixTestHighRate::doXPixelAlive() done
[15:39:44.980] INFO: PixTest:: pg_setup set to default.
[15:39:44.000] INFO: enter test to run
[15:40:17.905] INFO: test: HighRate no parameter change
[15:40:17.905] INFO: running: highrate
[15:40:17.906] INFO: ----------------------------------------------------------------------
[15:40:17.906] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:40:17.906] INFO: ----------------------------------------------------------------------
[15:40:18.523] INFO: Expecting 208000 events.
[15:40:34.165] INFO: 208000 events read in total (15115ms).
[15:40:34.173] INFO: Test took 16256ms.
[15:40:34.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:40:34.998] INFO: number of dead pixels (per ROC): 1 0 1 0 0 0 0 0 2 0 0 0 0 0 0 0
[15:40:34.999] INFO: number of red-efficiency pixels: 594 353 759 888 1045 1510 1182 677 708 746 721 718 712 436 97 83
[15:40:34.999] INFO: number of X-ray hits detected: 234754 147356 225433 343217 377191 386122 386130 277461 259873 298472 299447 260208 258533 162164 66751 74820
[15:40:34.999] 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:40:34.999] INFO: number of Vcal hits detected: 207201 207586 206925 206936 206671 205861 206492 207155 207121 207132 207145 207127 207196 207485 207897 207915
[15:40:34.999] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.5 99.4 99.1 99.4 99.6 99.6 99.6 99.6 99.6 99.6 99.8 100.0 100.0
[15:40:34.999] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.5 99.4 99.0 99.3 99.6 99.6 99.6 99.6 99.6 99.6 99.8 100.0 100.0
[15:40:34.999] INFO: X-ray hit rate [MHz/cm2]: 68.8 43.2 66.1 100.6 110.6 113.2 113.2 81.3 76.2 87.5 87.8 76.3 75.8 47.5 19.6 21.9
[15:40:34.999] INFO: PixTestHighRate::doXPixelAlive() done
[15:40:35.048] INFO: PixTest:: pg_setup set to default.
[15:40:35.061] INFO: enter test to run
[15:40:36.961] INFO: test: exit no parameter change
[15:40:37.247] QUIET: Connection to board 33 closed.
[15:40:37.249] INFO: pXar: this is the end, my friend