[10:26:46.010] INFO: *** Welcome to pxar ***
[10:26:46.010] INFO: *** Today: 2016/04/15
[10:26:46.030] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:26:46.031] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//dacParameters35_C15.dat
[10:26:46.056] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:26:46.056] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//defaultMaskFile.dat
[10:26:46.056] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C15.dat
[10:26:46.177] INFO: clk: 4
[10:26:46.177] INFO: ctr: 4
[10:26:46.177] INFO: sda: 19
[10:26:46.177] INFO: tin: 9
[10:26:46.177] INFO: level: 15
[10:26:46.177] INFO: triggerdelay: 0
[10:26:46.177] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:26:46.177] INFO: Log level: INFO
[10:26:46.195] QUIET: Connection to board DTB_WREKRL opened.
[10:26:46.199] 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:
------------------------------------------------------
[10:26:46.202] INFO: RPC call hashes of host and DTB match: 398089610
[10:26:47.732] INFO: DUT info:
[10:26:47.732] INFO: The DUT currently contains the following objects:
[10:26:47.732] INFO: 2 TBM Cores tbm08c (2 ON)
[10:26:47.732] INFO: TBM Core alpha (0): 7 registers set
[10:26:47.732] INFO: TBM Core beta (1): 7 registers set
[10:26:47.732] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:26:47.732] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.732] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.732] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.732] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.732] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.732] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.732] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.733] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.733] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.733] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.733] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.733] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.733] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.733] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.733] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:47.733] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:48.136] INFO: enter 'restricted' command line mode
[10:26:48.137] INFO: enter test to run
[10:26:54.875] INFO: test: PixelAlive no parameter change
[10:26:54.875] INFO: running: pixelalive
[10:26:54.884] INFO: ----------------------------------------------------------------------
[10:26:54.884] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:26:54.884] INFO: ----------------------------------------------------------------------
[10:26:55.199] INFO: Expecting 41600 events.
[10:26:59.539] INFO: 41600 events read in total (3622ms).
[10:26:59.707] INFO: Test took 4821ms.
[10:26:59.722] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:00.012] INFO: PixTestAlive::aliveTest() done
[10:27:00.013] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 1 0 0 0 0 0 0 0 0
[10:27:00.042] INFO: enter test to run
[10:27:16.082] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:27:16.083] INFO: running: highrate
[10:27:16.083] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:27:16.299] INFO: ----------------------------------------------------------------------
[10:27:16.299] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:27:16.299] INFO: ----------------------------------------------------------------------
[10:27:16.299] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:27:16.299] INFO: edge/corner pixel THR is adjusted
[10:27:16.299] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:27:17.258] INFO: Collecting data for 5 seconds...
[10:27:22.274] INFO: Done with hot pixel readout
[10:27:34.242] INFO: PixTest:: pg_setup set to default.
[10:27:34.243] INFO: 6 hot pixels found in step 0
[10:27:35.261] INFO: Collecting data for 5 seconds...
[10:27:40.278] INFO: Done with hot pixel readout
[10:27:52.333] INFO: PixTest:: pg_setup set to default.
[10:27:52.334] INFO: 2 hot pixels found in step 1
[10:27:53.327] INFO: Collecting data for 5 seconds...
[10:27:58.345] INFO: Done with hot pixel readout
[10:28:10.439] INFO: PixTest:: pg_setup set to default.
[10:28:10.440] INFO: 5 hot pixels found in step 2
[10:28:11.436] INFO: Collecting data for 5 seconds...
[10:28:16.453] INFO: Done with hot pixel readout
[10:28:28.471] INFO: PixTest:: pg_setup set to default.
[10:28:28.472] INFO: 9 hot pixels found in step 3
[10:28:29.470] INFO: Collecting data for 5 seconds...
[10:28:34.486] INFO: Done with hot pixel readout
[10:28:46.628] INFO: PixTest:: pg_setup set to default.
[10:28:46.629] INFO: 2 hot pixels found in step 4
[10:28:47.627] INFO: Collecting data for 5 seconds...
[10:28:52.643] INFO: Done with hot pixel readout
[10:29:04.835] INFO: PixTest:: pg_setup set to default.
[10:29:04.835] INFO: 4 hot pixels found in step 5
[10:29:05.831] INFO: Collecting data for 5 seconds...
[10:29:10.847] INFO: Done with hot pixel readout
[10:29:23.038] INFO: PixTest:: pg_setup set to default.
[10:29:23.039] INFO: 4 hot pixels found in step 6
[10:29:24.035] INFO: Collecting data for 5 seconds...
[10:29:29.051] INFO: Done with hot pixel readout
[10:29:41.252] INFO: PixTest:: pg_setup set to default.
[10:29:41.253] INFO: 6 hot pixels found in step 7
[10:29:42.249] INFO: Collecting data for 5 seconds...
[10:29:47.264] INFO: Done with hot pixel readout
[10:29:59.457] INFO: PixTest:: pg_setup set to default.
[10:29:59.458] INFO: 4 hot pixels found in step 8
[10:30:00.455] INFO: Collecting data for 5 seconds...
[10:30:05.471] INFO: Done with hot pixel readout
[10:30:17.686] INFO: PixTest:: pg_setup set to default.

