[11:01:07.074] INFO: *** Welcome to pxar ***
[11:01:07.074] INFO: *** Today: 2016/06/16
[11:01:07.090] INFO: *** Version: v1.9.0-814-g7497
[11:01:07.090] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//dacParameters35_C15.dat
[11:01:07.110] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:01:07.110] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//defaultMaskFile.dat
[11:01:07.111] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C15.dat
[11:01:07.231] INFO: clk: 4
[11:01:07.231] INFO: ctr: 4
[11:01:07.231] INFO: sda: 19
[11:01:07.231] INFO: tin: 9
[11:01:07.231] INFO: level: 15
[11:01:07.231] INFO: triggerdelay: 0
[11:01:07.231] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:01:07.231] INFO: Log level: INFO
[11:01:07.249] QUIET: Connection to board DTB_WREKRL opened.
[11:01:07.252] 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:
------------------------------------------------------
[11:01:07.255] INFO: RPC call hashes of host and DTB match: 398089610
[11:01:08.788] INFO: DUT info:
[11:01:08.788] INFO: The DUT currently contains the following objects:
[11:01:08.788] INFO: 2 TBM Cores tbm08c (2 ON)
[11:01:08.788] INFO: TBM Core alpha (0): 7 registers set
[11:01:08.788] INFO: TBM Core beta (1): 7 registers set
[11:01:08.788] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:01:08.788] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.788] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.789] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.789] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.789] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:08.789] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:09.192] INFO: enter 'restricted' command line mode
[11:01:09.192] INFO: enter test to run
[11:01:19.986] INFO: test: PixelAlive no parameter change
[11:01:19.987] INFO: running: pixelalive
[11:01:19.996] INFO: ----------------------------------------------------------------------
[11:01:19.996] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:01:19.996] INFO: ----------------------------------------------------------------------
[11:01:20.311] INFO: Expecting 41600 events.
[11:01:24.651] INFO: 41600 events read in total (3622ms).
[11:01:24.819] INFO: Test took 4821ms.
[11:01:24.830] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:25.091] INFO: PixTestAlive::aliveTest() done
[11:01:25.091] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:01:25.123] INFO: enter test to run
[11:01:55.482] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:01:55.482] INFO: running: highrate
[11:01:55.483] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:01:55.718] INFO: ----------------------------------------------------------------------
[11:01:55.718] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:01:55.718] INFO: ----------------------------------------------------------------------
[11:01:55.718] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:01:55.718] INFO: edge/corner pixel THR is adjusted
[11:01:55.718] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:01:56.679] INFO: Collecting data for 5 seconds...
[11:02:01.696] INFO: Done with hot pixel readout
[11:02:13.333] INFO: PixTest:: pg_setup set to default.
[11:02:13.334] INFO: 12 hot pixels found in step 0
[11:02:14.327] INFO: Collecting data for 5 seconds...
[11:02:19.344] INFO: Done with hot pixel readout
[11:02:30.882] INFO: PixTest:: pg_setup set to default.
[11:02:30.883] INFO: 13 hot pixels found in step 1
[11:02:31.872] INFO: Collecting data for 5 seconds...
[11:02:36.889] INFO: Done with hot pixel readout
[11:02:48.456] INFO: PixTest:: pg_setup set to default.
[11:02:48.457] INFO: 12 hot pixels found in step 2
[11:02:49.447] INFO: Collecting data for 5 seconds...
[11:02:54.463] INFO: Done with hot pixel readout
[11:03:06.011] INFO: PixTest:: pg_setup set to default.
[11:03:06.012] INFO: 9 hot pixels found in step 3
[11:03:06.001] INFO: Collecting data for 5 seconds...
[11:03:12.018] INFO: Done with hot pixel readout
[11:03:23.604] INFO: PixTest:: pg_setup set to default.
[11:03:23.605] INFO: 12 hot pixels found in step 4
[11:03:24.596] INFO: Collecting data for 5 seconds...
[11:03:29.612] INFO: Done with hot pixel readout
[11:03:41.193] INFO: PixTest:: pg_setup set to default.
[11:03:41.194] INFO: 11 hot pixels found in step 5
[11:03:42.184] INFO: Collecting data for 5 seconds...
[11:03:47.200] INFO: Done with hot pixel readout
[11:03:58.761] INFO: PixTest:: pg_setup set to default.
[11:03:58.762] INFO: 10 hot pixels found in step 6
[11:03:59.753] INFO: Collecting data for 5 seconds...
[11:04:04.769] INFO: Done with hot pixel readout
[11:04:16.361] INFO: PixTest:: pg_setup set to default.

