[09:59:25.746] INFO: *** Welcome to pxar ***
[09:59:25.747] INFO: *** Today: 2016/04/22
[09:59:25.763] INFO: *** Version: v1.9.0-796-gef167-dirty
[09:59:25.763] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//dacParameters35_C15.dat
[09:59:25.818] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:59:25.819] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//defaultMaskFile.dat
[09:59:25.819] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C15.dat
[09:59:25.933] INFO: clk: 4
[09:59:25.933] INFO: ctr: 4
[09:59:25.933] INFO: sda: 19
[09:59:25.933] INFO: tin: 9
[09:59:25.933] INFO: level: 15
[09:59:25.933] INFO: triggerdelay: 0
[09:59:25.933] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[09:59:25.933] INFO: Log level: INFO
[09:59:25.951] QUIET: Connection to board DTB_WREK4U opened.
[09:59:25.954] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[09:59:25.957] INFO: RPC call hashes of host and DTB match: 398089610
[09:59:27.489] INFO: DUT info:
[09:59:27.489] INFO: The DUT currently contains the following objects:
[09:59:27.489] INFO: 2 TBM Cores tbm08c (2 ON)
[09:59:27.489] INFO: TBM Core alpha (0): 7 registers set
[09:59:27.489] INFO: TBM Core beta (1): 7 registers set
[09:59:27.489] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:59:27.489] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.489] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.490] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.490] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:27.893] INFO: enter 'restricted' command line mode
[09:59:27.893] INFO: enter test to run
[09:59:49.458] INFO: test: PixelAlive no parameter change
[09:59:49.458] INFO: running: pixelalive
[09:59:49.467] INFO: ----------------------------------------------------------------------
[09:59:49.467] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:59:49.467] INFO: ----------------------------------------------------------------------
[09:59:49.783] INFO: Expecting 41600 events.
[09:59:54.113] INFO: 41600 events read in total (3612ms).
[09:59:54.280] INFO: Test took 4811ms.
[09:59:54.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:54.555] INFO: PixTestAlive::aliveTest() done
[09:59:54.555] INFO: number of dead pixels (per ROC): 0 0 2 3 0 0 0 0 1 3 0 0 0 0 0 0
[09:59:54.590] INFO: enter test to run
[10:00:18.458] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:00:18.458] INFO: running: highrate
[10:00:18.458] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:00:18.675] INFO: ----------------------------------------------------------------------
[10:00:18.675] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:00:18.675] INFO: ----------------------------------------------------------------------
[10:00:18.675] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:00:18.675] INFO: edge/corner pixel THR is adjusted
[10:00:18.675] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:00:19.634] INFO: Collecting data for 5 seconds...
[10:00:24.651] INFO: Done with hot pixel readout
[10:00:37.007] INFO: PixTest:: pg_setup set to default.
[10:00:37.007] INFO: 32 hot pixels found in step 0
[10:00:38.031] INFO: Collecting data for 5 seconds...
[10:00:43.047] INFO: Done with hot pixel readout
[10:00:55.381] INFO: PixTest:: pg_setup set to default.


[10:00:55.382] INFO: 32 hot pixels found in step 1
[10:00:56.373] INFO: Collecting data for 5 seconds...
[10:01:01.389] INFO: Done with hot pixel readout
[10:01:13.725] INFO: PixTest:: pg_setup set to default.


[10:01:13.726] INFO: 34 hot pixels found in step 2
[10:01:14.718] INFO: Collecting data for 5 seconds...
[10:01:19.735] INFO: Done with hot pixel readout
[10:01:31.718] INFO: PixTest:: pg_setup set to default.


[10:01:31.719] INFO: 24 hot pixels found in step 3
[10:01:32.712] INFO: Collecting data for 5 seconds...
[10:01:37.727] INFO: Done with hot pixel readout
[10:01:49.000] INFO: PixTest:: pg_setup set to default.

[10:01:49.001] INFO: 21 hot pixels found in step 4
[10:01:50.995] INFO: Collecting data for 5 seconds...
[10:01:56.012] INFO: Done with hot pixel readout
[10:02:08.238] INFO: PixTest:: pg_setup set to default.

