[12:22:55.973] INFO: *** Welcome to pxar ***
[12:22:55.973] INFO: *** Today: 2016/05/10
[12:22:56.015] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:22:56.015] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//dacParameters35_C15.dat
[12:22:56.016] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:22:56.016] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//defaultMaskFile.dat
[12:22:56.016] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C15.dat
[12:22:56.088] INFO: clk: 4
[12:22:56.088] INFO: ctr: 4
[12:22:56.088] INFO: sda: 19
[12:22:56.088] INFO: tin: 9
[12:22:56.088] INFO: level: 15
[12:22:56.088] INFO: triggerdelay: 0
[12:22:56.088] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:22:56.088] INFO: Log level: INFO
[12:22:56.103] QUIET: Connection to board DTB_WREKRL opened.
[12:22:56.106] 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:
------------------------------------------------------
[12:22:56.109] INFO: RPC call hashes of host and DTB match: 398089610
[12:22:57.643] INFO: DUT info:
[12:22:57.643] INFO: The DUT currently contains the following objects:
[12:22:57.643] INFO: 2 TBM Cores tbm08c (2 ON)
[12:22:57.643] INFO: TBM Core alpha (0): 7 registers set
[12:22:57.643] INFO: TBM Core beta (1): 7 registers set
[12:22:57.644] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:22:57.644] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:57.644] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:22:58.047] INFO: enter 'restricted' command line mode
[12:22:58.047] INFO: enter test to run
[12:23:50.214] INFO: test: PixelAlive no parameter change
[12:23:50.214] INFO: running: pixelalive
[12:23:50.250] INFO: ----------------------------------------------------------------------
[12:23:50.250] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:23:50.251] INFO: ----------------------------------------------------------------------
[12:23:50.574] INFO: Expecting 41600 events.
[12:23:54.794] INFO: 41600 events read in total (3502ms).
[12:23:54.961] INFO: Test took 4708ms.
[12:23:54.974] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:55.280] INFO: PixTestAlive::aliveTest() done
[12:23:55.280] INFO: number of dead pixels (per ROC): 2 0 3 0 0 1 0 0 0 1 0 1 0 0 0 0
[12:23:55.334] INFO: enter test to run
[12:24:20.230] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:24:20.230] INFO: running: highrate
[12:24:20.230] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:24:20.398] INFO: ----------------------------------------------------------------------
[12:24:20.398] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:24:20.398] INFO: ----------------------------------------------------------------------
[12:24:20.398] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:24:20.398] INFO: edge/corner pixel THR is adjusted
[12:24:20.398] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:24:21.356] INFO: Collecting data for 5 seconds...
[12:24:26.373] INFO: Done with hot pixel readout
[12:24:37.688] INFO: PixTest:: pg_setup set to default.
[12:24:37.689] INFO: 2 hot pixels found in step 0
[12:24:38.679] INFO: Collecting data for 5 seconds...
[12:24:43.695] INFO: Done with hot pixel readout
[12:24:54.893] INFO: PixTest:: pg_setup set to default.
[12:24:54.894] INFO: 1 hot pixels found in step 1
[12:24:55.887] INFO: Collecting data for 5 seconds...
[12:25:00.903] INFO: Done with hot pixel readout
[12:25:12.148] INFO: PixTest:: pg_setup set to default.
[12:25:12.149] INFO: 1 hot pixels found in step 2
[12:25:13.138] INFO: Collecting data for 5 seconds...
[12:25:18.155] INFO: Done with hot pixel readout
[12:25:29.460] INFO: PixTest:: pg_setup set to default.
[12:25:29.460] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:25:29.461] INFO: 2 hot pixels found in step 3
[12:25:30.450] INFO: Collecting data for 5 seconds...
[12:25:35.467] INFO: Done with hot pixel readout
[12:25:46.790] INFO: PixTest:: pg_setup set to default.
[12:25:46.791] INFO: 1 hot pixels found in step 4
[12:25:47.779] INFO: Collecting data for 5 seconds...
[12:25:52.795] INFO: Done with hot pixel readout
[12:26:04.059] INFO: PixTest:: pg_setup set to default.
[12:26:04.060] INFO: 1 hot pixels found in step 5
[12:26:05.049] INFO: Collecting data for 5 seconds...
[12:26:10.064] INFO: Done with hot pixel readout
[12:26:21.350] INFO: PixTest:: pg_setup set to default.
[12:26:21.351] INFO: 0 hot pixels found in step 6
[12:26:21.384] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:26:21.415] INFO: PixTest::trimHotPixels() done
[12:26:21.416] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C0.dat
[12:26:21.423] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C1.dat
[12:26:21.430] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C2.dat
[12:26:21.437] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C3.dat
[12:26:21.444] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C4.dat
[12:26:21.451] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C5.dat
[12:26:21.458] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C6.dat
[12:26:21.465] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C7.dat
[12:26:21.472] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C8.dat
[12:26:21.479] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C9.dat
[12:26:21.486] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C10.dat
[12:26:21.493] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C11.dat
[12:26:21.500] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C12.dat
[12:26:21.507] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C13.dat
[12:26:21.515] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C14.dat
[12:26:21.522] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C15.dat
[12:26:21.529] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//defaultMaskFile.dat
[12:26:21.538] INFO: enter test to run
[12:27:01.445] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:27:01.445] INFO: running: highrate
[12:27:01.449] INFO: ----------------------------------------------------------------------
[12:27:01.449] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:27:01.449] INFO: ----------------------------------------------------------------------
[12:27:01.449] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:27:01.449] INFO: edge/corner pixel THR is adjusted
[12:27:01.449] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:27:02.406] INFO: Collecting data for 1 seconds...
[12:27:03.411] INFO: Done with hot pixel readout
[12:27:07.182] INFO: PixTest:: pg_setup set to default.
[12:27:07.182] INFO: 0 hot pixels found in step 0
[12:27:07.188] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:27:07.288] INFO: PixTest::trimHotPixels() done
[12:27:07.288] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C0.dat
[12:27:07.300] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C1.dat
[12:27:07.308] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C2.dat
[12:27:07.314] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C3.dat
[12:27:07.322] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C4.dat
[12:27:07.329] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C5.dat
[12:27:07.336] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C6.dat
[12:27:07.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C7.dat
[12:27:07.349] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C8.dat
[12:27:07.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C9.dat
[12:27:07.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C10.dat
[12:27:07.370] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C11.dat
[12:27:07.377] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C12.dat
[12:27:07.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C13.dat
[12:27:07.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C14.dat
[12:27:07.398] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C15.dat
[12:27:07.405] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-40_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//defaultMaskFile.dat
[12:27:07.415] INFO: enter test to run
[12:27:43.668] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:27:43.668] INFO: running: xray
[12:27:43.670] INFO: ----------------------------------------------------------------------
[12:27:43.670] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:27:43.670] INFO: ----------------------------------------------------------------------
[12:27:44.633] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:27:56.609] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:28:25.762] INFO: Resuming triggers.
[12:28:37.740] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:29:06.881] INFO: Resuming triggers.
[12:29:18.857] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:29:47.858] INFO: Resuming triggers.
[12:29:59.836] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:30:28.836] INFO: Resuming triggers.
[12:30:40.813] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:31:10.338] INFO: Resuming triggers.
[12:31:22.316] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[12:31:51.478] INFO: Resuming triggers.
[12:32:03.457] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[12:32:32.773] INFO: Resuming triggers.
[12:32:44.753] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:33:14.224] INFO: Resuming triggers.
[12:33:18.751] INFO: data taking finished, elapsed time: 100 seconds.
[12:33:30.208] INFO: PixTest:: pg_setup set to default.
[12:33:30.212] INFO: PixTestXray::doPhRun() done
[12:33:30.362] INFO: enter test to run
[12:34:21.618] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:34:21.618] INFO: running: xray
[12:34:21.619] INFO: ----------------------------------------------------------------------
[12:34:21.619] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:34:21.619] INFO: ----------------------------------------------------------------------
[12:34:22.583] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:34:29.799] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[12:34:59.123] INFO: Resuming triggers.
[12:35:06.341] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[12:35:35.004] INFO: Resuming triggers.
[12:35:43.222] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:36:13.278] INFO: Resuming triggers.
[12:36:20.498] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[12:36:50.535] INFO: Resuming triggers.
[12:36:57.758] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[12:37:27.778] INFO: Resuming triggers.
[12:37:34.996] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:38:04.917] INFO: Resuming triggers.
[12:38:12.138] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[12:38:42.181] INFO: Resuming triggers.
[12:38:49.396] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:39:19.400] INFO: Resuming triggers.
[12:39:26.616] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[12:39:56.537] INFO: Resuming triggers.
[12:40:03.753] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[12:40:33.717] INFO: Resuming triggers.
[12:40:40.933] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:41:10.877] INFO: Resuming triggers.
[12:41:18.098] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[12:41:48.154] INFO: Resuming triggers.
[12:41:55.369] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:42:26.054] INFO: Resuming triggers.
[12:42:32.551] INFO: data taking finished, elapsed time: 100 seconds.
[12:43:00.107] INFO: PixTest:: pg_setup set to default.
[12:43:00.110] INFO: PixTestXray::doPhRun() done
[12:43:00.260] INFO: enter test to run
[12:43:34.733] INFO: test: HighRate no parameter change
[12:43:34.734] INFO: running: highrate
[12:43:34.735] INFO: ----------------------------------------------------------------------
[12:43:34.735] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:43:34.735] INFO: ----------------------------------------------------------------------
[12:43:34.875] INFO: Expecting 768 events.
[12:43:36.009] INFO: 768 events read in total (419ms).
[12:43:36.009] INFO: Test took 1268ms.
[12:43:36.812] INFO: Expecting 41600 events.
[12:43:39.883] INFO: 41600 events read in total (2544ms).
[12:43:39.885] INFO: Test took 3870ms.
[12:43:39.918] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:40.648] INFO: Expecting 41600 events.
[12:43:43.829] INFO: 41600 events read in total (2654ms).
[12:43:43.829] INFO: Test took 3894ms.
[12:43:43.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:44.587] INFO: Expecting 41600 events.
[12:43:47.705] INFO: 41600 events read in total (2592ms).
[12:43:47.706] INFO: Test took 3830ms.
[12:43:47.737] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:48.460] INFO: Expecting 41600 events.
[12:43:51.653] INFO: 41600 events read in total (2666ms).
[12:43:51.654] INFO: Test took 3901ms.
[12:43:51.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:52.409] INFO: Expecting 41600 events.
[12:43:55.642] INFO: 41600 events read in total (2706ms).
[12:43:55.644] INFO: Test took 3943ms.
[12:43:55.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:56.404] INFO: Expecting 41600 events.
[12:43:59.505] INFO: 41600 events read in total (2574ms).
[12:43:59.506] INFO: Test took 3814ms.
[12:43:59.537] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:00.266] INFO: Expecting 41600 events.
[12:44:03.555] INFO: 41600 events read in total (2762ms).
[12:44:03.555] INFO: Test took 4001ms.
[12:44:03.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:04.307] INFO: Expecting 41600 events.
[12:44:07.460] INFO: 41600 events read in total (2626ms).
[12:44:07.461] INFO: Test took 3859ms.
[12:44:07.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:08.219] INFO: Expecting 41600 events.
[12:44:11.420] INFO: 41600 events read in total (2674ms).
[12:44:11.421] INFO: Test took 3912ms.
[12:44:11.452] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:12.181] INFO: Expecting 41600 events.
[12:44:15.422] INFO: 41600 events read in total (2714ms).
[12:44:15.423] INFO: Test took 3955ms.
[12:44:15.454] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:16.185] INFO: Expecting 41600 events.
[12:44:19.366] INFO: 41600 events read in total (2654ms).
[12:44:19.366] INFO: Test took 3896ms.
[12:44:19.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:20.127] INFO: Expecting 41600 events.
[12:44:23.446] INFO: 41600 events read in total (2792ms).
[12:44:23.447] INFO: Test took 4033ms.
[12:44:23.478] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:24.208] INFO: Expecting 41600 events.
[12:44:27.436] INFO: 41600 events read in total (2701ms).
[12:44:27.437] INFO: Test took 3943ms.
[12:44:27.468] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:28.192] INFO: Expecting 41600 events.
[12:44:31.412] INFO: 41600 events read in total (2693ms).
[12:44:31.413] INFO: Test took 3928ms.
[12:44:31.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:32.172] INFO: Expecting 41600 events.
[12:44:35.396] INFO: 41600 events read in total (2697ms).
[12:44:35.397] INFO: Test took 3937ms.
[12:44:35.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:36.155] INFO: Expecting 41600 events.
[12:44:39.339] INFO: 41600 events read in total (2657ms).
[12:44:39.340] INFO: Test took 3893ms.
[12:44:39.376] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:40.091] INFO: Expecting 41600 events.
[12:44:43.379] INFO: 41600 events read in total (2761ms).
[12:44:43.380] INFO: Test took 3988ms.
[12:44:43.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:44.141] INFO: Expecting 41600 events.
[12:44:47.384] INFO: 41600 events read in total (2716ms).
[12:44:47.385] INFO: Test took 3946ms.
[12:44:47.416] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:48.146] INFO: Expecting 41600 events.
[12:44:51.319] INFO: 41600 events read in total (2646ms).
[12:44:51.320] INFO: Test took 3888ms.
[12:44:51.351] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:52.078] INFO: Expecting 41600 events.
[12:44:55.191] INFO: 41600 events read in total (2587ms).
[12:44:55.192] INFO: Test took 3825ms.
[12:44:55.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:55.593] INFO: enter test to run
[12:45:05.325] INFO: test: HighRate no parameter change
[12:45:05.325] INFO: running: highrate
[12:45:05.326] INFO: ----------------------------------------------------------------------
[12:45:05.326] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:45:05.326] INFO: ----------------------------------------------------------------------
[12:45:05.945] INFO: Expecting 208000 events.
[12:45:17.529] INFO: 208000 events read in total (11057ms).
[12:45:17.531] INFO: Test took 12199ms.
[12:45:17.657] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:17.901] INFO: number of dead pixels (per ROC): 2 0 3 0 0 1 0 0 0 1 0 1 0 0 0 0
[12:45:17.901] INFO: number of red-efficiency pixels: 56 37 70 103 114 122 114 83 80 90 102 84 78 45 28 19
[12:45:17.901] INFO: number of X-ray hits detected: 56012 37995 56999 94288 96318 100579 99597 67416 61852 81793 80004 73469 75895 40950 17516 19831
[12:45:17.901] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:45:17.901] INFO: number of Vcal hits detected: 207846 207963 207783 207895 207885 207826 207884 207916 207919 207859 207897 207866 207921 207954 207972 207981
[12:45:17.901] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[12:45:17.901] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 99.9 100.0 100.0 100.0 100.0
[12:45:17.901] INFO: X-ray hit rate [MHz/cm2]: 16.4 11.1 16.7 27.6 28.2 29.5 29.2 19.8 18.1 24.0 23.4 21.5 22.2 12.0 5.1 5.8
[12:45:17.901] INFO: PixTestHighRate::doXPixelAlive() done
[12:45:17.949] INFO: PixTest:: pg_setup set to default.
[12:45:17.959] INFO: enter test to run
[12:45:53.724] INFO: test: HighRate no parameter change
[12:45:53.724] INFO: running: highrate
[12:45:53.725] INFO: ----------------------------------------------------------------------
[12:45:53.725] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:45:53.725] INFO: ----------------------------------------------------------------------
[12:45:54.341] INFO: Expecting 208000 events.
[12:46:07.450] INFO: 208000 events read in total (12582ms).
[12:46:07.454] INFO: Test took 13721ms.
[12:46:07.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:07.003] INFO: number of dead pixels (per ROC): 2 0 3 0 0 1 0 0 0 1 0 1 0 0 0 0
[12:46:07.003] INFO: number of red-efficiency pixels: 177 104 229 326 340 432 333 279 242 351 303 213 216 118 47 56
[12:46:07.003] INFO: number of X-ray hits detected: 120609 80500 120700 200471 206169 212601 211791 144292 131364 174486 170215 157508 162414 87341 37814 42878
[12:46:07.003] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:46:07.003] INFO: number of Vcal hits detected: 207716 207893 207612 207656 207644 207482 207647 207704 207749 207577 207682 207731 207775 207878 207950 207944
[12:46:07.003] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[12:46:07.003] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[12:46:07.003] INFO: X-ray hit rate [MHz/cm2]: 35.4 23.6 35.4 58.8 60.4 62.3 62.1 42.3 38.5 51.1 49.9 46.2 47.6 25.6 11.1 12.6
[12:46:07.003] INFO: PixTestHighRate::doXPixelAlive() done
[12:46:08.050] INFO: PixTest:: pg_setup set to default.
[12:46:08.067] INFO: enter test to run
[12:46:37.556] INFO: test: HighRate no parameter change
[12:46:37.556] INFO: running: highrate
[12:46:37.557] INFO: ----------------------------------------------------------------------
[12:46:37.557] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:46:37.557] INFO: ----------------------------------------------------------------------
[12:46:38.176] INFO: Expecting 208000 events.
[12:46:52.897] INFO: 208000 events read in total (14194ms).
[12:46:52.903] INFO: Test took 15337ms.
[12:46:53.283] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:53.614] INFO: number of dead pixels (per ROC): 2 0 3 0 0 1 0 0 0 1 0 1 0 0 0 0
[12:46:53.614] INFO: number of red-efficiency pixels: 321 227 507 833 848 1040 784 583 437 702 721 520 450 286 58 80
[12:46:53.614] INFO: number of X-ray hits detected: 182681 122331 183169 303564 311711 322984 321424 219139 198449 264746 257957 238984 246247 132434 57399 65996
[12:46:53.615] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:46:53.615] INFO: number of Vcal hits detected: 207545 207760 207243 207026 206994 206660 207094 207332 207529 207164 207184 207380 207511 207689 207940 207918
[12:46:53.615] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.6 99.4 99.6 99.7 99.8 99.7 99.6 99.8 99.8 99.9 100.0 100.0
[12:46:53.615] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.5 99.5 99.4 99.6 99.7 99.8 99.6 99.6 99.7 99.8 99.9 100.0 100.0
[12:46:53.615] INFO: X-ray hit rate [MHz/cm2]: 53.5 35.9 53.7 89.0 91.4 94.7 94.2 64.2 58.2 77.6 75.6 70.0 72.2 38.8 16.8 19.3
[12:46:53.615] INFO: PixTestHighRate::doXPixelAlive() done
[12:46:53.661] INFO: PixTest:: pg_setup set to default.
[12:46:53.679] INFO: enter test to run
[12:47:14.900] INFO: test: exit no parameter change
[12:47:15.218] QUIET: Connection to board 33 closed.
[12:47:15.220] INFO: pXar: this is the end, my friend