[10:26:46.282] INFO: *** Welcome to pxar ***
[10:26:46.282] INFO: *** Today: 2016/07/28
[10:26:47.198] INFO: *** Version: v1.9.0-818-g96727
[10:26:47.198] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//dacParameters35_C15.dat
[10:26:47.333] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:26:47.333] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//defaultMaskFile.dat
[10:26:47.333] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C15.dat
[10:26:47.470] INFO: clk: 4
[10:26:47.470] INFO: ctr: 4
[10:26:47.470] INFO: sda: 19
[10:26:47.470] INFO: tin: 9
[10:26:47.470] INFO: level: 15
[10:26:47.470] INFO: triggerdelay: 0
[10:26:47.470] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[10:26:47.470] INFO: Log level: INFO
[10:26:47.491] QUIET: Connection to board DTB_WREKRL opened.
[10:26:47.494] 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:
------------------------------------------------------
[10:26:47.497] INFO: RPC call hashes of host and DTB match: 398089610
[10:26:49.044] INFO: DUT info:
[10:26:49.044] INFO: The DUT currently contains the following objects:
[10:26:49.044] INFO: 2 TBM Cores tbm08c (2 ON)
[10:26:49.058] INFO: TBM Core alpha (0): 7 registers set
[10:26:49.058] INFO: TBM Core beta (1): 7 registers set
[10:26:49.058] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:26:49.058] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.058] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.058] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.058] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.058] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.058] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.059] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.059] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.059] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.059] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.059] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.059] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.059] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.059] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.059] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.059] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:49.494] INFO: enter 'restricted' command line mode
[10:26:49.494] INFO: enter test to run
[10:27:00.548] INFO: test: PixelAlive no parameter change
[10:27:00.548] INFO: running: pixelalive
[10:27:00.605] INFO: ----------------------------------------------------------------------
[10:27:00.605] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:27:00.605] INFO: ----------------------------------------------------------------------
[10:27:00.926] INFO: Expecting 41600 events.
[10:27:05.293] INFO: 41600 events read in total (3649ms).
[10:27:05.457] INFO: Test took 4849ms.
[10:27:05.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:05.817] INFO: PixTestAlive::aliveTest() done
[10:27:05.817] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 1 0 0 0
[10:27:05.962] INFO: enter test to run
[10:34:56.177] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:34:56.177] INFO: running: highrate
[10:34:56.186] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:34:56.484] INFO: ----------------------------------------------------------------------
[10:34:56.484] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:34:56.484] INFO: ----------------------------------------------------------------------
[10:34:56.484] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:34:56.485] INFO: edge/corner pixel THR is adjusted
[10:34:56.485] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:34:57.446] INFO: Collecting data for 5 seconds...
[10:35:02.461] INFO: Done with hot pixel readout
[10:35:13.693] INFO: PixTest:: pg_setup set to default.
[10:35:13.694] INFO: 10 hot pixels found in step 0
[10:35:14.678] INFO: Collecting data for 5 seconds...
[10:35:19.694] INFO: Done with hot pixel readout
[10:35:30.911] INFO: PixTest:: pg_setup set to default.
[10:35:30.912] INFO: 7 hot pixels found in step 1
[10:35:31.903] INFO: Collecting data for 5 seconds...
[10:35:36.920] INFO: Done with hot pixel readout
[10:35:48.081] INFO: PixTest:: pg_setup set to default.
[10:35:48.082] INFO: 4 hot pixels found in step 2
[10:35:49.071] INFO: Collecting data for 5 seconds...
[10:35:54.087] INFO: Done with hot pixel readout
[10:36:04.666] INFO: PixTest:: pg_setup set to default.
[10:36:04.666] INFO: 1 hot pixels found in step 3
[10:36:05.655] INFO: Collecting data for 5 seconds...
[10:36:10.671] INFO: Done with hot pixel readout
[10:36:21.583] INFO: PixTest:: pg_setup set to default.
[10:36:21.584] INFO: 1 hot pixels found in step 4
[10:36:22.572] INFO: Collecting data for 5 seconds...
[10:36:27.590] INFO: Done with hot pixel readout
[10:36:38.718] INFO: PixTest:: pg_setup set to default.
[10:36:38.719] INFO: 2 hot pixels found in step 5
[10:36:39.716] INFO: Collecting data for 5 seconds...
[10:36:44.732] INFO: Done with hot pixel readout
[10:36:55.784] INFO: PixTest:: pg_setup set to default.
[10:36:55.785] INFO: 2 hot pixels found in step 6
[10:36:56.773] INFO: Collecting data for 5 seconds...
[10:37:01.789] INFO: Done with hot pixel readout
[10:37:12.477] INFO: PixTest:: pg_setup set to default.
[10:37:12.478] INFO: 0 hot pixels found in step 7
[10:37:12.516] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:37:12.534] INFO: PixTest::trimHotPixels() done
[10:37:12.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C0.dat
[10:37:12.540] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C1.dat
[10:37:12.545] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C2.dat
[10:37:12.551] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C3.dat
[10:37:12.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C4.dat
[10:37:12.561] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C5.dat
[10:37:12.567] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C6.dat
[10:37:12.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C7.dat
[10:37:12.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C8.dat
[10:37:12.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C9.dat
[10:37:12.588] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C10.dat
[10:37:12.593] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C11.dat
[10:37:12.600] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C12.dat
[10:37:12.605] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C13.dat
[10:37:12.610] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C14.dat
[10:37:12.615] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C15.dat
[10:37:12.620] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//defaultMaskFile.dat
[10:37:12.631] INFO: enter test to run
[10:41:26.238] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:41:26.238] INFO: running: highrate
[10:41:26.243] INFO: ----------------------------------------------------------------------
[10:41:26.243] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:41:26.243] INFO: ----------------------------------------------------------------------
[10:41:26.243] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:41:26.243] INFO: edge/corner pixel THR is adjusted
[10:41:26.243] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:41:27.200] INFO: Collecting data for 1 seconds...
[10:41:28.204] INFO: Done with hot pixel readout
[10:41:31.683] INFO: PixTest:: pg_setup set to default.
[10:41:31.683] INFO: 0 hot pixels found in step 0
[10:41:31.690] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:41:31.781] INFO: PixTest::trimHotPixels() done
[10:41:31.781] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C0.dat
[10:41:31.791] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C1.dat
[10:41:31.797] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C2.dat
[10:41:31.802] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C3.dat
[10:41:31.807] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C4.dat
[10:41:31.813] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C5.dat
[10:41:31.818] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C6.dat
[10:41:31.824] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C7.dat
[10:41:31.829] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C8.dat
[10:41:31.834] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C9.dat
[10:41:31.840] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C10.dat
[10:41:31.845] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C11.dat
[10:41:31.850] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C12.dat
[10:41:31.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C13.dat
[10:41:31.861] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C14.dat
[10:41:31.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//trimParameters35_C15.dat
[10:41:31.892] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-J-4-26_FPIXTest-17C-Nebraska-160519-1359_2016-05-19_13h59m_1463684391/000_FPIXTest_p17//defaultMaskFile.dat
[10:41:31.902] INFO: enter test to run
[10:42:12.094] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:42:12.094] INFO: running: xray
[10:42:12.095] INFO: ----------------------------------------------------------------------
[10:42:12.095] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:42:12.095] INFO: ----------------------------------------------------------------------
[10:42:13.082] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:42:25.131] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[10:42:53.375] INFO: Resuming triggers.
[10:43:05.428] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[10:43:34.265] INFO: Resuming triggers.
[10:43:46.316] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[10:44:15.238] INFO: Resuming triggers.
[10:44:27.290] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[10:44:56.164] INFO: Resuming triggers.
[10:45:08.215] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[10:45:36.583] INFO: Resuming triggers.
[10:45:48.638] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[10:46:17.315] INFO: Resuming triggers.
[10:46:29.367] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[10:46:58.223] INFO: Resuming triggers.
[10:47:10.279] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[10:47:38.584] INFO: Resuming triggers.
[10:47:42.498] INFO: data taking finished, elapsed time: 100 seconds.
[10:47:51.960] INFO: PixTest:: pg_setup set to default.
[10:47:51.963] INFO: PixTestXray::doPhRun() done
[10:47:52.136] INFO: enter test to run
[10:49:29.739] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:49:29.739] INFO: running: xray
[10:49:29.740] INFO: ----------------------------------------------------------------------
[10:49:29.740] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:49:29.740] INFO: ----------------------------------------------------------------------
[10:49:30.706] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:49:38.128] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[10:50:08.279] INFO: Resuming triggers.
[10:50:15.703] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[10:50:45.586] INFO: Resuming triggers.
[10:50:53.008] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[10:51:22.918] INFO: Resuming triggers.
[10:51:30.343] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[10:52:00.873] INFO: Resuming triggers.
[10:52:08.298] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[10:52:38.136] INFO: Resuming triggers.
[10:52:45.559] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:53:17.092] INFO: Resuming triggers.
[10:53:24.518] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[10:53:54.949] INFO: Resuming triggers.
[10:54:02.376] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[10:54:33.758] INFO: Resuming triggers.
[10:54:41.188] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:55:12.316] INFO: Resuming triggers.
[10:55:19.740] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[10:55:49.327] INFO: Resuming triggers.
[10:55:56.753] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:56:26.943] INFO: Resuming triggers.
[10:56:34.365] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:57:04.549] INFO: Resuming triggers.
[10:57:11.971] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[10:57:42.403] INFO: Resuming triggers.
[10:57:46.233] INFO: data taking finished, elapsed time: 100 seconds.
[10:58:01.965] INFO: PixTest:: pg_setup set to default.
[10:58:01.969] INFO: PixTestXray::doPhRun() done
[10:58:02.117] INFO: enter test to run
[10:59:00.943] INFO: test: HighRate no parameter change
[10:59:00.943] INFO: running: highrate
[10:59:00.956] INFO: ----------------------------------------------------------------------
[10:59:00.956] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:59:00.956] INFO: ----------------------------------------------------------------------
[10:59:01.111] INFO: Expecting 768 events.
[10:59:02.251] INFO: 768 events read in total (419ms).
[10:59:02.251] INFO: Test took 1274ms.
[10:59:03.054] INFO: Expecting 41600 events.
[10:59:06.120] INFO: 41600 events read in total (2539ms).
[10:59:06.121] INFO: Test took 3850ms.
[10:59:06.150] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:06.877] INFO: Expecting 41600 events.
[10:59:10.051] INFO: 41600 events read in total (2647ms).
[10:59:10.052] INFO: Test took 3886ms.
[10:59:10.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:10.811] INFO: Expecting 41600 events.
[10:59:13.992] INFO: 41600 events read in total (2654ms).
[10:59:13.993] INFO: Test took 3895ms.
[10:59:14.023] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:14.757] INFO: Expecting 41600 events.
[10:59:17.949] INFO: 41600 events read in total (2665ms).
[10:59:17.949] INFO: Test took 3910ms.
[10:59:17.980] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:18.710] INFO: Expecting 41600 events.
[10:59:21.908] INFO: 41600 events read in total (2671ms).
[10:59:21.908] INFO: Test took 3911ms.
[10:59:21.939] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:22.668] INFO: Expecting 41600 events.
[10:59:25.869] INFO: 41600 events read in total (2674ms).
[10:59:25.870] INFO: Test took 3914ms.
[10:59:25.900] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:26.632] INFO: Expecting 41600 events.
[10:59:29.828] INFO: 41600 events read in total (2669ms).
[10:59:29.829] INFO: Test took 3913ms.
[10:59:29.859] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:30.589] INFO: Expecting 41600 events.
[10:59:33.791] INFO: 41600 events read in total (2675ms).
[10:59:33.792] INFO: Test took 3916ms.
[10:59:33.822] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:34.555] INFO: Expecting 41600 events.
[10:59:37.758] INFO: 41600 events read in total (2676ms).
[10:59:37.759] INFO: Test took 3920ms.
[10:59:37.790] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:38.518] INFO: Expecting 41600 events.
[10:59:41.663] INFO: 41600 events read in total (2618ms).
[10:59:41.664] INFO: Test took 3857ms.
[10:59:41.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:42.427] INFO: Expecting 41600 events.
[10:59:45.598] INFO: 41600 events read in total (2644ms).
[10:59:45.599] INFO: Test took 3888ms.
[10:59:45.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:46.361] INFO: Expecting 41600 events.
[10:59:49.559] INFO: 41600 events read in total (2671ms).
[10:59:49.560] INFO: Test took 3915ms.
[10:59:49.590] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:50.324] INFO: Expecting 41600 events.
[10:59:53.517] INFO: 41600 events read in total (2667ms).
[10:59:53.518] INFO: Test took 3911ms.
[10:59:53.548] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:54.279] INFO: Expecting 41600 events.
[10:59:57.453] INFO: 41600 events read in total (2647ms).
[10:59:57.454] INFO: Test took 3890ms.
[10:59:57.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:58.215] INFO: Expecting 41600 events.
[11:00:01.355] INFO: 41600 events read in total (2614ms).
[11:00:01.356] INFO: Test took 3854ms.
[11:00:01.388] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:02.118] INFO: Expecting 41600 events.
[11:00:05.323] INFO: 41600 events read in total (2678ms).
[11:00:05.324] INFO: Test took 3919ms.
[11:00:05.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:06.084] INFO: Expecting 41600 events.
[11:00:09.287] INFO: 41600 events read in total (2676ms).
[11:00:09.288] INFO: Test took 3917ms.
[11:00:09.318] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:10.052] INFO: Expecting 41600 events.
[11:00:13.255] INFO: 41600 events read in total (2676ms).
[11:00:13.256] INFO: Test took 3921ms.
[11:00:13.286] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:14.014] INFO: Expecting 41600 events.
[11:00:17.205] INFO: 41600 events read in total (2664ms).
[11:00:17.206] INFO: Test took 3902ms.
[11:00:17.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:17.969] INFO: Expecting 41600 events.
[11:00:21.028] INFO: 41600 events read in total (2532ms).
[11:00:21.029] INFO: Test took 3776ms.
[11:00:21.058] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:21.422] INFO: enter test to run
[11:00:29.263] INFO: test: HighRate no parameter change
[11:00:29.263] INFO: running: highrate
[11:00:29.264] INFO: ----------------------------------------------------------------------
[11:00:29.264] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:00:29.264] INFO: ----------------------------------------------------------------------
[11:00:29.876] INFO: Expecting 208000 events.
[11:00:41.495] INFO: 208000 events read in total (11093ms).
[11:00:41.498] INFO: Test took 12228ms.
[11:00:41.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:41.869] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 1 0 0 0
[11:00:41.869] INFO: number of red-efficiency pixels: 56 46 67 108 128 159 109 88 83 93 79 110 79 47 15 27
[11:00:41.869] INFO: number of X-ray hits detected: 55905 37144 59453 91246 95111 107290 99175 67125 63293 86073 73261 72995 75395 44582 17744 21964
[11:00:41.869] 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:00:41.869] INFO: number of Vcal hits detected: 207943 207954 207933 207791 207871 207837 207886 207911 207917 207903 207921 207889 207872 207951 207985 207973
[11:00:41.869] 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 99.9 100.0 100.0 100.0 100.0
[11:00:41.869] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0
[11:00:41.869] INFO: X-ray hit rate [MHz/cm2]: 16.4 10.9 17.4 26.7 27.9 31.4 29.1 19.7 18.6 25.2 21.5 21.4 22.1 13.1 5.2 6.4
[11:00:41.869] INFO: PixTestHighRate::doXPixelAlive() done
[11:00:41.920] INFO: PixTest:: pg_setup set to default.
[11:00:41.936] INFO: enter test to run
[11:01:17.030] INFO: test: HighRate no parameter change
[11:01:17.030] INFO: running: highrate
[11:01:17.032] INFO: ----------------------------------------------------------------------
[11:01:17.032] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:01:17.032] INFO: ----------------------------------------------------------------------
[11:01:17.648] INFO: Expecting 208000 events.
[11:01:30.692] INFO: 208000 events read in total (12517ms).
[11:01:30.697] INFO: Test took 13655ms.
[11:01:30.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:31.238] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 1 0 0 0
[11:01:31.238] INFO: number of red-efficiency pixels: 174 89 157 333 375 395 333 175 232 251 205 282 242 134 42 45
[11:01:31.238] INFO: number of X-ray hits detected: 113437 75970 120653 184534 193767 217342 201742 136652 129677 176469 148746 149530 153162 91306 36419 44698
[11:01:31.238] 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:01:31.238] INFO: number of Vcal hits detected: 207814 207910 207835 207549 207598 207577 207645 207816 207757 207738 207782 207697 207703 207857 207958 207953
[11:01:31.238] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[11:01:31.238] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[11:01:31.238] INFO: X-ray hit rate [MHz/cm2]: 33.2 22.3 35.4 54.1 56.8 63.7 59.1 40.1 38.0 51.7 43.6 43.8 44.9 26.8 10.7 13.1
[11:01:31.238] INFO: PixTestHighRate::doXPixelAlive() done
[11:01:31.285] INFO: PixTest:: pg_setup set to default.
[11:01:31.300] INFO: enter test to run
[11:02:21.022] INFO: test: HighRate no parameter change
[11:02:21.022] INFO: running: highrate
[11:02:21.023] INFO: ----------------------------------------------------------------------
[11:02:21.023] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:02:21.023] INFO: ----------------------------------------------------------------------
[11:02:21.635] INFO: Expecting 208000 events.
[11:02:36.184] INFO: 208000 events read in total (14022ms).
[11:02:36.190] INFO: Test took 15158ms.
[11:02:36.572] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:36.898] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 1 0 0 0
[11:02:36.899] INFO: number of red-efficiency pixels: 357 135 362 749 801 843 708 364 449 522 478 585 457 267 79 70
[11:02:36.899] INFO: number of X-ray hits detected: 170638 114909 182440 277818 291574 328826 303817 207339 195770 265229 225577 224110 230575 136948 55371 67878
[11:02:36.899] 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:02:36.899] INFO: number of Vcal hits detected: 207589 207858 207599 207043 207058 206997 207191 207608 207506 207429 207485 207327 207448 207706 207917 207929
[11:02:36.899] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.6 99.6 99.8 99.8 99.7 99.8 99.7 99.8 99.9 100.0 100.0
[11:02:36.899] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.5 99.5 99.5 99.6 99.8 99.8 99.7 99.8 99.7 99.7 99.9 100.0 100.0
[11:02:36.899] INFO: X-ray hit rate [MHz/cm2]: 50.0 33.7 53.5 81.4 85.5 96.4 89.1 60.8 57.4 77.7 66.1 65.7 67.6 40.1 16.2 19.9
[11:02:36.899] INFO: PixTestHighRate::doXPixelAlive() done
[11:02:36.945] INFO: PixTest:: pg_setup set to default.
[11:02:36.957] INFO: enter test to run
[11:02:54.262] INFO: test: exit no parameter change
[11:02:54.597] QUIET: Connection to board 33 closed.
[11:02:54.610] INFO: pXar: this is the end, my friend