[10:02:08.239] INFO: 17 hot pixels found in step 5
[10:02:09.232] INFO: Collecting data for 5 seconds...
[10:02:14.248] INFO: Done with hot pixel readout
[10:02:26.563] INFO: PixTest:: pg_setup set to default.
[10:02:26.564] INFO: 29 hot pixels found in step 6
[10:02:27.556] INFO: Collecting data for 5 seconds...
[10:02:32.572] INFO: Done with hot pixel readout
[10:02:44.933] INFO: PixTest:: pg_setup set to default.
[10:02:44.934] INFO: 21 hot pixels found in step 7
[10:02:45.926] INFO: Collecting data for 5 seconds...
[10:02:50.942] INFO: Done with hot pixel readout
[10:03:03.281] INFO: PixTest:: pg_setup set to default.
[10:03:03.282] INFO: 18 hot pixels found in step 8
[10:03:04.274] INFO: Collecting data for 5 seconds...
[10:03:09.290] INFO: Done with hot pixel readout
[10:03:21.616] INFO: PixTest:: pg_setup set to default.


[10:03:21.616] INFO: 23 hot pixels found in step 9
[10:03:22.609] INFO: Collecting data for 5 seconds...
[10:03:27.624] INFO: Done with hot pixel readout
[10:03:39.926] INFO: PixTest:: pg_setup set to default.



[10:03:39.927] INFO: 26 hot pixels found in step 10
[10:03:40.920] INFO: Collecting data for 5 seconds...
[10:03:45.936] INFO: Done with hot pixel readout
[10:03:58.279] INFO: PixTest:: pg_setup set to default.



[10:03:58.279] INFO: 22 hot pixels found in step 11
[10:03:59.273] INFO: Collecting data for 5 seconds...
[10:04:04.289] INFO: Done with hot pixel readout
[10:04:16.625] INFO: PixTest:: pg_setup set to default.

[10:04:16.626] INFO: 21 hot pixels found in step 12
[10:04:17.619] INFO: Collecting data for 5 seconds...
[10:04:22.635] INFO: Done with hot pixel readout
[10:04:34.960] INFO: PixTest:: pg_setup set to default.
[10:04:34.961] INFO: 25 hot pixels found in step 13
[10:04:35.953] INFO: Collecting data for 5 seconds...
[10:04:40.970] INFO: Done with hot pixel readout
[10:04:53.258] INFO: PixTest:: pg_setup set to default.


