[16:13:15.239] INFO: *** Welcome to pxar ***
[16:13:15.239] INFO: *** Today: 2016/07/11
[16:13:15.258] INFO: *** Version: v1.9.0-814-g7497
[16:13:15.258] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//dacParameters35_C15.dat
[16:13:15.305] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:13:15.305] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//defaultMaskFile.dat
[16:13:15.307] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C15.dat
[16:13:15.390] INFO: clk: 4
[16:13:15.390] INFO: ctr: 4
[16:13:15.390] INFO: sda: 19
[16:13:15.390] INFO: tin: 9
[16:13:15.390] INFO: level: 15
[16:13:15.390] INFO: triggerdelay: 0
[16:13:15.390] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:13:15.390] INFO: Log level: INFO
[16:13:15.408] QUIET: Connection to board DTB_WREKRL opened.
[16:13:15.411] 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:
------------------------------------------------------
[16:13:15.413] INFO: RPC call hashes of host and DTB match: 398089610
[16:13:16.944] INFO: DUT info:
[16:13:16.944] INFO: The DUT currently contains the following objects:
[16:13:16.945] INFO: 2 TBM Cores tbm08c (2 ON)
[16:13:16.945] INFO: TBM Core alpha (0): 7 registers set
[16:13:16.945] INFO: TBM Core beta (1): 7 registers set
[16:13:16.945] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:13:16.945] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:16.945] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:13:17.349] INFO: enter 'restricted' command line mode
[16:13:17.349] INFO: enter test to run
[16:13:21.009] INFO: test: PixelAlive no parameter change
[16:13:21.009] INFO: running: pixelalive
[16:13:21.018] INFO: ----------------------------------------------------------------------
[16:13:21.018] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:13:21.019] INFO: ----------------------------------------------------------------------
[16:13:21.333] INFO: Expecting 41600 events.
[16:13:25.660] INFO: 41600 events read in total (3609ms).
[16:13:25.828] INFO: Test took 4807ms.
[16:13:25.840] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:13:26.105] INFO: PixTestAlive::aliveTest() done
[16:13:26.105] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[16:13:26.135] INFO: enter test to run
[16:13:45.361] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:13:45.361] INFO: running: highrate
[16:13:45.361] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:13:45.589] INFO: ----------------------------------------------------------------------
[16:13:45.589] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:13:45.589] INFO: ----------------------------------------------------------------------
[16:13:45.589] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:13:45.589] INFO: edge/corner pixel THR is adjusted
[16:13:45.589] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:13:46.549] INFO: Collecting data for 5 seconds...
[16:13:51.564] INFO: Done with hot pixel readout
[16:14:03.666] INFO: PixTest:: pg_setup set to default.
[16:14:03.667] INFO: 41 hot pixels found in step 0
[16:14:04.682] INFO: Collecting data for 5 seconds...
[16:14:09.698] INFO: Done with hot pixel readout
[16:14:21.552] INFO: PixTest:: pg_setup set to default.
[16:14:21.553] INFO: 37 hot pixels found in step 1
[16:14:22.556] INFO: Collecting data for 5 seconds...
[16:14:27.572] INFO: Done with hot pixel readout
[16:14:39.581] INFO: PixTest:: pg_setup set to default.

[16:14:39.582] INFO: 37 hot pixels found in step 2
[16:14:40.573] INFO: Collecting data for 5 seconds...
[16:14:45.589] INFO: Done with hot pixel readout
[16:14:57.643] INFO: PixTest:: pg_setup set to default.

[16:14:57.644] INFO: 32 hot pixels found in step 3
[16:14:58.634] INFO: Collecting data for 5 seconds...
[16:15:03.649] INFO: Done with hot pixel readout
[16:15:15.678] INFO: PixTest:: pg_setup set to default.

[16:15:15.679] INFO: 33 hot pixels found in step 4
[16:15:16.670] INFO: Collecting data for 5 seconds...
[16:15:21.685] INFO: Done with hot pixel readout
[16:15:33.748] INFO: PixTest:: pg_setup set to default.




[16:15:33.749] INFO: 35 hot pixels found in step 5
[16:15:34.741] INFO: Collecting data for 5 seconds...
[16:15:39.756] INFO: Done with hot pixel readout
[16:15:51.796] INFO: PixTest:: pg_setup set to default.