[10:30:17.687] INFO: 7 hot pixels found in step 9
[10:30:18.684] INFO: Collecting data for 5 seconds...
[10:30:23.700] INFO: Done with hot pixel readout
[10:30:35.902] INFO: PixTest:: pg_setup set to default.
[10:30:35.903] INFO: 2 hot pixels found in step 10
[10:30:36.901] INFO: Collecting data for 5 seconds...
[10:30:41.917] INFO: Done with hot pixel readout
[10:30:54.113] INFO: PixTest:: pg_setup set to default.
[10:30:54.114] INFO: 3 hot pixels found in step 11
[10:30:55.110] INFO: Collecting data for 5 seconds...
[10:31:00.127] INFO: Done with hot pixel readout
[10:31:12.313] INFO: PixTest:: pg_setup set to default.
[10:31:12.314] INFO: 5 hot pixels found in step 12
[10:31:13.310] INFO: Collecting data for 5 seconds...
[10:31:18.327] INFO: Done with hot pixel readout
[10:31:30.548] INFO: PixTest:: pg_setup set to default.
[10:31:30.549] INFO: 7 hot pixels found in step 13
[10:31:31.545] INFO: Collecting data for 5 seconds...
[10:31:36.561] INFO: Done with hot pixel readout
[10:31:48.741] INFO: PixTest:: pg_setup set to default.
[10:31:48.742] INFO: 8 hot pixels found in step 14
[10:31:48.787] INFO: 8 hot pixels could not be trimmed and have been masked.
[10:31:48.790] INFO: PixTest::trimHotPixels() done
[10:31:48.790] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C0.dat
[10:31:48.796] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C1.dat
[10:31:48.802] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C2.dat
[10:31:48.808] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C3.dat
[10:31:48.813] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C4.dat
[10:31:48.819] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C5.dat
[10:31:48.824] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C6.dat
[10:31:48.845] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C7.dat
[10:31:48.852] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C8.dat
[10:31:48.858] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C9.dat
[10:31:48.863] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C10.dat
[10:31:48.869] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C11.dat
[10:31:48.874] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C12.dat
[10:31:48.879] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C13.dat
[10:31:48.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C14.dat
[10:31:48.890] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C15.dat
[10:31:48.895] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//defaultMaskFile.dat
[10:31:48.905] INFO: enter test to run
[10:32:11.992] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:32:11.992] INFO: running: highrate
[10:32:11.997] INFO: ----------------------------------------------------------------------
[10:32:11.997] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:32:11.997] INFO: ----------------------------------------------------------------------
[10:32:11.997] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:32:11.997] INFO: edge/corner pixel THR is adjusted
[10:32:11.997] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:32:12.954] INFO: Collecting data for 1 seconds...
[10:32:13.958] INFO: Done with hot pixel readout
[10:32:18.229] INFO: PixTest:: pg_setup set to default.
[10:32:18.230] INFO: 0 hot pixels found in step 0
[10:32:18.235] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:32:18.313] INFO: PixTest::trimHotPixels() done
[10:32:18.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C0.dat
[10:32:18.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C1.dat
[10:32:18.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C2.dat
[10:32:18.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C3.dat
[10:32:18.337] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C4.dat
[10:32:18.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C5.dat
[10:32:18.347] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C6.dat
[10:32:18.352] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C7.dat
[10:32:18.357] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C8.dat
[10:32:18.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C9.dat
[10:32:18.368] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C10.dat
[10:32:18.373] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C11.dat
[10:32:18.378] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C12.dat
[10:32:18.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C13.dat
[10:32:18.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C14.dat
[10:32:18.394] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//trimParameters35_C15.dat
[10:32:18.399] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-30_FPIXTest-17C-FNAL-160408-1158_2016-04-08_11h58m_1460134718/000_FPIXTest_p17//defaultMaskFile.dat
[10:32:18.414] INFO: enter test to run
[10:32:35.449] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:32:35.449] INFO: running: xray
[10:32:35.450] INFO: ----------------------------------------------------------------------
[10:32:35.450] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:32:35.450] INFO: ----------------------------------------------------------------------
[10:32:36.414] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:32:47.284] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[10:33:16.888] INFO: Resuming triggers.
[10:33:27.760] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[10:33:57.391] INFO: Resuming triggers.
[10:34:08.256] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[10:34:37.763] INFO: Resuming triggers.
[10:34:48.632] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[10:35:14.644] INFO: Resuming triggers.
[10:35:25.511] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[10:35:55.042] INFO: Resuming triggers.
[10:36:05.911] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[10:36:35.410] INFO: Resuming triggers.
[10:36:46.281] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[10:37:15.914] INFO: Resuming triggers.
[10:37:26.784] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[10:37:56.333] INFO: Resuming triggers.
[10:38:07.200] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[10:38:36.798] INFO: Resuming triggers.
[10:38:39.303] INFO: data taking finished, elapsed time: 100 seconds.
[10:38:46.449] INFO: PixTest:: pg_setup set to default.
[10:38:46.453] INFO: PixTestXray::doPhRun() done
[10:38:46.590] INFO: enter test to run
[10:39:47.341] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:39:47.341] INFO: running: xray
[10:39:47.342] INFO: ----------------------------------------------------------------------
[10:39:47.342] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:39:47.342] INFO: ----------------------------------------------------------------------
[10:39:48.313] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:39:54.475] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:40:24.444] INFO: Resuming triggers.
[10:40:30.613] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[10:41:00.561] INFO: Resuming triggers.
[10:41:06.724] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[10:41:36.696] INFO: Resuming triggers.
[10:41:42.858] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[10:42:12.867] INFO: Resuming triggers.
[10:42:19.029] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[10:42:48.975] INFO: Resuming triggers.
[10:42:55.141] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[10:43:25.160] INFO: Resuming triggers.
[10:43:31.322] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[10:44:01.311] INFO: Resuming triggers.
[10:44:07.473] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[10:44:37.436] INFO: Resuming triggers.
[10:44:43.602] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[10:45:13.464] INFO: Resuming triggers.
[10:45:19.629] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[10:45:49.068] INFO: Resuming triggers.
[10:45:55.235] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[10:46:25.211] INFO: Resuming triggers.
[10:46:31.378] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[10:47:01.313] INFO: Resuming triggers.
[10:47:07.479] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[10:47:37.490] INFO: Resuming triggers.
[10:47:43.658] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[10:48:13.709] INFO: Resuming triggers.
[10:48:19.875] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:48:49.936] INFO: Resuming triggers.
[10:48:56.104] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[10:49:26.163] INFO: Resuming triggers.
[10:49:27.842] INFO: data taking finished, elapsed time: 100 seconds.
[10:49:36.335] INFO: PixTest:: pg_setup set to default.
[10:49:36.338] INFO: PixTestXray::doPhRun() done
[10:49:36.489] INFO: enter test to run
[10:50:45.200] INFO: test: HighRate no parameter change
[10:50:45.200] INFO: running: highrate
[10:50:45.201] INFO: ----------------------------------------------------------------------
[10:50:45.201] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:50:45.201] INFO: ----------------------------------------------------------------------
[10:50:45.343] INFO: Expecting 768 events.
[10:50:46.477] INFO: 768 events read in total (418ms).
[10:50:46.477] INFO: Test took 1269ms.
[10:50:47.281] INFO: Expecting 41600 events.
[10:50:50.401] INFO: 41600 events read in total (2593ms).
[10:50:50.402] INFO: Test took 3919ms.
[10:50:50.440] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:51.157] INFO: Expecting 41600 events.
[10:50:54.404] INFO: 41600 events read in total (2720ms).
[10:50:54.405] INFO: Test took 3945ms.
[10:50:54.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:55.161] INFO: Expecting 41600 events.
[10:50:58.450] INFO: 41600 events read in total (2762ms).
[10:50:58.450] INFO: Test took 3986ms.
[10:50:58.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:59.206] INFO: Expecting 41600 events.
[10:51:02.490] INFO: 41600 events read in total (2757ms).
[10:51:02.491] INFO: Test took 3983ms.
[10:51:02.530] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:03.244] INFO: Expecting 41600 events.
[10:51:06.523] INFO: 41600 events read in total (2753ms).
[10:51:06.524] INFO: Test took 3973ms.
[10:51:06.562] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:07.277] INFO: Expecting 41600 events.
[10:51:10.577] INFO: 41600 events read in total (2773ms).
[10:51:10.578] INFO: Test took 3997ms.
[10:51:10.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:11.330] INFO: Expecting 41600 events.
[10:51:14.624] INFO: 41600 events read in total (2767ms).
[10:51:14.625] INFO: Test took 3986ms.
[10:51:14.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:15.379] INFO: Expecting 41600 events.
[10:51:18.666] INFO: 41600 events read in total (2760ms).
[10:51:18.667] INFO: Test took 3984ms.
[10:51:18.706] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:19.419] INFO: Expecting 41600 events.
[10:51:22.701] INFO: 41600 events read in total (2755ms).
[10:51:22.702] INFO: Test took 3977ms.
[10:51:22.742] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:23.457] INFO: Expecting 41600 events.
[10:51:26.754] INFO: 41600 events read in total (2770ms).
[10:51:26.755] INFO: Test took 3994ms.
[10:51:26.794] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:27.506] INFO: Expecting 41600 events.
[10:51:30.797] INFO: 41600 events read in total (2765ms).
[10:51:30.798] INFO: Test took 3984ms.
[10:51:30.837] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:31.549] INFO: Expecting 41600 events.
[10:51:34.841] INFO: 41600 events read in total (2766ms).
[10:51:34.842] INFO: Test took 3985ms.
[10:51:34.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:35.594] INFO: Expecting 41600 events.
[10:51:38.899] INFO: 41600 events read in total (2778ms).
[10:51:38.900] INFO: Test took 3999ms.
[10:51:38.939] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:39.653] INFO: Expecting 41600 events.
[10:51:42.933] INFO: 41600 events read in total (2753ms).
[10:51:42.934] INFO: Test took 3976ms.
[10:51:42.973] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:43.689] INFO: Expecting 41600 events.
[10:51:46.962] INFO: 41600 events read in total (2746ms).
[10:51:46.963] INFO: Test took 3970ms.
[10:51:47.002] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:47.715] INFO: Expecting 41600 events.
[10:51:51.009] INFO: 41600 events read in total (2767ms).
[10:51:51.010] INFO: Test took 3988ms.
[10:51:51.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:51.766] INFO: Expecting 41600 events.
[10:51:55.053] INFO: 41600 events read in total (2760ms).
[10:51:55.054] INFO: Test took 3986ms.
[10:51:55.092] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:55.809] INFO: Expecting 41600 events.
[10:51:59.096] INFO: 41600 events read in total (2760ms).
[10:51:59.097] INFO: Test took 3986ms.
[10:51:59.136] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:59.850] INFO: Expecting 41600 events.
[10:52:03.128] INFO: 41600 events read in total (2751ms).
[10:52:03.129] INFO: Test took 3972ms.
[10:52:03.167] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:03.882] INFO: Expecting 41600 events.
[10:52:07.047] INFO: 41600 events read in total (2638ms).
[10:52:07.048] INFO: Test took 3860ms.
[10:52:07.085] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:07.433] INFO: enter test to run
[10:53:01.567] INFO: test: HighRate no parameter change
[10:53:01.567] INFO: running: highrate
[10:53:01.569] INFO: ----------------------------------------------------------------------
[10:53:01.569] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:53:01.569] INFO: ----------------------------------------------------------------------
[10:53:02.184] INFO: Expecting 208000 events.
[10:53:14.316] INFO: 208000 events read in total (11606ms).
[10:53:14.319] INFO: Test took 12740ms.
[10:53:14.491] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:14.751] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 1 0 0 0 0 0 0 0 0
[10:53:14.751] INFO: number of red-efficiency pixels: 86 62 108 171 189 201 181 118 127 181 174 145 127 75 25 38
[10:53:14.751] INFO: number of X-ray hits detected: 71588 48747 78182 129641 134319 136803 131729 94751 100819 113397 115236 98062 105491 61420 26618 32630
[10:53:14.752] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:53:14.752] INFO: number of Vcal hits detected: 207911 207937 207890 207823 207806 207793 207764 207830 207864 207813 207820 207851 207872 207925 207975 207961
[10:53:14.752] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:53:14.752] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:53:14.752] INFO: X-ray hit rate [MHz/cm2]: 21.0 14.3 22.9 38.0 39.4 40.1 38.6 27.8 29.6 33.2 33.8 28.7 30.9 18.0 7.8 9.6
[10:53:14.752] INFO: PixTestHighRate::doXPixelAlive() done
[10:53:14.797] INFO: PixTest:: pg_setup set to default.
[10:53:14.814] INFO: enter test to run
[10:53:50.439] INFO: test: HighRate no parameter change
[10:53:50.439] INFO: running: highrate
[10:53:50.440] INFO: ----------------------------------------------------------------------
[10:53:50.440] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:53:50.440] INFO: ----------------------------------------------------------------------
[10:53:51.057] INFO: Expecting 208000 events.
[10:54:05.210] INFO: 208000 events read in total (13626ms).
[10:54:05.216] INFO: Test took 14767ms.
[10:54:05.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:05.868] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 1 0 0 0 0 0 0 0 0
[10:54:05.868] INFO: number of red-efficiency pixels: 258 143 354 546 482 668 671 351 329 547 554 398 405 282 63 91
[10:54:05.868] INFO: number of X-ray hits detected: 144347 98805 157157 260637 270415 275344 265995 192467 202575 228215 231748 196972 212688 124729 53928 65849
[10:54:05.868] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:54:05.868] INFO: number of Vcal hits detected: 207717 207848 207596 207395 207470 207226 207174 207565 207649 207397 207392 207581 207564 207695 207937 207905
[10:54:05.868] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.7 99.7 99.8 99.8 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[10:54:05.868] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.6 99.6 99.8 99.8 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[10:54:05.868] INFO: X-ray hit rate [MHz/cm2]: 42.3 29.0 46.1 76.4 79.3 80.7 78.0 56.4 59.4 66.9 67.9 57.7 62.3 36.6 15.8 19.3
[10:54:05.868] INFO: PixTestHighRate::doXPixelAlive() done
[10:54:05.916] INFO: PixTest:: pg_setup set to default.
[10:54:05.934] INFO: enter test to run
[10:54:46.055] INFO: test: HighRate no parameter change
[10:54:46.055] INFO: running: highrate
[10:54:46.056] INFO: ----------------------------------------------------------------------
[10:54:46.056] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:54:46.056] INFO: ----------------------------------------------------------------------
[10:54:46.677] INFO: Expecting 208000 events.
[10:55:02.952] INFO: 208000 events read in total (15748ms).
[10:55:02.961] INFO: Test took 16895ms.
[10:55:03.467] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:55:03.838] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 1 0 0 0 0 0 0 0 0
[10:55:03.838] INFO: number of red-efficiency pixels: 526 283 781 1244 1160 1419 1523 749 763 1175 1268 885 948 585 110 140
[10:55:03.838] INFO: number of X-ray hits detected: 215204 145745 234595 385881 400188 408449 392948 285364 301012 339285 343390 292780 314910 183473 79671 97497
[10:55:03.838] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:55:03.838] INFO: number of Vcal hits detected: 207360 207688 206906 206360 206538 206030 205797 206988 207087 206512 206364 206931 206861 207293 207886 207857
[10:55:03.838] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.5 99.3 99.4 99.2 99.1 99.6 99.6 99.4 99.3 99.6 99.5 99.7 99.9 99.9
[10:55:03.838] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.5 99.2 99.3 99.1 98.9 99.5 99.6 99.3 99.2 99.5 99.5 99.7 99.9 99.9
[10:55:03.838] INFO: X-ray hit rate [MHz/cm2]: 63.1 42.7 68.8 113.1 117.3 119.7 115.2 83.6 88.2 99.4 100.7 85.8 92.3 53.8 23.4 28.6
[10:55:03.838] INFO: PixTestHighRate::doXPixelAlive() done
[10:55:03.883] INFO: PixTest:: pg_setup set to default.
[10:55:03.898] INFO: enter test to run
[10:56:11.182] INFO: test: exit no parameter change
[10:56:11.458] QUIET: Connection to board 33 closed.
[10:56:11.459] INFO: pXar: this is the end, my friend