[11:04:16.362] INFO: 8 hot pixels found in step 7
[11:04:17.351] INFO: Collecting data for 5 seconds...
[11:04:22.368] INFO: Done with hot pixel readout
[11:04:33.911] INFO: PixTest:: pg_setup set to default.
[11:04:33.912] INFO: 4 hot pixels found in step 8
[11:04:34.902] INFO: Collecting data for 5 seconds...
[11:04:39.918] INFO: Done with hot pixel readout
[11:04:51.393] INFO: PixTest:: pg_setup set to default.

[11:04:51.394] INFO: 4 hot pixels found in step 9
[11:04:52.383] INFO: Collecting data for 5 seconds...
[11:04:57.400] INFO: Done with hot pixel readout
[11:05:09.009] INFO: PixTest:: pg_setup set to default.

[11:05:09.010] INFO: 5 hot pixels found in step 10
[11:05:09.000] INFO: Collecting data for 5 seconds...
[11:05:15.017] INFO: Done with hot pixel readout
[11:05:26.589] INFO: PixTest:: pg_setup set to default.
[11:05:26.590] INFO: 3 hot pixels found in step 11
[11:05:27.580] INFO: Collecting data for 5 seconds...
[11:05:32.597] INFO: Done with hot pixel readout
[11:05:44.169] INFO: PixTest:: pg_setup set to default.
[11:05:44.170] INFO: 2 hot pixels found in step 12
[11:05:45.160] INFO: Collecting data for 5 seconds...
[11:05:50.176] INFO: Done with hot pixel readout
[11:06:01.760] INFO: PixTest:: pg_setup set to default.

[11:06:01.761] INFO: 3 hot pixels found in step 13
[11:06:02.750] INFO: Collecting data for 5 seconds...
[11:06:07.767] INFO: Done with hot pixel readout
[11:06:19.329] INFO: PixTest:: pg_setup set to default.

