[13:39:00.266] INFO: *** Welcome to pxar ***
[13:39:00.266] INFO: *** Today: 2016/08/25
[13:39:01.862] INFO: *** Version: v1.9.0-818-g96727
[13:39:01.862] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//dacParameters35_C15.dat
[13:39:02.366] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:39:02.366] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//defaultMaskFile.dat
[13:39:02.394] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C15.dat
[13:39:03.599] INFO: clk: 4
[13:39:03.599] INFO: ctr: 4
[13:39:03.599] INFO: sda: 19
[13:39:03.599] INFO: tin: 9
[13:39:03.599] INFO: level: 15
[13:39:03.599] INFO: triggerdelay: 0
[13:39:03.599] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:39:03.599] INFO: Log level: INFO
[13:39:03.617] QUIET: Connection to board DTB_WREKRL opened.
[13:39:03.623] 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:
------------------------------------------------------
[13:39:03.627] INFO: RPC call hashes of host and DTB match: 398089610
[13:39:05.161] INFO: DUT info:
[13:39:05.161] INFO: The DUT currently contains the following objects:
[13:39:05.161] INFO: 2 TBM Cores tbm08c (2 ON)
[13:39:05.161] INFO: TBM Core alpha (0): 7 registers set
[13:39:05.161] INFO: TBM Core beta (1): 7 registers set
[13:39:05.161] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:39:05.161] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.161] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.161] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.161] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.162] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:39:05.631] INFO: enter 'restricted' command line mode
[13:39:05.631] INFO: enter test to run
[13:39:15.273] INFO: test: PixelAlive no parameter change
[13:39:15.273] INFO: running: pixelalive
[13:39:15.296] INFO: ----------------------------------------------------------------------
[13:39:15.296] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:39:15.296] INFO: ----------------------------------------------------------------------
[13:39:15.618] INFO: Expecting 41600 events.
[13:39:19.936] INFO: 41600 events read in total (3599ms).
[13:39:20.105] INFO: Test took 4806ms.
[13:39:20.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:20.404] INFO: PixTestAlive::aliveTest() done
[13:39:20.404] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 4 0 0 0 0 0 1 0 0 0
[13:39:20.434] INFO: enter test to run
[13:39:55.097] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:39:55.097] INFO: running: highrate
[13:39:55.110] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:39:57.436] INFO: ----------------------------------------------------------------------
[13:39:57.436] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:39:57.436] INFO: ----------------------------------------------------------------------
[13:39:57.436] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:39:57.436] INFO: edge/corner pixel THR is adjusted
[13:39:57.436] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:39:58.447] INFO: Collecting data for 5 seconds...
[13:40:03.463] INFO: Done with hot pixel readout
[13:40:15.230] INFO: PixTest:: pg_setup set to default.
[13:40:15.231] INFO: 23 hot pixels found in step 0
[13:40:16.247] INFO: Collecting data for 5 seconds...
[13:40:21.264] INFO: Done with hot pixel readout
[13:40:33.018] INFO: PixTest:: pg_setup set to default.
[13:40:33.019] INFO: 19 hot pixels found in step 1
[13:40:34.007] INFO: Collecting data for 5 seconds...
[13:40:39.024] INFO: Done with hot pixel readout
[13:40:50.683] INFO: PixTest:: pg_setup set to default.
[13:40:50.684] INFO: 21 hot pixels found in step 2
[13:40:51.673] INFO: Collecting data for 5 seconds...
[13:40:56.690] INFO: Done with hot pixel readout
[13:41:07.006] INFO: PixTest:: pg_setup set to default.
[13:41:07.008] INFO: 26 hot pixels found in step 3
[13:41:07.003] INFO: Collecting data for 5 seconds...
[13:41:13.019] INFO: Done with hot pixel readout
[13:41:23.773] INFO: PixTest:: pg_setup set to default.
[13:41:23.774] INFO: 23 hot pixels found in step 4
[13:41:24.768] INFO: Collecting data for 5 seconds...
[13:41:29.783] INFO: Done with hot pixel readout
[13:41:40.365] INFO: PixTest:: pg_setup set to default.
[13:41:40.366] INFO: 29 hot pixels found in step 5
[13:41:41.359] INFO: Collecting data for 5 seconds...
[13:41:46.376] INFO: Done with hot pixel readout
[13:41:57.904] INFO: PixTest:: pg_setup set to default.
[13:41:57.905] INFO: 21 hot pixels found in step 6
[13:41:58.894] INFO: Collecting data for 5 seconds...
[13:42:03.910] INFO: Done with hot pixel readout
[13:42:15.487] INFO: PixTest:: pg_setup set to default.
[13:42:15.487] INFO: 18 hot pixels found in step 7
[13:42:16.475] INFO: Collecting data for 5 seconds...
[13:42:21.492] INFO: Done with hot pixel readout
[13:42:33.068] INFO: PixTest:: pg_setup set to default.
[13:42:33.069] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:42:33.069] INFO: 17 hot pixels found in step 8
[13:42:34.058] INFO: Collecting data for 5 seconds...
[13:42:39.074] INFO: Done with hot pixel readout
[13:42:50.698] INFO: PixTest:: pg_setup set to default.
[13:42:50.699] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:42:50.699] INFO: 22 hot pixels found in step 9
[13:42:51.688] INFO: Collecting data for 5 seconds...
[13:42:56.705] INFO: Done with hot pixel readout
[13:43:08.312] INFO: PixTest:: pg_setup set to default.
[13:43:08.313] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:43:08.313] INFO: 22 hot pixels found in step 10
[13:43:09.302] INFO: Collecting data for 5 seconds...
[13:43:14.318] INFO: Done with hot pixel readout
[13:43:25.937] INFO: PixTest:: pg_setup set to default.
[13:43:25.938] INFO: 14 hot pixels found in step 11
[13:43:26.926] INFO: Collecting data for 5 seconds...
[13:43:31.942] INFO: Done with hot pixel readout
[13:43:43.564] INFO: PixTest:: pg_setup set to default.
[13:43:43.564] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:43:43.564] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:43:43.564] INFO: 17 hot pixels found in step 12
[13:43:44.552] INFO: Collecting data for 5 seconds...
[13:43:49.569] INFO: Done with hot pixel readout
[13:44:01.186] INFO: PixTest:: pg_setup set to default.
[13:44:01.187] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:44:01.187] INFO: 17 hot pixels found in step 13
[13:44:02.175] INFO: Collecting data for 5 seconds...
[13:44:07.192] INFO: Done with hot pixel readout
[13:44:18.500] INFO: PixTest:: pg_setup set to default.
[13:44:18.501] INFO: 20 hot pixels found in step 14
[13:44:18.532] INFO: 20 hot pixels could not be trimmed and have been masked.
[13:44:18.610] INFO: PixTest::trimHotPixels() done
[13:44:18.614] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C0.dat
[13:44:18.619] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C1.dat
[13:44:18.625] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C2.dat
[13:44:18.630] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C3.dat
[13:44:18.636] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C4.dat
[13:44:18.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C5.dat
[13:44:18.647] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C6.dat
[13:44:18.653] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C7.dat
[13:44:18.658] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C8.dat
[13:44:18.664] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C9.dat
[13:44:18.669] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C10.dat
[13:44:18.675] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C11.dat
[13:44:18.680] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C12.dat
[13:44:18.686] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C13.dat
[13:44:18.691] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C14.dat
[13:44:18.697] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C15.dat
[13:44:18.703] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//defaultMaskFile.dat
[13:44:18.713] INFO: enter test to run
[13:49:41.237] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:49:41.237] INFO: running: highrate
[13:49:41.242] INFO: ----------------------------------------------------------------------
[13:49:41.242] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:49:41.242] INFO: ----------------------------------------------------------------------
[13:49:41.242] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:49:41.242] INFO: edge/corner pixel THR is adjusted
[13:49:41.242] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:49:42.204] INFO: Collecting data for 1 seconds...
[13:49:43.209] INFO: Done with hot pixel readout
[13:49:47.564] INFO: PixTest:: pg_setup set to default.
[13:49:47.564] INFO: 0 hot pixels found in step 0
[13:49:47.570] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:49:47.644] INFO: PixTest::trimHotPixels() done
[13:49:47.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C0.dat
[13:49:47.654] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C1.dat
[13:49:47.659] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C2.dat
[13:49:47.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C3.dat
[13:49:47.671] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C4.dat
[13:49:47.677] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C5.dat
[13:49:47.683] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C6.dat
[13:49:47.688] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C7.dat
[13:49:47.694] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C8.dat
[13:49:47.700] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C9.dat
[13:49:47.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C10.dat
[13:49:47.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C11.dat
[13:49:47.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C12.dat
[13:49:47.723] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C13.dat
[13:49:47.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C14.dat
[13:49:47.734] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//trimParameters35_C15.dat
[13:49:47.740] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-9-18_FPIXTest-17C-FNAL-160819-1210-150V_2016-08-19_12h10m_1471626637/000_FPIXTest_p17//defaultMaskFile.dat
[13:49:47.749] INFO: enter test to run
[13:50:31.220] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:50:31.221] INFO: running: xray
[13:50:31.222] INFO: ----------------------------------------------------------------------
[13:50:31.222] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:50:31.222] INFO: ----------------------------------------------------------------------
[13:50:32.186] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:50:43.757] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:51:13.336] INFO: Resuming triggers.
[13:51:24.907] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:51:54.302] INFO: Resuming triggers.
[13:52:05.872] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:52:35.359] INFO: Resuming triggers.
[13:52:46.935] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:53:16.367] INFO: Resuming triggers.
[13:53:27.937] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:53:57.342] INFO: Resuming triggers.
[13:54:08.909] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:54:38.303] INFO: Resuming triggers.
[13:54:49.873] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:55:19.331] INFO: Resuming triggers.
[13:55:30.906] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:56:00.281] INFO: Resuming triggers.
[13:56:08.039] INFO: data taking finished, elapsed time: 100 seconds.
[13:56:28.037] INFO: PixTest:: pg_setup set to default.
[13:56:28.040] INFO: PixTestXray::doPhRun() done
[13:56:28.177] INFO: enter test to run
[13:57:14.122] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:57:14.122] INFO: running: xray
[13:57:14.123] INFO: ----------------------------------------------------------------------
[13:57:14.123] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:57:14.123] INFO: ----------------------------------------------------------------------
[13:57:15.087] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:57:21.846] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:57:52.253] INFO: Resuming triggers.
[13:57:59.015] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:58:30.255] INFO: Resuming triggers.
[13:58:37.014] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:59:07.960] INFO: Resuming triggers.
[13:59:14.722] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[13:59:45.192] INFO: Resuming triggers.
[13:59:51.954] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:00:22.940] INFO: Resuming triggers.
[14:00:29.698] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[14:01:00.889] INFO: Resuming triggers.
[14:01:07.646] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:01:39.554] INFO: Resuming triggers.
[14:01:46.314] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[14:02:17.842] INFO: Resuming triggers.
[14:02:24.602] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[14:02:56.172] INFO: Resuming triggers.
[14:03:02.928] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:03:33.360] INFO: Resuming triggers.
[14:03:40.120] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:04:10.536] INFO: Resuming triggers.
[14:04:17.292] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:04:47.686] INFO: Resuming triggers.
[14:04:54.447] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[14:05:24.839] INFO: Resuming triggers.
[14:05:31.601] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:06:02.047] INFO: Resuming triggers.
[14:06:07.765] INFO: data taking finished, elapsed time: 100 seconds.
[14:06:33.840] INFO: PixTest:: pg_setup set to default.
[14:06:33.844] INFO: PixTestXray::doPhRun() done
[14:06:34.008] INFO: enter test to run
[14:06:55.022] INFO: test: HighRate no parameter change
[14:06:55.022] INFO: running: highrate
[14:06:55.036] INFO: ----------------------------------------------------------------------
[14:06:55.036] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:06:55.036] INFO: ----------------------------------------------------------------------
[14:06:55.192] INFO: Expecting 768 events.
[14:06:56.325] INFO: 768 events read in total (418ms).
[14:06:56.326] INFO: Test took 1269ms.
[14:06:57.129] INFO: Expecting 41600 events.
[14:07:00.224] INFO: 41600 events read in total (2568ms).
[14:07:00.225] INFO: Test took 3873ms.
[14:07:00.257] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:00.986] INFO: Expecting 41600 events.
[14:07:04.187] INFO: 41600 events read in total (2674ms).
[14:07:04.188] INFO: Test took 3913ms.
[14:07:04.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:04.947] INFO: Expecting 41600 events.
[14:07:08.184] INFO: 41600 events read in total (2710ms).
[14:07:08.185] INFO: Test took 3948ms.
[14:07:08.217] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:08.945] INFO: Expecting 41600 events.
[14:07:12.181] INFO: 41600 events read in total (2709ms).
[14:07:12.182] INFO: Test took 3947ms.
[14:07:12.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:12.942] INFO: Expecting 41600 events.
[14:07:16.167] INFO: 41600 events read in total (2698ms).
[14:07:16.168] INFO: Test took 3936ms.
[14:07:16.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:16.929] INFO: Expecting 41600 events.
[14:07:20.158] INFO: 41600 events read in total (2702ms).
[14:07:20.159] INFO: Test took 3940ms.
[14:07:20.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:20.917] INFO: Expecting 41600 events.
[14:07:24.158] INFO: 41600 events read in total (2714ms).
[14:07:24.159] INFO: Test took 3950ms.
[14:07:24.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:24.920] INFO: Expecting 41600 events.
[14:07:28.147] INFO: 41600 events read in total (2700ms).
[14:07:28.148] INFO: Test took 3939ms.
[14:07:28.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:28.900] INFO: Expecting 41600 events.
[14:07:32.146] INFO: 41600 events read in total (2719ms).
[14:07:32.147] INFO: Test took 3947ms.
[14:07:32.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:32.905] INFO: Expecting 41600 events.
[14:07:36.111] INFO: 41600 events read in total (2679ms).
[14:07:36.112] INFO: Test took 3916ms.
[14:07:36.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:36.868] INFO: Expecting 41600 events.
[14:07:40.106] INFO: 41600 events read in total (2711ms).
[14:07:40.107] INFO: Test took 3943ms.
[14:07:40.140] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:40.869] INFO: Expecting 41600 events.
[14:07:44.039] INFO: 41600 events read in total (2643ms).
[14:07:44.040] INFO: Test took 3882ms.
[14:07:44.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:44.800] INFO: Expecting 41600 events.
[14:07:47.889] INFO: 41600 events read in total (2563ms).
[14:07:47.890] INFO: Test took 3799ms.
[14:07:47.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:48.646] INFO: Expecting 41600 events.
[14:07:51.862] INFO: 41600 events read in total (2689ms).
[14:07:51.863] INFO: Test took 3922ms.
[14:07:51.896] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:52.620] INFO: Expecting 41600 events.
[14:07:55.851] INFO: 41600 events read in total (2705ms).
[14:07:55.853] INFO: Test took 3938ms.
[14:07:55.886] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:56.611] INFO: Expecting 41600 events.
[14:07:59.832] INFO: 41600 events read in total (2694ms).
[14:07:59.833] INFO: Test took 3929ms.
[14:07:59.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:00.591] INFO: Expecting 41600 events.
[14:08:03.827] INFO: 41600 events read in total (2709ms).
[14:08:03.828] INFO: Test took 3945ms.
[14:08:03.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:04.587] INFO: Expecting 41600 events.
[14:08:07.837] INFO: 41600 events read in total (2723ms).
[14:08:07.838] INFO: Test took 3961ms.
[14:08:07.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:08.599] INFO: Expecting 41600 events.
[14:08:11.831] INFO: 41600 events read in total (2705ms).
[14:08:11.832] INFO: Test took 3946ms.
[14:08:11.863] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:12.591] INFO: Expecting 41600 events.
[14:08:15.658] INFO: 41600 events read in total (2540ms).
[14:08:15.659] INFO: Test took 3779ms.
[14:08:15.690] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:16.058] INFO: enter test to run
[14:08:42.037] INFO: test: HighRate no parameter change
[14:08:42.037] INFO: running: highrate
[14:08:42.038] INFO: ----------------------------------------------------------------------
[14:08:42.038] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:08:42.038] INFO: ----------------------------------------------------------------------
[14:08:42.652] INFO: Expecting 208000 events.
[14:08:54.411] INFO: 208000 events read in total (11232ms).
[14:08:54.413] INFO: Test took 12364ms.
[14:08:54.543] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:54.790] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 4 135 0 0 0 0 1 0 0 0
[14:08:54.790] INFO: number of red-efficiency pixels: 56 46 83 112 3992 173 145 386 72 129 146 101 114 76 29 22
[14:08:54.790] INFO: number of X-ray hits detected: 43274 39796 64371 102733 41758 111617 109194 69696 71314 98646 96710 85109 90250 52928 19960 22714
[14:08:54.790] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:08:54.790] INFO: number of Vcal hits detected: 207943 207954 207916 207885 156404 207821 207657 200977 207927 207871 207848 207899 207836 207923 207971 207978
[14:08:54.790] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 75.1 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[14:08:54.790] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 75.2 99.9 99.8 96.6 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[14:08:54.790] INFO: X-ray hit rate [MHz/cm2]: 12.7 11.7 18.9 30.1 12.2 32.7 32.0 20.4 20.9 28.9 28.3 24.9 26.5 15.5 5.9 6.7
[14:08:54.790] INFO: PixTestHighRate::doXPixelAlive() done
[14:08:54.841] INFO: PixTest:: pg_setup set to default.
[14:08:54.856] INFO: enter test to run
[14:09:11.957] INFO: test: HighRate no parameter change
[14:09:11.957] INFO: running: highrate
[14:09:11.958] INFO: ----------------------------------------------------------------------
[14:09:11.958] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:09:11.958] INFO: ----------------------------------------------------------------------
[14:09:12.575] INFO: Expecting 208000 events.
[14:09:26.061] INFO: 208000 events read in total (12960ms).
[14:09:26.066] INFO: Test took 14097ms.
[14:09:26.332] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:26.624] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 4 141 0 0 0 0 1 0 0 0
[14:09:26.624] INFO: number of red-efficiency pixels: 119 128 306 375 3867 560 437 488 225 440 426 277 318 208 47 77
[14:09:26.624] INFO: number of X-ray hits detected: 91125 83468 135527 215346 78804 234232 229371 146595 149739 206045 203266 178123 188899 111057 42064 47809
[14:09:26.624] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:09:26.624] INFO: number of Vcal hits detected: 207876 207867 207655 207587 166720 207374 207327 200466 207765 207532 207541 207706 207622 207778 207951 207922
[14:09:26.624] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 80.2 99.7 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:09:26.624] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 80.2 99.7 99.7 96.4 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[14:09:26.624] INFO: X-ray hit rate [MHz/cm2]: 26.7 24.5 39.7 63.1 23.1 68.7 67.2 43.0 43.9 60.4 59.6 52.2 55.4 32.6 12.3 14.0
[14:09:26.624] INFO: PixTestHighRate::doXPixelAlive() done
[14:09:26.678] INFO: PixTest:: pg_setup set to default.
[14:09:26.693] INFO: enter test to run
[14:09:41.613] INFO: test: HighRate no parameter change
[14:09:41.613] INFO: running: highrate
[14:09:41.614] INFO: ----------------------------------------------------------------------
[14:09:41.614] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:09:41.614] INFO: ----------------------------------------------------------------------
[14:09:42.235] INFO: Expecting 208000 events.
[14:09:57.615] INFO: 208000 events read in total (14854ms).
[14:09:57.622] INFO: Test took 15997ms.
[14:09:58.022] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:58.358] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 4 160 0 0 0 0 1 0 0 0
[14:09:58.358] INFO: number of red-efficiency pixels: 244 245 669 883 3738 1379 1002 904 466 1101 1032 555 700 508 90 93
[14:09:58.358] INFO: number of X-ray hits detected: 139152 126824 206871 328484 114336 356711 350394 223218 230899 314263 308952 272066 288399 169615 64683 72874
[14:09:58.358] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:09:58.358] INFO: number of Vcal hits detected: 207738 207726 207115 206930 173121 206129 206546 199069 207462 206616 206712 207363 207148 207389 207908 207906
[14:09:58.358] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.6 99.5 83.3 99.2 99.5 99.6 99.8 99.4 99.4 99.7 99.7 99.7 100.0 100.0
[14:09:58.358] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.6 99.5 83.2 99.1 99.3 95.7 99.7 99.3 99.4 99.7 99.6 99.7 100.0 100.0
[14:09:58.358] INFO: X-ray hit rate [MHz/cm2]: 40.8 37.2 60.6 96.3 33.5 104.6 102.7 65.4 67.7 92.1 90.6 79.7 84.5 49.7 19.0 21.4
[14:09:58.358] INFO: PixTestHighRate::doXPixelAlive() done
[14:09:58.409] INFO: PixTest:: pg_setup set to default.
[14:09:58.424] INFO: enter test to run
[14:10:01.260] INFO: test: exit no parameter change
[14:10:01.539] QUIET: Connection to board 33 closed.
[14:10:01.549] INFO: pXar: this is the end, my friend