[16:15:51.797] INFO: 31 hot pixels found in step 6
[16:15:52.787] INFO: Collecting data for 5 seconds...
[16:15:57.803] INFO: Done with hot pixel readout
[16:16:09.858] INFO: PixTest:: pg_setup set to default.




[16:16:09.859] INFO: 17 hot pixels found in step 7
[16:16:10.851] INFO: Collecting data for 5 seconds...
[16:16:15.866] INFO: Done with hot pixel readout
[16:16:27.893] INFO: PixTest:: pg_setup set to default.







[16:16:27.894] INFO: 32 hot pixels found in step 8
[16:16:28.886] INFO: Collecting data for 5 seconds...
[16:16:33.901] INFO: Done with hot pixel readout
[16:16:45.998] INFO: PixTest:: pg_setup set to default.








[16:16:45.999] INFO: 22 hot pixels found in step 9
[16:16:46.991] INFO: Collecting data for 5 seconds...
[16:16:52.006] INFO: Done with hot pixel readout
[16:17:04.048] INFO: PixTest:: pg_setup set to default.







[16:17:04.049] INFO: 17 hot pixels found in step 10
[16:17:05.039] INFO: Collecting data for 5 seconds...
[16:17:10.055] INFO: Done with hot pixel readout
[16:17:22.123] INFO: PixTest:: pg_setup set to default.







[16:17:22.124] INFO: 21 hot pixels found in step 11
[16:17:23.115] INFO: Collecting data for 5 seconds...
[16:17:28.131] INFO: Done with hot pixel readout
[16:17:40.200] INFO: PixTest:: pg_setup set to default.








[16:17:40.201] INFO: 27 hot pixels found in step 12
[16:17:41.192] INFO: Collecting data for 5 seconds...
[16:17:46.207] INFO: Done with hot pixel readout
[16:17:58.277] INFO: PixTest:: pg_setup set to default.





[16:17:58.278] INFO: 25 hot pixels found in step 13
[16:17:59.269] INFO: Collecting data for 5 seconds...
[16:18:04.284] INFO: Done with hot pixel readout
[16:18:16.394] INFO: PixTest:: pg_setup set to default.