[11:06:19.330] INFO: 3 hot pixels found in step 14
[11:06:19.364] INFO: 3 hot pixels could not be trimmed and have been masked.
[11:06:19.368] INFO: PixTest::trimHotPixels() done
[11:06:19.368] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C0.dat
[11:06:19.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C1.dat
[11:06:19.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C2.dat
[11:06:19.386] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C3.dat
[11:06:19.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C4.dat
[11:06:19.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C5.dat
[11:06:19.401] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C6.dat
[11:06:19.407] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C7.dat
[11:06:19.412] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C8.dat
[11:06:19.417] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C9.dat
[11:06:19.422] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C10.dat
[11:06:19.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C11.dat
[11:06:19.433] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C12.dat
[11:06:19.438] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C13.dat
[11:06:19.443] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C14.dat
[11:06:19.448] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C15.dat
[11:06:19.453] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//defaultMaskFile.dat
[11:06:19.463] INFO: enter test to run
[11:06:59.784] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:06:59.784] INFO: running: highrate
[11:06:59.789] INFO: ----------------------------------------------------------------------
[11:06:59.789] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:06:59.789] INFO: ----------------------------------------------------------------------
[11:06:59.789] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:06:59.790] INFO: edge/corner pixel THR is adjusted
[11:06:59.790] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:07:00.747] INFO: Collecting data for 1 seconds...
[11:07:01.751] INFO: Done with hot pixel readout
[11:07:05.702] INFO: PixTest:: pg_setup set to default.
[11:07:05.703] INFO: 0 hot pixels found in step 0
[11:07:05.709] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:07:05.804] INFO: PixTest::trimHotPixels() done
[11:07:05.804] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C0.dat
[11:07:05.812] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C1.dat
[11:07:05.818] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C2.dat
[11:07:05.823] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C3.dat
[11:07:05.829] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C4.dat
[11:07:05.834] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C5.dat
[11:07:05.839] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C6.dat
[11:07:05.844] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C7.dat
[11:07:05.850] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C8.dat
[11:07:05.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C9.dat
[11:07:05.861] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C10.dat
[11:07:05.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C11.dat
[11:07:05.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C12.dat
[11:07:05.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C13.dat
[11:07:05.882] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C14.dat
[11:07:05.887] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C15.dat
[11:07:05.892] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-08_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//defaultMaskFile.dat
[11:07:05.902] INFO: enter test to run
[11:07:34.720] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:07:34.720] INFO: running: xray
[11:07:34.721] INFO: ----------------------------------------------------------------------
[11:07:34.721] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:07:34.721] INFO: ----------------------------------------------------------------------
[11:07:35.686] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:07:47.399] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:08:16.618] INFO: Resuming triggers.
[11:08:28.329] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[11:08:57.368] INFO: Resuming triggers.
[11:09:09.083] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[11:09:38.346] INFO: Resuming triggers.
[11:09:50.060] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[11:10:19.260] INFO: Resuming triggers.
[11:10:30.973] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[11:11:00.223] INFO: Resuming triggers.
[11:11:11.933] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[11:11:41.161] INFO: Resuming triggers.
[11:11:52.872] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:12:22.203] INFO: Resuming triggers.
[11:12:33.913] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[11:13:03.224] INFO: Resuming triggers.
[11:13:09.855] INFO: data taking finished, elapsed time: 100 seconds.
[11:13:26.744] INFO: PixTest:: pg_setup set to default.
[11:13:26.747] INFO: PixTestXray::doPhRun() done
[11:13:26.881] INFO: enter test to run
[11:14:04.685] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:14:04.685] INFO: running: xray
[11:14:04.686] INFO: ----------------------------------------------------------------------
[11:14:04.687] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:14:04.687] INFO: ----------------------------------------------------------------------
[11:14:05.653] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:14:12.507] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:14:42.472] INFO: Resuming triggers.
[11:14:49.325] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:15:19.333] INFO: Resuming triggers.
[11:15:26.191] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[11:15:56.100] INFO: Resuming triggers.
[11:16:02.961] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[11:16:32.880] INFO: Resuming triggers.
[11:16:39.735] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:17:09.644] INFO: Resuming triggers.
[11:17:16.500] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[11:17:46.345] INFO: Resuming triggers.
[11:17:53.202] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[11:18:23.019] INFO: Resuming triggers.
[11:18:29.875] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[11:18:59.798] INFO: Resuming triggers.
[11:19:06.653] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[11:19:36.566] INFO: Resuming triggers.
[11:19:43.421] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:20:13.400] INFO: Resuming triggers.
[11:20:20.255] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[11:20:50.191] INFO: Resuming triggers.
[11:20:57.045] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:21:27.245] INFO: Resuming triggers.
[11:21:34.105] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[11:22:04.056] INFO: Resuming triggers.
[11:22:10.911] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[11:22:40.773] INFO: Resuming triggers.
[11:22:45.122] INFO: data taking finished, elapsed time: 100 seconds.
[11:23:04.387] INFO: PixTest:: pg_setup set to default.
[11:23:04.391] INFO: PixTestXray::doPhRun() done
[11:23:04.538] INFO: enter test to run
[11:23:30.826] INFO: test: HighRate no parameter change
[11:23:30.826] INFO: running: highrate
[11:23:30.827] INFO: ----------------------------------------------------------------------
[11:23:30.827] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:23:30.827] INFO: ----------------------------------------------------------------------
[11:23:30.967] INFO: Expecting 768 events.
[11:23:32.101] INFO: 768 events read in total (418ms).
[11:23:32.101] INFO: Test took 1268ms.
[11:23:32.904] INFO: Expecting 41600 events.
[11:23:35.973] INFO: 41600 events read in total (2542ms).
[11:23:35.974] INFO: Test took 3865ms.
[11:23:36.006] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:36.739] INFO: Expecting 41600 events.
[11:23:39.888] INFO: 41600 events read in total (2622ms).
[11:23:39.889] INFO: Test took 3867ms.
[11:23:39.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:40.650] INFO: Expecting 41600 events.
[11:23:43.858] INFO: 41600 events read in total (2681ms).
[11:23:43.859] INFO: Test took 3919ms.
[11:23:43.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:44.620] INFO: Expecting 41600 events.
[11:23:47.840] INFO: 41600 events read in total (2694ms).
[11:23:47.841] INFO: Test took 3930ms.
[11:23:47.874] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:48.598] INFO: Expecting 41600 events.
[11:23:51.825] INFO: 41600 events read in total (2700ms).
[11:23:51.826] INFO: Test took 3934ms.
[11:23:51.859] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:52.582] INFO: Expecting 41600 events.
[11:23:55.814] INFO: 41600 events read in total (2705ms).
[11:23:55.814] INFO: Test took 3937ms.
[11:23:55.847] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:56.574] INFO: Expecting 41600 events.
[11:23:59.796] INFO: 41600 events read in total (2696ms).
[11:23:59.797] INFO: Test took 3932ms.
[11:23:59.829] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:00.558] INFO: Expecting 41600 events.
[11:24:03.780] INFO: 41600 events read in total (2695ms).
[11:24:03.781] INFO: Test took 3934ms.
[11:24:03.814] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:04.542] INFO: Expecting 41600 events.
[11:24:07.775] INFO: 41600 events read in total (2706ms).
[11:24:07.776] INFO: Test took 3944ms.
[11:24:07.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:08.537] INFO: Expecting 41600 events.
[11:24:11.758] INFO: 41600 events read in total (2695ms).
[11:24:11.759] INFO: Test took 3932ms.
[11:24:11.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:12.515] INFO: Expecting 41600 events.
[11:24:15.732] INFO: 41600 events read in total (2690ms).
[11:24:15.733] INFO: Test took 3923ms.
[11:24:15.766] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:16.493] INFO: Expecting 41600 events.
[11:24:19.724] INFO: 41600 events read in total (2704ms).
[11:24:19.725] INFO: Test took 3940ms.
[11:24:19.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:20.483] INFO: Expecting 41600 events.
[11:24:23.709] INFO: 41600 events read in total (2699ms).
[11:24:23.710] INFO: Test took 3934ms.
[11:24:23.743] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:24.467] INFO: Expecting 41600 events.
[11:24:27.694] INFO: 41600 events read in total (2700ms).
[11:24:27.695] INFO: Test took 3935ms.
[11:24:27.727] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:28.455] INFO: Expecting 41600 events.
[11:24:31.681] INFO: 41600 events read in total (2699ms).
[11:24:31.682] INFO: Test took 3938ms.
[11:24:31.715] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:32.444] INFO: Expecting 41600 events.
[11:24:35.672] INFO: 41600 events read in total (2702ms).
[11:24:35.673] INFO: Test took 3940ms.
[11:24:35.706] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:36.430] INFO: Expecting 41600 events.
[11:24:39.647] INFO: 41600 events read in total (2690ms).
[11:24:39.648] INFO: Test took 3925ms.
[11:24:39.680] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:40.408] INFO: Expecting 41600 events.
[11:24:43.641] INFO: 41600 events read in total (2706ms).
[11:24:43.641] INFO: Test took 3942ms.
[11:24:43.674] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:44.399] INFO: Expecting 41600 events.
[11:24:47.600] INFO: 41600 events read in total (2674ms).
[11:24:47.601] INFO: Test took 3910ms.
[11:24:47.634] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:48.358] INFO: Expecting 41600 events.
[11:24:51.414] INFO: 41600 events read in total (2529ms).
[11:24:51.415] INFO: Test took 3765ms.
[11:24:51.446] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:51.814] INFO: enter test to run
[11:24:56.409] INFO: test: HighRate no parameter change
[11:24:56.409] INFO: running: highrate
[11:24:56.410] INFO: ----------------------------------------------------------------------
[11:24:56.410] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:24:56.410] INFO: ----------------------------------------------------------------------
[11:24:57.022] INFO: Expecting 208000 events.
[11:25:08.919] INFO: 208000 events read in total (11371ms).
[11:25:08.922] INFO: Test took 12505ms.
[11:25:09.060] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:09.308] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:25:09.308] INFO: number of red-efficiency pixels: 91 55 83 144 169 191 135 99 67 105 108 61 91 54 26 21
[11:25:09.308] INFO: number of X-ray hits detected: 63904 41912 63738 105680 112624 116427 111387 84396 70608 88585 82490 71896 77434 45898 22454 26254
[11:25:09.309] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:25:09.309] INFO: number of Vcal hits detected: 207905 207944 207914 207850 207823 207798 207864 207899 207930 207894 207891 207938 207909 207945 207974 207979
[11:25:09.309] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[11:25:09.309] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[11:25:09.309] INFO: X-ray hit rate [MHz/cm2]: 18.7 12.3 18.7 31.0 33.0 34.1 32.6 24.7 20.7 26.0 24.2 21.1 22.7 13.5 6.6 7.7
[11:25:09.309] INFO: PixTestHighRate::doXPixelAlive() done
[11:25:09.354] INFO: PixTest:: pg_setup set to default.
[11:25:09.364] INFO: enter test to run
[11:25:35.921] INFO: test: HighRate no parameter change
[11:25:35.921] INFO: running: highrate
[11:25:35.922] INFO: ----------------------------------------------------------------------
[11:25:35.922] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:25:35.922] INFO: ----------------------------------------------------------------------
[11:25:36.537] INFO: Expecting 208000 events.
[11:25:50.091] INFO: 208000 events read in total (13027ms).
[11:25:50.096] INFO: Test took 14165ms.
[11:25:50.378] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:50.674] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:25:50.674] INFO: number of red-efficiency pixels: 192 114 259 460 550 603 367 281 242 338 316 236 214 144 54 64
[11:25:50.674] INFO: number of X-ray hits detected: 132275 86356 133639 219029 233237 242102 232601 176147 146870 184345 172407 148727 160536 95889 46653 54129
[11:25:50.674] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:25:50.674] INFO: number of Vcal hits detected: 207794 207883 207715 207499 207397 207323 207607 207699 207748 207646 207672 207755 207775 207845 207946 207935
[11:25:50.675] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[11:25:50.675] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[11:25:50.675] INFO: X-ray hit rate [MHz/cm2]: 38.8 25.3 39.2 64.2 68.4 71.0 68.2 51.6 43.0 54.0 50.5 43.6 47.1 28.1 13.7 15.9
[11:25:50.675] INFO: PixTestHighRate::doXPixelAlive() done
[11:25:50.724] INFO: PixTest:: pg_setup set to default.
[11:25:50.741] INFO: enter test to run
[11:26:12.928] INFO: test: HighRate no parameter change
[11:26:12.928] INFO: running: highrate
[11:26:12.930] INFO: ----------------------------------------------------------------------
[11:26:12.930] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:26:12.930] INFO: ----------------------------------------------------------------------
[11:26:13.541] INFO: Expecting 208000 events.
[11:26:28.927] INFO: 208000 events read in total (14859ms).
[11:26:28.935] INFO: Test took 15997ms.
[11:26:29.367] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:29.711] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:26:29.711] INFO: number of red-efficiency pixels: 373 217 648 1196 1364 1394 944 697 539 776 649 517 535 264 100 98
[11:26:29.711] INFO: number of X-ray hits detected: 201073 132344 202419 332555 354873 368152 352460 268720 223690 279399 262087 225942 246181 146412 71754 83437
[11:26:29.711] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:26:29.711] INFO: number of Vcal hits detected: 207577 207768 207126 206521 206244 206090 206848 207139 207404 207117 207265 207429 207413 207710 207896 207901
[11:26:29.711] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.4 99.2 99.2 99.5 99.6 99.7 99.6 99.7 99.8 99.7 99.9 100.0 100.0
[11:26:29.711] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.3 99.2 99.1 99.4 99.6 99.7 99.6 99.6 99.7 99.7 99.9 100.0 100.0
[11:26:29.711] INFO: X-ray hit rate [MHz/cm2]: 58.9 38.8 59.3 97.5 104.0 107.9 103.3 78.8 65.6 81.9 76.8 66.2 72.2 42.9 21.0 24.5
[11:26:29.711] INFO: PixTestHighRate::doXPixelAlive() done
[11:26:29.757] INFO: PixTest:: pg_setup set to default.
[11:26:29.769] INFO: enter test to run
[11:26:40.472] INFO: test: exit no parameter change
[11:26:40.816] QUIET: Connection to board 33 closed.
[11:26:40.818] INFO: pXar: this is the end, my friend