[17:29:45.939] INFO: *** Welcome to pxar ***
[17:29:45.939] INFO: *** Today: 2016/06/22
[17:29:45.958] INFO: *** Version: v1.9.0-814-g7497
[17:29:45.958] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//dacParameters35_C15.dat
[17:29:45.988] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:29:45.988] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//defaultMaskFile.dat
[17:29:45.988] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C15.dat
[17:29:46.071] INFO: clk: 4
[17:29:46.071] INFO: ctr: 4
[17:29:46.071] INFO: sda: 19
[17:29:46.071] INFO: tin: 9
[17:29:46.071] INFO: level: 15
[17:29:46.071] INFO: triggerdelay: 0
[17:29:46.071] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[17:29:46.071] INFO: Log level: INFO
[17:29:46.087] QUIET: Connection to board DTB_WREK4U opened.
[17:29:46.090] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[17:29:46.093] INFO: RPC call hashes of host and DTB match: 398089610
[17:29:47.625] INFO: DUT info:
[17:29:47.625] INFO: The DUT currently contains the following objects:
[17:29:47.625] INFO: 2 TBM Cores tbm08c (2 ON)
[17:29:47.625] INFO: TBM Core alpha (0): 7 registers set
[17:29:47.625] INFO: TBM Core beta (1): 7 registers set
[17:29:47.625] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[17:29:47.625] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:47.625] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:29:48.029] INFO: enter 'restricted' command line mode
[17:29:48.029] INFO: enter test to run
[17:29:59.036] INFO: test: PixelAlive no parameter change
[17:29:59.036] INFO: running: pixelalive
[17:29:59.049] INFO: ----------------------------------------------------------------------
[17:29:59.049] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:29:59.049] INFO: ----------------------------------------------------------------------
[17:29:59.386] INFO: Expecting 41600 events.
[17:30:03.718] INFO: 41600 events read in total (3614ms).
[17:30:03.875] INFO: Test took 4823ms.
[17:30:03.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:30:04.150] INFO: PixTestAlive::aliveTest() done
[17:30:04.150] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:30:04.184] INFO: enter test to run
[17:31:27.892] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[17:31:27.892] INFO: running: highrate
[17:31:27.892] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[17:31:28.098] INFO: ----------------------------------------------------------------------
[17:31:28.098] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[17:31:28.098] INFO: ----------------------------------------------------------------------
[17:31:28.098] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[17:31:28.098] INFO: edge/corner pixel THR is adjusted
[17:31:28.098] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:31:29.056] INFO: Collecting data for 5 seconds...
[17:31:34.074] INFO: Done with hot pixel readout
[17:31:46.062] INFO: PixTest:: pg_setup set to default.
[17:31:46.062] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:31:46.063] INFO: 2 hot pixels found in step 0
[17:31:47.052] INFO: Collecting data for 5 seconds...
[17:31:52.070] INFO: Done with hot pixel readout
[17:32:03.850] INFO: PixTest:: pg_setup set to default.
[17:32:03.850] INFO: 2 hot pixels found in step 1
[17:32:04.846] INFO: Collecting data for 5 seconds...
[17:32:09.866] INFO: Done with hot pixel readout
[17:32:21.938] INFO: PixTest:: pg_setup set to default.
[17:32:21.938] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:32:21.939] INFO: 5 hot pixels found in step 2
[17:32:22.931] INFO: Collecting data for 5 seconds...
[17:32:27.949] INFO: Done with hot pixel readout
[17:32:39.894] INFO: PixTest:: pg_setup set to default.
[17:32:39.895] INFO: 3 hot pixels found in step 3
[17:32:40.887] INFO: Collecting data for 5 seconds...
[17:32:45.907] INFO: Done with hot pixel readout
[17:32:57.917] INFO: PixTest:: pg_setup set to default.
[17:32:57.918] INFO: 1 hot pixels found in step 4
[17:32:58.910] INFO: Collecting data for 5 seconds...
[17:33:03.930] INFO: Done with hot pixel readout
[17:33:15.803] INFO: PixTest:: pg_setup set to default.
[17:33:15.804] INFO: 1 hot pixels found in step 5
[17:33:16.796] INFO: Collecting data for 5 seconds...
[17:33:21.811] INFO: Done with hot pixel readout
[17:33:33.646] INFO: PixTest:: pg_setup set to default.
[17:33:33.646] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[17:33:33.647] INFO: 3 hot pixels found in step 6
[17:33:34.640] INFO: Collecting data for 5 seconds...
[17:33:39.655] INFO: Done with hot pixel readout
[17:33:51.455] INFO: PixTest:: pg_setup set to default.
[17:33:51.455] INFO: 2 hot pixels found in step 7
[17:33:52.448] INFO: Collecting data for 5 seconds...
[17:33:57.463] INFO: Done with hot pixel readout
[17:34:09.249] INFO: PixTest:: pg_setup set to default.
[17:34:09.250] INFO: 0 hot pixels found in step 8
[17:34:09.286] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:34:09.289] INFO: PixTest::trimHotPixels() done
[17:34:09.290] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C0.dat
[17:34:09.296] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C1.dat
[17:34:09.302] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C2.dat
[17:34:09.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C3.dat
[17:34:09.312] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C4.dat
[17:34:09.318] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C5.dat
[17:34:09.323] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C6.dat
[17:34:09.328] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C7.dat
[17:34:09.333] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C8.dat
[17:34:09.339] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C9.dat
[17:34:09.344] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C10.dat
[17:34:09.349] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C11.dat
[17:34:09.354] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C12.dat
[17:34:09.359] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C13.dat
[17:34:09.365] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C14.dat
[17:34:09.370] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C15.dat
[17:34:09.375] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//defaultMaskFile.dat
[17:34:09.385] INFO: enter test to run
[17:34:31.291] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[17:34:31.291] INFO: running: highrate
[17:34:31.295] INFO: ----------------------------------------------------------------------
[17:34:31.295] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[17:34:31.295] INFO: ----------------------------------------------------------------------
[17:34:31.295] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[17:34:31.295] INFO: edge/corner pixel THR is adjusted
[17:34:31.295] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:34:32.253] INFO: Collecting data for 1 seconds...
[17:34:33.256] INFO: Done with hot pixel readout
[17:34:37.262] INFO: PixTest:: pg_setup set to default.
[17:34:37.263] INFO: 0 hot pixels found in step 0
[17:34:37.268] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:34:37.360] INFO: PixTest::trimHotPixels() done
[17:34:37.360] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C0.dat
[17:34:37.369] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C1.dat
[17:34:37.375] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C2.dat
[17:34:37.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C3.dat
[17:34:37.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C4.dat
[17:34:37.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C5.dat
[17:34:37.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C6.dat
[17:34:37.401] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C7.dat
[17:34:37.406] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C8.dat
[17:34:37.411] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C9.dat
[17:34:37.416] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C10.dat
[17:34:37.422] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C11.dat
[17:34:37.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C12.dat
[17:34:37.432] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C13.dat
[17:34:37.437] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C14.dat
[17:34:37.442] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C15.dat
[17:34:37.447] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-24_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//defaultMaskFile.dat
[17:34:37.457] INFO: enter test to run
[17:36:26.226] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[17:36:26.226] INFO: running: xray
[17:36:26.227] INFO: ----------------------------------------------------------------------
[17:36:26.227] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:36:26.227] INFO: ----------------------------------------------------------------------
[17:36:27.191] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:36:38.516] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[17:37:07.830] INFO: Resuming triggers.
[17:37:19.162] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[17:37:48.658] INFO: Resuming triggers.
[17:37:59.988] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[17:38:29.410] INFO: Resuming triggers.
[17:38:40.740] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[17:39:10.164] INFO: Resuming triggers.
[17:39:21.498] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[17:39:50.936] INFO: Resuming triggers.
[17:40:02.268] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[17:40:31.717] INFO: Resuming triggers.
[17:40:43.050] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[17:41:12.718] INFO: Resuming triggers.
[17:41:24.043] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[17:41:53.767] INFO: Resuming triggers.
[17:42:03.441] INFO: data taking finished, elapsed time: 100 seconds.
[17:42:28.790] INFO: PixTest:: pg_setup set to default.
[17:42:28.793] INFO: PixTestXray::doPhRun() done
[17:42:28.931] INFO: enter test to run
[17:43:57.447] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:43:57.447] INFO: running: xray
[17:43:57.448] INFO: ----------------------------------------------------------------------
[17:43:57.448] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:43:57.448] INFO: ----------------------------------------------------------------------
[17:43:58.426] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:44:05.110] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[17:44:36.726] INFO: Resuming triggers.
[17:44:43.406] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[17:45:13.419] INFO: Resuming triggers.
[17:45:20.105] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[17:45:50.153] INFO: Resuming triggers.
[17:45:56.840] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[17:46:26.909] INFO: Resuming triggers.
[17:46:33.591] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[17:47:03.581] INFO: Resuming triggers.
[17:47:10.260] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[17:47:40.292] INFO: Resuming triggers.
[17:47:46.975] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[17:48:17.035] INFO: Resuming triggers.
[17:48:23.722] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[17:48:53.715] INFO: Resuming triggers.
[17:49:00.404] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[17:49:30.441] INFO: Resuming triggers.
[17:49:37.125] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[17:50:07.255] INFO: Resuming triggers.
[17:50:13.939] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[17:50:44.004] INFO: Resuming triggers.
[17:50:50.688] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[17:51:20.716] INFO: Resuming triggers.
[17:51:27.397] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[17:51:57.523] INFO: Resuming triggers.
[17:52:04.207] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[17:52:34.267] INFO: Resuming triggers.
[17:52:40.948] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[17:53:11.932] INFO: Resuming triggers.
[17:53:11.001] INFO: data taking finished, elapsed time: 100 seconds.
[17:53:12.854] INFO: PixTest:: pg_setup set to default.
[17:53:12.857] INFO: PixTestXray::doPhRun() done
[17:53:13.020] INFO: enter test to run
[17:54:06.123] INFO: test: HighRate no parameter change
[17:54:06.123] INFO: running: highrate
[17:54:06.138] INFO: ----------------------------------------------------------------------
[17:54:06.138] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:54:06.138] INFO: ----------------------------------------------------------------------
[17:54:06.294] INFO: Expecting 768 events.
[17:54:07.437] INFO: 768 events read in total (420ms).
[17:54:07.437] INFO: Test took 1278ms.
[17:54:08.240] INFO: Expecting 41600 events.
[17:54:11.438] INFO: 41600 events read in total (2671ms).
[17:54:11.439] INFO: Test took 3995ms.
[17:54:11.475] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:12.185] INFO: Expecting 41600 events.
[17:54:15.405] INFO: 41600 events read in total (2693ms).
[17:54:15.406] INFO: Test took 3914ms.
[17:54:15.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:16.159] INFO: Expecting 41600 events.
[17:54:19.360] INFO: 41600 events read in total (2675ms).
[17:54:19.361] INFO: Test took 3902ms.
[17:54:19.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:20.112] INFO: Expecting 41600 events.
[17:54:23.424] INFO: 41600 events read in total (2786ms).
[17:54:23.425] INFO: Test took 4008ms.
[17:54:23.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:24.179] INFO: Expecting 41600 events.
[17:54:27.419] INFO: 41600 events read in total (2713ms).
[17:54:27.420] INFO: Test took 3940ms.
[17:54:27.457] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:28.174] INFO: Expecting 41600 events.
[17:54:31.478] INFO: 41600 events read in total (2777ms).
[17:54:31.479] INFO: Test took 4004ms.
[17:54:31.516] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:32.237] INFO: Expecting 41600 events.
[17:54:35.537] INFO: 41600 events read in total (2773ms).
[17:54:35.538] INFO: Test took 4003ms.
[17:54:35.574] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:36.296] INFO: Expecting 41600 events.
[17:54:39.623] INFO: 41600 events read in total (2800ms).
[17:54:39.624] INFO: Test took 4032ms.
[17:54:39.660] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:40.378] INFO: Expecting 41600 events.
[17:54:43.612] INFO: 41600 events read in total (2707ms).
[17:54:43.613] INFO: Test took 3935ms.
[17:54:43.649] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:44.371] INFO: Expecting 41600 events.
[17:54:47.676] INFO: 41600 events read in total (2778ms).
[17:54:47.677] INFO: Test took 4011ms.
[17:54:47.713] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:48.436] INFO: Expecting 41600 events.
[17:54:51.796] INFO: 41600 events read in total (2835ms).
[17:54:51.797] INFO: Test took 4067ms.
[17:54:51.833] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:52.548] INFO: Expecting 41600 events.
[17:54:55.825] INFO: 41600 events read in total (2750ms).
[17:54:55.826] INFO: Test took 3974ms.
[17:54:55.861] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:56.581] INFO: Expecting 41600 events.
[17:54:59.867] INFO: 41600 events read in total (2759ms).
[17:54:59.868] INFO: Test took 3987ms.
[17:54:59.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:00.621] INFO: Expecting 41600 events.
[17:55:03.853] INFO: 41600 events read in total (2705ms).
[17:55:03.854] INFO: Test took 3932ms.
[17:55:03.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:04.609] INFO: Expecting 41600 events.
[17:55:07.920] INFO: 41600 events read in total (2784ms).
[17:55:07.921] INFO: Test took 4014ms.
[17:55:07.959] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:08.672] INFO: Expecting 41600 events.
[17:55:12.003] INFO: 41600 events read in total (2804ms).
[17:55:12.004] INFO: Test took 4027ms.
[17:55:12.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:12.761] INFO: Expecting 41600 events.
[17:55:16.053] INFO: 41600 events read in total (2765ms).
[17:55:16.053] INFO: Test took 3995ms.
[17:55:16.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:16.803] INFO: Expecting 41600 events.
[17:55:20.150] INFO: 41600 events read in total (2820ms).
[17:55:20.151] INFO: Test took 4043ms.
[17:55:20.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:20.908] INFO: Expecting 41600 events.
[17:55:24.157] INFO: 41600 events read in total (2722ms).
[17:55:24.158] INFO: Test took 3954ms.
[17:55:24.193] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:24.915] INFO: Expecting 41600 events.
[17:55:28.016] INFO: 41600 events read in total (2574ms).
[17:55:28.017] INFO: Test took 3806ms.
[17:55:28.051] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:28.406] INFO: enter test to run
[17:55:40.802] INFO: test: HighRate no parameter change
[17:55:40.802] INFO: running: highrate
[17:55:40.803] INFO: ----------------------------------------------------------------------
[17:55:40.803] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:55:40.803] INFO: ----------------------------------------------------------------------
[17:55:41.425] INFO: Expecting 208000 events.
[17:55:53.845] INFO: 208000 events read in total (11894ms).
[17:55:53.849] INFO: Test took 13037ms.
[17:55:53.002] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:54.256] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 0 0 0 0 0 0 0
[17:55:54.256] INFO: number of red-efficiency pixels: 79 61 82 140 166 110 144 112 96 123 99 97 96 62 23 20
[17:55:54.257] INFO: number of X-ray hits detected: 62430 49075 69754 109838 117762 115627 119251 89019 82902 105274 95249 83324 85904 52673 19959 21855
[17:55:54.257] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:55:54.257] INFO: number of Vcal hits detected: 207920 207939 207869 207810 207830 207886 207848 207887 207903 207875 207901 207903 207902 207936 207976 207980
[17:55:54.257] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[17:55:54.257] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[17:55:54.257] INFO: X-ray hit rate [MHz/cm2]: 18.3 14.4 20.4 32.2 34.5 33.9 35.0 26.1 24.3 30.9 27.9 24.4 25.2 15.4 5.9 6.4
[17:55:54.257] INFO: PixTestHighRate::doXPixelAlive() done
[17:55:54.304] INFO: PixTest:: pg_setup set to default.
[17:55:54.318] INFO: enter test to run
[17:56:12.290] INFO: test: HighRate no parameter change
[17:56:12.290] INFO: running: highrate
[17:56:12.291] INFO: ----------------------------------------------------------------------
[17:56:12.291] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:56:12.291] INFO: ----------------------------------------------------------------------
[17:56:12.913] INFO: Expecting 208000 events.
[17:56:27.051] INFO: 208000 events read in total (13611ms).
[17:56:27.057] INFO: Test took 14757ms.
[17:56:27.369] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:56:27.677] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 0 0 0 0 0 0 0
[17:56:27.677] INFO: number of red-efficiency pixels: 207 128 258 405 595 379 585 298 305 358 271 295 281 197 56 61
[17:56:27.677] INFO: number of X-ray hits detected: 127801 99706 142701 224555 240165 235858 244484 182415 169232 214219 194508 169876 174898 108842 40959 45118
[17:56:27.677] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:56:27.677] INFO: number of Vcal hits detected: 207785 207863 207679 207520 207339 207598 207362 207681 207682 207612 207716 207688 207707 207797 207943 207939
[17:56:27.677] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[17:56:27.677] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.8 99.7 99.8 99.8 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[17:56:27.677] INFO: X-ray hit rate [MHz/cm2]: 37.5 29.2 41.8 65.8 70.4 69.1 71.7 53.5 49.6 62.8 57.0 49.8 51.3 31.9 12.0 13.2
[17:56:27.677] INFO: PixTestHighRate::doXPixelAlive() done
[17:56:27.724] INFO: PixTest:: pg_setup set to default.
[17:56:27.738] INFO: enter test to run
[17:56:44.810] INFO: test: HighRate no parameter change
[17:56:44.810] INFO: running: highrate
[17:56:44.811] INFO: ----------------------------------------------------------------------
[17:56:44.811] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:56:44.811] INFO: ----------------------------------------------------------------------
[17:56:45.427] INFO: Expecting 208000 events.
[17:57:00.915] INFO: 208000 events read in total (14961ms).
[17:57:00.923] INFO: Test took 16103ms.
[17:57:01.361] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:01.710] INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 0 0 0 0 0 0 0 0
[17:57:01.710] INFO: number of red-efficiency pixels: 463 254 545 864 1289 930 1374 629 672 785 611 655 596 376 93 73
[17:57:01.710] INFO: number of X-ray hits detected: 190714 148820 212220 334708 355437 352335 364599 271365 253392 321492 289960 254638 261663 160888 61419 68240
[17:57:01.710] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:57:01.710] INFO: number of Vcal hits detected: 207457 207720 207250 206940 206361 206863 206112 207234 207223 207099 207322 207249 207336 207568 207904 207925
[17:57:01.710] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.3 99.5 99.2 99.7 99.7 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[17:57:01.710] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.5 99.2 99.5 99.1 99.6 99.6 99.6 99.7 99.6 99.7 99.8 100.0 100.0
[17:57:01.710] INFO: X-ray hit rate [MHz/cm2]: 55.9 43.6 62.2 98.1 104.2 103.3 106.9 79.5 74.3 94.2 85.0 74.6 76.7 47.2 18.0 20.0
[17:57:01.710] INFO: PixTestHighRate::doXPixelAlive() done
[17:57:01.762] INFO: PixTest:: pg_setup set to default.
[17:57:01.780] INFO: enter test to run
[17:57:11.209] INFO: test: exit no parameter change
[17:57:11.523] QUIET: Connection to board 32 closed.
[17:57:11.524] INFO: pXar: this is the end, my friend