[16:18:16.395] INFO: 19 hot pixels found in step 14
[16:18:16.430] INFO: 19 hot pixels could not be trimmed and have been masked.
[16:18:16.434] INFO: PixTest::trimHotPixels() done
[16:18:16.441] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C0.dat
[16:18:16.447] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C1.dat
[16:18:16.452] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C2.dat
[16:18:16.458] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C3.dat
[16:18:16.463] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C4.dat
[16:18:16.468] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C5.dat
[16:18:16.473] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C6.dat
[16:18:16.478] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C7.dat
[16:18:16.483] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C8.dat
[16:18:16.488] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C9.dat
[16:18:16.494] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C10.dat
[16:18:16.499] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C11.dat
[16:18:16.504] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C12.dat
[16:18:16.509] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C13.dat
[16:18:16.515] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C14.dat
[16:18:16.520] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C15.dat
[16:18:16.525] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//defaultMaskFile.dat
[16:18:16.535] INFO: enter test to run
[16:18:54.215] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:18:54.215] INFO: running: highrate
[16:18:54.220] INFO: ----------------------------------------------------------------------
[16:18:54.220] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:18:54.220] INFO: ----------------------------------------------------------------------
[16:18:54.220] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:18:54.220] INFO: edge/corner pixel THR is adjusted
[16:18:54.220] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:18:55.177] INFO: Collecting data for 1 seconds...
[16:18:56.181] INFO: Done with hot pixel readout
[16:19:00.342] INFO: PixTest:: pg_setup set to default.
[16:19:00.343] INFO: 0 hot pixels found in step 0
[16:19:00.348] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:19:00.432] INFO: PixTest::trimHotPixels() done
[16:19:00.432] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C0.dat
[16:19:00.441] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C1.dat
[16:19:00.450] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C2.dat
[16:19:00.455] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C3.dat
[16:19:00.461] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C4.dat
[16:19:00.466] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C5.dat
[16:19:00.472] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C6.dat
[16:19:00.477] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C7.dat
[16:19:00.482] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C8.dat
[16:19:00.487] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C9.dat
[16:19:00.493] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C10.dat
[16:19:00.499] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C11.dat
[16:19:00.504] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C12.dat
[16:19:00.509] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C13.dat
[16:19:00.515] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C14.dat
[16:19:00.520] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C15.dat
[16:19:00.526] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-48_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//defaultMaskFile.dat
[16:19:00.537] INFO: enter test to run
[16:19:13.463] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:19:13.463] INFO: running: xray
[16:19:13.464] INFO: ----------------------------------------------------------------------
[16:19:13.464] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:19:13.464] INFO: ----------------------------------------------------------------------
[16:19:14.428] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:19:25.480] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:19:54.885] INFO: Resuming triggers.
[16:20:05.934] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:20:35.400] INFO: Resuming triggers.
[16:20:46.447] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:21:15.835] INFO: Resuming triggers.
[16:21:26.883] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:21:56.170] INFO: Resuming triggers.
[16:22:07.215] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[16:22:36.517] INFO: Resuming triggers.
[16:22:47.567] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[16:23:16.933] INFO: Resuming triggers.
[16:23:27.980] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[16:23:57.347] INFO: Resuming triggers.
[16:24:08.392] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[16:24:37.753] INFO: Resuming triggers.
[16:24:48.800] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[16:25:18.150] INFO: Resuming triggers.
[16:25:19.024] INFO: data taking finished, elapsed time: 100 seconds.
[16:25:21.723] INFO: PixTest:: pg_setup set to default.
[16:25:21.726] INFO: PixTestXray::doPhRun() done
[16:25:21.866] INFO: enter test to run
[16:25:37.884] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:25:37.884] INFO: running: xray
[16:25:37.885] INFO: ----------------------------------------------------------------------
[16:25:37.885] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:25:37.885] INFO: ----------------------------------------------------------------------
[16:25:38.865] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:25:45.224] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:26:15.443] INFO: Resuming triggers.
[16:26:21.800] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[16:26:51.973] INFO: Resuming triggers.
[16:26:58.336] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[16:27:28.487] INFO: Resuming triggers.
[16:27:34.843] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[16:28:04.926] INFO: Resuming triggers.
[16:28:11.286] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[16:28:41.390] INFO: Resuming triggers.
[16:28:47.747] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[16:29:17.904] INFO: Resuming triggers.
[16:29:24.262] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:29:54.340] INFO: Resuming triggers.
[16:30:00.699] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[16:30:30.804] INFO: Resuming triggers.
[16:30:37.167] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[16:31:07.327] INFO: Resuming triggers.
[16:31:13.685] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[16:31:43.857] INFO: Resuming triggers.
[16:31:50.216] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[16:32:20.287] INFO: Resuming triggers.
[16:32:26.646] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[16:32:56.703] INFO: Resuming triggers.
[16:33:03.059] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[16:33:33.219] INFO: Resuming triggers.
[16:33:39.578] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[16:34:09.691] INFO: Resuming triggers.
[16:34:16.046] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[16:34:46.179] INFO: Resuming triggers.
[16:34:51.108] INFO: data taking finished, elapsed time: 100 seconds.
[16:35:14.661] INFO: PixTest:: pg_setup set to default.
[16:35:14.665] INFO: PixTestXray::doPhRun() done
[16:35:14.815] INFO: enter test to run
[16:35:39.248] INFO: test: HighRate no parameter change
[16:35:39.248] INFO: running: highrate
[16:35:39.249] INFO: ----------------------------------------------------------------------
[16:35:39.249] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:35:39.249] INFO: ----------------------------------------------------------------------
[16:35:39.390] INFO: Expecting 768 events.
[16:35:40.524] INFO: 768 events read in total (419ms).
[16:35:40.524] INFO: Test took 1268ms.
[16:35:41.327] INFO: Expecting 41600 events.
[16:35:44.385] INFO: 41600 events read in total (2531ms).
[16:35:44.387] INFO: Test took 3856ms.
[16:35:44.421] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:45.148] INFO: Expecting 41600 events.
[16:35:48.334] INFO: 41600 events read in total (2659ms).
[16:35:48.335] INFO: Test took 3895ms.
[16:35:48.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:49.090] INFO: Expecting 41600 events.
[16:35:52.334] INFO: 41600 events read in total (2717ms).
[16:35:52.335] INFO: Test took 3945ms.
[16:35:52.371] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:53.088] INFO: Expecting 41600 events.
[16:35:56.345] INFO: 41600 events read in total (2730ms).
[16:35:56.346] INFO: Test took 3955ms.
[16:35:56.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:57.105] INFO: Expecting 41600 events.
[16:36:00.353] INFO: 41600 events read in total (2721ms).
[16:36:00.354] INFO: Test took 3952ms.
[16:36:00.391] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:01.113] INFO: Expecting 41600 events.
[16:36:04.373] INFO: 41600 events read in total (2733ms).
[16:36:04.374] INFO: Test took 3965ms.
[16:36:04.411] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:05.132] INFO: Expecting 41600 events.
[16:36:08.394] INFO: 41600 events read in total (2735ms).
[16:36:08.395] INFO: Test took 3965ms.
[16:36:08.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:09.152] INFO: Expecting 41600 events.
[16:36:12.398] INFO: 41600 events read in total (2719ms).
[16:36:12.399] INFO: Test took 3948ms.
[16:36:12.436] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:13.155] INFO: Expecting 41600 events.
[16:36:16.421] INFO: 41600 events read in total (2739ms).
[16:36:16.422] INFO: Test took 3967ms.
[16:36:16.459] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:17.179] INFO: Expecting 41600 events.
[16:36:20.450] INFO: 41600 events read in total (2744ms).
[16:36:20.451] INFO: Test took 3972ms.
[16:36:20.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:21.205] INFO: Expecting 41600 events.
[16:36:24.469] INFO: 41600 events read in total (2737ms).
[16:36:24.470] INFO: Test took 3965ms.
[16:36:24.507] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:25.224] INFO: Expecting 41600 events.
[16:36:28.479] INFO: 41600 events read in total (2728ms).
[16:36:28.480] INFO: Test took 3954ms.
[16:36:28.517] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:29.237] INFO: Expecting 41600 events.
[16:36:32.521] INFO: 41600 events read in total (2757ms).
[16:36:32.522] INFO: Test took 3987ms.
[16:36:32.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:33.276] INFO: Expecting 41600 events.
[16:36:36.543] INFO: 41600 events read in total (2740ms).
[16:36:36.544] INFO: Test took 3966ms.
[16:36:36.582] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:37.301] INFO: Expecting 41600 events.
[16:36:40.565] INFO: 41600 events read in total (2738ms).
[16:36:40.566] INFO: Test took 3965ms.
[16:36:40.603] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:41.323] INFO: Expecting 41600 events.
[16:36:44.583] INFO: 41600 events read in total (2733ms).
[16:36:44.584] INFO: Test took 3961ms.
[16:36:44.621] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:45.339] INFO: Expecting 41600 events.
[16:36:48.616] INFO: 41600 events read in total (2750ms).
[16:36:48.617] INFO: Test took 3977ms.
[16:36:48.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:49.374] INFO: Expecting 41600 events.
[16:36:52.645] INFO: 41600 events read in total (2744ms).
[16:36:52.646] INFO: Test took 3974ms.
[16:36:52.683] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:53.402] INFO: Expecting 41600 events.
[16:36:56.654] INFO: 41600 events read in total (2725ms).
[16:36:56.655] INFO: Test took 3953ms.
[16:36:56.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:57.411] INFO: Expecting 41600 events.
[16:37:00.539] INFO: 41600 events read in total (2602ms).
[16:37:00.540] INFO: Test took 3829ms.
[16:37:00.576] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:37:00.935] INFO: enter test to run
[16:37:12.455] INFO: test: HighRate no parameter change
[16:37:12.455] INFO: running: highrate
[16:37:12.457] INFO: ----------------------------------------------------------------------
[16:37:12.457] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:37:12.457] INFO: ----------------------------------------------------------------------
[16:37:13.073] INFO: Expecting 208000 events.
[16:37:25.092] INFO: 208000 events read in total (11491ms).
[16:37:25.095] INFO: Test took 12628ms.
[16:37:25.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:37:25.512] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[16:37:25.512] INFO: number of red-efficiency pixels: 98 41 80 108 114 194 138 111 113 155 172 141 106 88 29 24
[16:37:25.512] INFO: number of X-ray hits detected: 68740 42572 67069 106012 108575 122029 112610 85700 92091 120663 122463 97836 106098 64516 24640 29606
[16:37:25.512] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:37:25.512] INFO: number of Vcal hits detected: 207898 207959 207917 207889 207884 207804 207860 207889 207885 207830 207820 207855 207844 207911 207971 207976
[16:37:25.512] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[16:37:25.512] INFO: Vcal hit overall 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
[16:37:25.512] INFO: X-ray hit rate [MHz/cm2]: 20.1 12.5 19.7 31.1 31.8 35.8 33.0 25.1 27.0 35.4 35.9 28.7 31.1 18.9 7.2 8.7
[16:37:25.512] INFO: PixTestHighRate::doXPixelAlive() done
[16:37:25.559] INFO: PixTest:: pg_setup set to default.
[16:37:25.575] INFO: enter test to run
[16:37:40.447] INFO: test: HighRate no parameter change
[16:37:40.447] INFO: running: highrate
[16:37:40.448] INFO: ----------------------------------------------------------------------
[16:37:40.448] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:37:40.448] INFO: ----------------------------------------------------------------------
[16:37:41.069] INFO: Expecting 208000 events.
[16:37:55.029] INFO: 208000 events read in total (13433ms).
[16:37:55.035] INFO: Test took 14576ms.
[16:37:55.365] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:37:55.675] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[16:37:55.675] INFO: number of red-efficiency pixels: 268 116 273 371 381 625 538 361 383 455 663 430 379 294 60 80
[16:37:55.675] INFO: number of X-ray hits detected: 142483 87594 138862 220191 225419 252258 232939 176917 190668 250328 253389 202044 219285 134332 51589 61618
[16:37:55.675] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:37:55.675] INFO: number of Vcal hits detected: 207715 207881 207696 207595 207587 207299 207408 207599 207586 207498 207267 207534 207552 207666 207936 207919
[16:37:55.675] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.8 99.8 99.7 99.8 99.8 99.9 100.0 100.0
[16:37:55.675] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.8 99.8 99.6 99.8 99.8 99.8 100.0 100.0
[16:37:55.675] INFO: X-ray hit rate [MHz/cm2]: 41.8 25.7 40.7 64.5 66.1 73.9 68.3 51.9 55.9 73.4 74.3 59.2 64.3 39.4 15.1 18.1
[16:37:55.676] INFO: PixTestHighRate::doXPixelAlive() done
[16:37:55.725] INFO: PixTest:: pg_setup set to default.
[16:37:55.743] INFO: enter test to run
[16:38:10.871] INFO: test: HighRate no parameter change
[16:38:10.871] INFO: running: highrate
[16:38:10.872] INFO: ----------------------------------------------------------------------
[16:38:10.872] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:38:10.872] INFO: ----------------------------------------------------------------------
[16:38:11.490] INFO: Expecting 208000 events.
[16:38:27.608] INFO: 208000 events read in total (15592ms).
[16:38:27.616] INFO: Test took 16734ms.
[16:38:28.108] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:38:28.471] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[16:38:28.471] INFO: number of red-efficiency pixels: 542 222 652 805 973 1458 1313 834 855 1100 1483 907 855 699 123 121
[16:38:28.471] INFO: number of X-ray hits detected: 212969 132221 209398 330558 337913 378977 347747 266582 286940 374077 378787 303098 329917 201278 78435 92988
[16:38:28.471] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:38:28.471] INFO: number of Vcal hits detected: 207316 207748 207141 207031 206827 205991 206277 206933 206892 206545 205929 206825 206932 207059 207872 207878
[16:38:28.471] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.6 99.5 99.1 99.3 99.5 99.5 99.4 99.1 99.5 99.6 99.6 99.9 99.9
[16:38:28.471] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.5 99.4 99.0 99.2 99.5 99.5 99.3 99.0 99.4 99.5 99.5 99.9 99.9
[16:38:28.471] INFO: X-ray hit rate [MHz/cm2]: 62.4 38.8 61.4 96.9 99.0 111.1 101.9 78.1 84.1 109.6 111.0 88.8 96.7 59.0 23.0 27.3
[16:38:28.471] INFO: PixTestHighRate::doXPixelAlive() done
[16:38:28.523] INFO: PixTest:: pg_setup set to default.
[16:38:28.541] INFO: enter test to run
[16:38:41.151] INFO: test: exit no parameter change
[16:38:41.434] QUIET: Connection to board 33 closed.
[16:38:41.436] INFO: pXar: this is the end, my friend