[10:04:53.259] INFO: 18 hot pixels found in step 14
[10:04:53.295] INFO: 18 hot pixels could not be trimmed and have been masked.
[10:04:53.299] INFO: PixTest::trimHotPixels() done
[10:04:53.301] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C0.dat
[10:04:53.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C1.dat
[10:04:53.312] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C2.dat
[10:04:53.317] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C3.dat
[10:04:53.323] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C4.dat
[10:04:53.328] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C5.dat
[10:04:53.333] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C6.dat
[10:04:53.338] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C7.dat
[10:04:53.344] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C8.dat
[10:04:53.349] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C9.dat
[10:04:53.354] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C10.dat
[10:04:53.359] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C11.dat
[10:04:53.365] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C12.dat
[10:04:53.370] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C13.dat
[10:04:53.375] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C14.dat
[10:04:53.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C15.dat
[10:04:53.385] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//defaultMaskFile.dat
[10:04:53.395] INFO: enter test to run
[10:05:18.495] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:05:18.496] INFO: running: highrate
[10:05:18.500] INFO: ----------------------------------------------------------------------
[10:05:18.500] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:05:18.500] INFO: ----------------------------------------------------------------------
[10:05:18.500] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:05:18.500] INFO: edge/corner pixel THR is adjusted
[10:05:18.500] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:05:19.458] INFO: Collecting data for 1 seconds...
[10:05:20.462] INFO: Done with hot pixel readout
[10:05:24.698] INFO: PixTest:: pg_setup set to default.
[10:05:24.698] INFO: 0 hot pixels found in step 0
[10:05:24.704] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:05:24.783] INFO: PixTest::trimHotPixels() done
[10:05:24.783] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C0.dat
[10:05:24.795] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C1.dat
[10:05:24.801] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C2.dat
[10:05:24.807] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C3.dat
[10:05:24.812] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C4.dat
[10:05:24.817] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C5.dat
[10:05:24.823] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C6.dat
[10:05:24.828] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C7.dat
[10:05:24.833] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C8.dat
[10:05:24.838] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C9.dat
[10:05:24.844] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C10.dat
[10:05:24.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C11.dat
[10:05:24.854] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C12.dat
[10:05:24.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C13.dat
[10:05:24.865] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C14.dat
[10:05:24.870] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//trimParameters35_C15.dat
[10:05:24.875] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-39_FPIXTest-17C-FNAL-160418-0837_2016-04-18_08h37m_1460986635/000_FPIXTest_p17//defaultMaskFile.dat
[10:05:24.885] INFO: enter test to run
[10:05:42.695] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:05:42.695] INFO: running: xray
[10:05:42.711] INFO: ----------------------------------------------------------------------
[10:05:42.711] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:05:42.711] INFO: ----------------------------------------------------------------------
[10:05:43.674] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:05:54.708] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[10:06:24.452] INFO: Resuming triggers.
[10:06:35.488] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[10:07:02.558] INFO: Resuming triggers.
[10:07:13.595] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:07:42.690] INFO: Resuming triggers.
[10:07:53.723] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:08:23.229] INFO: Resuming triggers.
[10:08:34.264] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[10:09:03.777] INFO: Resuming triggers.
[10:09:14.813] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:09:44.325] INFO: Resuming triggers.
[10:09:55.364] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[10:10:24.828] INFO: Resuming triggers.
[10:10:35.864] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:11:05.320] INFO: Resuming triggers.
[10:11:16.359] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[10:11:45.873] INFO: Resuming triggers.
[10:11:46.873] INFO: data taking finished, elapsed time: 100 seconds.
[10:11:49.941] INFO: PixTest:: pg_setup set to default.
[10:11:49.944] INFO: PixTestXray::doPhRun() done
[10:11:50.084] INFO: enter test to run
[10:12:10.908] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:12:10.908] INFO: running: xray
[10:12:10.909] INFO: ----------------------------------------------------------------------
[10:12:10.910] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:12:10.910] INFO: ----------------------------------------------------------------------
[10:12:11.891] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:12:18.065] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:12:48.041] INFO: Resuming triggers.
[10:12:54.213] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[10:13:24.264] INFO: Resuming triggers.
[10:13:30.433] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[10:14:00.443] INFO: Resuming triggers.
[10:14:06.613] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[10:14:36.674] INFO: Resuming triggers.
[10:14:42.842] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[10:15:12.874] INFO: Resuming triggers.
[10:15:19.045] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[10:15:49.046] INFO: Resuming triggers.
[10:15:55.217] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[10:16:25.239] INFO: Resuming triggers.
[10:16:31.412] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[10:17:01.613] INFO: Resuming triggers.
[10:17:07.787] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[10:17:36.234] INFO: Resuming triggers.
[10:17:42.402] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[10:18:12.449] INFO: Resuming triggers.
[10:18:18.617] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[10:18:48.671] INFO: Resuming triggers.
[10:18:54.843] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[10:19:24.917] INFO: Resuming triggers.
[10:19:31.092] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[10:20:01.092] INFO: Resuming triggers.
[10:20:07.263] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[10:20:37.256] INFO: Resuming triggers.
[10:20:43.432] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:21:13.639] INFO: Resuming triggers.
[10:21:19.814] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[10:21:49.820] INFO: Resuming triggers.
[10:21:51.388] INFO: data taking finished, elapsed time: 100 seconds.
[10:21:59.367] INFO: PixTest:: pg_setup set to default.
[10:21:59.371] INFO: PixTestXray::doPhRun() done
[10:21:59.523] INFO: enter test to run
[10:22:40.000] INFO: test: HighRate no parameter change
[10:22:40.000] INFO: running: highrate
[10:22:40.001] INFO: ----------------------------------------------------------------------
[10:22:40.001] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:22:40.001] INFO: ----------------------------------------------------------------------
[10:22:41.158] INFO: Expecting 768 events.
[10:22:42.298] INFO: 768 events read in total (418ms).
[10:22:42.298] INFO: Test took 1275ms.
[10:22:43.101] INFO: Expecting 41600 events.
[10:22:46.253] INFO: 41600 events read in total (2625ms).
[10:22:46.254] INFO: Test took 3910ms.
[10:22:46.292] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:47.010] INFO: Expecting 41600 events.
[10:22:50.249] INFO: 41600 events read in total (2712ms).
[10:22:50.250] INFO: Test took 3938ms.
[10:22:50.289] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:50.002] INFO: Expecting 41600 events.
[10:22:54.274] INFO: 41600 events read in total (2745ms).
[10:22:54.275] INFO: Test took 3967ms.
[10:22:54.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:55.028] INFO: Expecting 41600 events.
[10:22:58.302] INFO: 41600 events read in total (2747ms).
[10:22:58.303] INFO: Test took 3968ms.
[10:22:58.342] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:59.053] INFO: Expecting 41600 events.
[10:23:02.119] INFO: 41600 events read in total (2539ms).
[10:23:02.120] INFO: Test took 3758ms.
[10:23:02.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:02.869] INFO: Expecting 41600 events.
[10:23:05.975] INFO: 41600 events read in total (2579ms).
[10:23:05.976] INFO: Test took 3795ms.
[10:23:06.016] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:06.732] INFO: Expecting 41600 events.
[10:23:10.026] INFO: 41600 events read in total (2767ms).
[10:23:10.027] INFO: Test took 3992ms.
[10:23:10.066] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:10.777] INFO: Expecting 41600 events.
[10:23:14.083] INFO: 41600 events read in total (2779ms).
[10:23:14.084] INFO: Test took 3999ms.
[10:23:14.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:14.836] INFO: Expecting 41600 events.
[10:23:18.130] INFO: 41600 events read in total (2768ms).
[10:23:18.131] INFO: Test took 3986ms.
[10:23:18.170] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:18.886] INFO: Expecting 41600 events.
[10:23:22.161] INFO: 41600 events read in total (2748ms).
[10:23:22.162] INFO: Test took 3972ms.
[10:23:22.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:22.913] INFO: Expecting 41600 events.
[10:23:26.192] INFO: 41600 events read in total (2752ms).
[10:23:26.193] INFO: Test took 3970ms.
[10:23:26.233] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:26.944] INFO: Expecting 41600 events.
[10:23:30.262] INFO: 41600 events read in total (2791ms).
[10:23:30.263] INFO: Test took 4011ms.
[10:23:30.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:31.015] INFO: Expecting 41600 events.
[10:23:34.326] INFO: 41600 events read in total (2784ms).
[10:23:34.327] INFO: Test took 4003ms.
[10:23:34.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:35.075] INFO: Expecting 41600 events.
[10:23:38.370] INFO: 41600 events read in total (2768ms).
[10:23:38.371] INFO: Test took 3984ms.
[10:23:38.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:39.122] INFO: Expecting 41600 events.
[10:23:42.412] INFO: 41600 events read in total (2763ms).
[10:23:42.413] INFO: Test took 3982ms.
[10:23:42.453] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:43.161] INFO: Expecting 41600 events.
[10:23:46.476] INFO: 41600 events read in total (2788ms).
[10:23:46.477] INFO: Test took 4005ms.
[10:23:46.517] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:47.231] INFO: Expecting 41600 events.
[10:23:50.374] INFO: 41600 events read in total (2616ms).
[10:23:50.375] INFO: Test took 3836ms.
[10:23:50.415] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:51.129] INFO: Expecting 41600 events.
[10:23:54.382] INFO: 41600 events read in total (2726ms).
[10:23:54.384] INFO: Test took 3948ms.
[10:23:54.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:55.135] INFO: Expecting 41600 events.
[10:23:58.401] INFO: 41600 events read in total (2739ms).
[10:23:58.402] INFO: Test took 3954ms.
[10:23:58.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:59.158] INFO: Expecting 41600 events.
[10:24:02.272] INFO: 41600 events read in total (2588ms).
[10:24:02.273] INFO: Test took 3810ms.
[10:24:02.311] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:02.667] INFO: enter test to run
[10:24:25.895] INFO: test: HighRate no parameter change
[10:24:25.895] INFO: running: highrate
[10:24:25.896] INFO: ----------------------------------------------------------------------
[10:24:25.896] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:24:25.896] INFO: ----------------------------------------------------------------------
[10:24:26.509] INFO: Expecting 208000 events.
[10:24:38.622] INFO: 208000 events read in total (11586ms).
[10:24:38.626] INFO: Test took 12720ms.
[10:24:38.795] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:39.055] INFO: number of dead pixels (per ROC): 0 0 2 3 0 0 0 0 1 3 0 0 0 0 0 0
[10:24:39.055] INFO: number of red-efficiency pixels: 103 71 100 174 183 163 173 128 111 149 160 133 126 64 28 43
[10:24:39.055] INFO: number of X-ray hits detected: 75551 51565 80239 131090 132250 137821 136854 99874 98221 119013 115623 100488 100167 58149 27175 29218
[10:24:39.055] 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:24:39.055] INFO: number of Vcal hits detected: 207895 207929 207802 207676 207811 207831 207821 207869 207838 207702 207837 207865 207870 207936 207971 207956
[10:24:39.055] 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:24:39.055] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 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:24:39.055] INFO: X-ray hit rate [MHz/cm2]: 22.1 15.1 23.5 38.4 38.8 40.4 40.1 29.3 28.8 34.9 33.9 29.5 29.4 17.0 8.0 8.6
[10:24:39.055] INFO: PixTestHighRate::doXPixelAlive() done
[10:24:39.104] INFO: PixTest:: pg_setup set to default.
[10:24:39.117] INFO: enter test to run
[10:24:57.279] INFO: test: HighRate no parameter change
[10:24:57.279] INFO: running: highrate
[10:24:57.280] INFO: ----------------------------------------------------------------------
[10:24:57.280] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:24:57.280] INFO: ----------------------------------------------------------------------
[10:24:57.900] INFO: Expecting 208000 events.
[10:25:12.063] INFO: 208000 events read in total (13636ms).
[10:25:12.069] INFO: Test took 14779ms.
[10:25:12.409] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:25:12.723] INFO: number of dead pixels (per ROC): 0 0 2 3 0 0 0 0 1 3 0 0 0 0 0 0
[10:25:12.723] INFO: number of red-efficiency pixels: 232 163 305 524 525 596 583 346 287 427 493 432 279 173 68 77
[10:25:12.723] INFO: number of X-ray hits detected: 149397 101583 159420 260453 262171 273488 270437 198716 193803 236036 228189 199245 199433 116082 53835 57797
[10:25:12.723] 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:25:12.723] INFO: number of Vcal hits detected: 207756 207826 207569 207282 207401 207332 207360 207625 207647 207392 207469 207536 207701 207822 207929 207920
[10:25:12.723] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[10:25:12.723] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.8 99.7 99.7 99.8 99.9 99.9 100.0 100.0
[10:25:12.723] INFO: X-ray hit rate [MHz/cm2]: 43.8 29.8 46.7 76.3 76.8 80.2 79.3 58.2 56.8 69.2 66.9 58.4 58.5 34.0 15.8 16.9
[10:25:12.723] INFO: PixTestHighRate::doXPixelAlive() done
[10:25:12.775] INFO: PixTest:: pg_setup set to default.
[10:25:12.789] INFO: enter test to run
[10:25:36.855] INFO: test: HighRate no parameter change
[10:25:36.855] INFO: running: highrate
[10:25:36.856] INFO: ----------------------------------------------------------------------
[10:25:36.856] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:25:36.856] INFO: ----------------------------------------------------------------------
[10:25:37.474] INFO: Expecting 208000 events.
[10:25:53.835] INFO: 208000 events read in total (15835ms).
[10:25:53.844] INFO: Test took 16980ms.
[10:25:54.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:25:54.729] INFO: number of dead pixels (per ROC): 0 0 2 3 0 0 0 0 1 3 0 0 0 0 0 0
[10:25:54.729] INFO: number of red-efficiency pixels: 466 369 649 1175 1137 1333 1305 757 656 971 1141 991 715 379 138 110
[10:25:54.729] INFO: number of X-ray hits detected: 222907 152381 239457 389628 391539 408335 406387 297269 291001 354733 342613 296709 297332 172372 80858 87172
[10:25:54.729] 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:25:54.729] INFO: number of Vcal hits detected: 207459 207585 207019 206388 206530 206202 206336 207043 207197 206668 206587 206792 207185 207571 207855 207890
[10:25:54.729] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.6 99.4 99.4 99.2 99.3 99.6 99.7 99.5 99.4 99.5 99.6 99.8 99.9 99.9
[10:25:54.729] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.2 99.3 99.1 99.2 99.5 99.6 99.4 99.3 99.4 99.6 99.8 99.9 99.9
[10:25:54.729] INFO: X-ray hit rate [MHz/cm2]: 65.3 44.7 70.2 114.2 114.8 119.7 119.1 87.1 85.3 104.0 100.4 87.0 87.2 50.5 23.7 25.6
[10:25:54.729] INFO: PixTestHighRate::doXPixelAlive() done
[10:25:54.774] INFO: PixTest:: pg_setup set to default.
[10:25:54.796] INFO: enter test to run
[10:26:00.430] INFO: test: exit no parameter change
[10:26:00.781] QUIET: Connection to board 32 closed.
[10:26:00.791] INFO: pXar: this is the end, my friend