[15:01:45.281] INFO: *** Welcome to pxar ***
[15:01:45.281] INFO: *** Today: 2016/09/09
[15:01:46.100] INFO: *** Version: v1.9.0-818-g96727
[15:01:46.100] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//dacParameters35_C15.dat
[15:01:46.166] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:01:46.187] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//defaultMaskFile.dat
[15:01:46.205] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C15.dat
[15:01:46.387] INFO: clk: 4
[15:01:46.387] INFO: ctr: 4
[15:01:46.387] INFO: sda: 19
[15:01:46.387] INFO: tin: 9
[15:01:46.387] INFO: level: 15
[15:01:46.387] INFO: triggerdelay: 0
[15:01:46.404] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:01:46.405] INFO: Log level: INFO
[15:01:46.429] QUIET: Connection to board DTB_WREKRL opened.
[15:01:46.432] 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:
------------------------------------------------------
[15:01:46.435] INFO: RPC call hashes of host and DTB match: 398089610
[15:01:47.965] INFO: DUT info:
[15:01:47.965] INFO: The DUT currently contains the following objects:
[15:01:47.965] INFO: 2 TBM Cores tbm08c (2 ON)
[15:01:47.965] INFO: TBM Core alpha (0): 7 registers set
[15:01:47.965] INFO: TBM Core beta (1): 7 registers set
[15:01:47.965] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:01:47.966] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:47.966] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:01:48.420] INFO: enter 'restricted' command line mode
[15:01:48.420] INFO: enter test to run
[15:01:55.401] INFO: test: PixelAlive no parameter change
[15:01:55.401] INFO: running: pixelalive
[15:01:55.450] INFO: ----------------------------------------------------------------------
[15:01:55.450] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:01:55.450] INFO: ----------------------------------------------------------------------
[15:01:55.769] INFO: Expecting 41600 events.
[15:02:00.089] INFO: 41600 events read in total (3602ms).
[15:02:00.259] INFO: Test took 4806ms.
[15:02:00.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:00.799] INFO: PixTestAlive::aliveTest() done
[15:02:00.799] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 1 0 0 0 0 1 0 0
[15:02:00.989] INFO: enter test to run
[15:02:24.673] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:02:24.673] INFO: running: highrate
[15:02:24.694] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:02:25.045] INFO: ----------------------------------------------------------------------
[15:02:25.045] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:02:25.046] INFO: ----------------------------------------------------------------------
[15:02:25.046] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:02:25.046] INFO: edge/corner pixel THR is adjusted
[15:02:25.046] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:02:26.024] INFO: Collecting data for 5 seconds...
[15:02:31.039] INFO: Done with hot pixel readout
[15:02:43.050] INFO: PixTest:: pg_setup set to default.
[15:02:43.051] INFO: 34 hot pixels found in step 0
[15:02:44.047] INFO: Collecting data for 5 seconds...
[15:02:49.062] INFO: Done with hot pixel readout
[15:03:00.003] INFO: PixTest:: pg_setup set to default.
[15:03:00.003] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:03:00.003] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:03:00.004] INFO: 39 hot pixels found in step 1
[15:03:01.001] INFO: Collecting data for 5 seconds...
[15:03:07.018] INFO: Done with hot pixel readout
[15:03:19.034] INFO: PixTest:: pg_setup set to default.
[15:03:19.035] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:03:19.035] INFO: 44 hot pixels found in step 2
[15:03:20.030] INFO: Collecting data for 5 seconds...
[15:03:25.047] INFO: Done with hot pixel readout
[15:03:37.073] INFO: PixTest:: pg_setup set to default.
[15:03:37.074] INFO: 37 hot pixels found in step 3
[15:03:38.068] INFO: Collecting data for 5 seconds...
[15:03:43.084] INFO: Done with hot pixel readout
[15:03:55.076] INFO: PixTest:: pg_setup set to default.
[15:03:55.077] INFO: 40 hot pixels found in step 4
[15:03:56.071] INFO: Collecting data for 5 seconds...
[15:04:01.086] INFO: Done with hot pixel readout
[15:04:13.123] INFO: PixTest:: pg_setup set to default.
[15:04:13.123] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:04:13.123] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:04:13.124] INFO: 33 hot pixels found in step 5
[15:04:14.119] INFO: Collecting data for 5 seconds...
[15:04:19.136] INFO: Done with hot pixel readout
[15:04:31.194] INFO: PixTest:: pg_setup set to default.
[15:04:31.194] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:04:31.195] INFO: 28 hot pixels found in step 6
[15:04:32.189] INFO: Collecting data for 5 seconds...
[15:04:37.204] INFO: Done with hot pixel readout
[15:04:49.169] INFO: PixTest:: pg_setup set to default.
[15:04:49.169] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:04:49.169] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:04:49.169] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:04:49.170] INFO: 28 hot pixels found in step 7
[15:04:50.165] INFO: Collecting data for 5 seconds...
[15:04:55.181] INFO: Done with hot pixel readout
[15:05:07.240] INFO: PixTest:: pg_setup set to default.
[15:05:07.240] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:07.240] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:07.240] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:07.240] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:07.241] INFO: 37 hot pixels found in step 8
[15:05:08.235] INFO: Collecting data for 5 seconds...
[15:05:13.251] INFO: Done with hot pixel readout
[15:05:25.239] INFO: PixTest:: pg_setup set to default.
[15:05:25.239] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:25.239] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:25.239] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:25.239] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:25.239] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:25.240] INFO: 27 hot pixels found in step 9
[15:05:26.233] INFO: Collecting data for 5 seconds...
[15:05:31.249] INFO: Done with hot pixel readout
[15:05:43.237] INFO: PixTest:: pg_setup set to default.
[15:05:43.237] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:43.237] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:43.237] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:43.237] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:05:43.238] INFO: 23 hot pixels found in step 10
[15:05:44.232] INFO: Collecting data for 5 seconds...
[15:05:49.248] INFO: Done with hot pixel readout
[15:06:01.233] INFO: PixTest:: pg_setup set to default.
[15:06:01.234] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:01.234] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:01.234] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:01.234] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:01.234] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:01.235] INFO: 29 hot pixels found in step 11
[15:06:02.230] INFO: Collecting data for 5 seconds...
[15:06:07.246] INFO: Done with hot pixel readout
[15:06:19.205] INFO: PixTest:: pg_setup set to default.
[15:06:19.205] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:19.205] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:19.205] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:19.205] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:19.206] INFO: 24 hot pixels found in step 12
[15:06:20.200] INFO: Collecting data for 5 seconds...
[15:06:25.216] INFO: Done with hot pixel readout
[15:06:37.189] INFO: PixTest:: pg_setup set to default.
[15:06:37.189] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:37.189] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:37.189] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:37.189] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:37.189] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:37.190] INFO: 18 hot pixels found in step 13
[15:06:38.185] INFO: Collecting data for 5 seconds...
[15:06:43.204] INFO: Done with hot pixel readout
[15:06:55.255] INFO: PixTest:: pg_setup set to default.
[15:06:55.255] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:55.255] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:55.255] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:55.255] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:06:55.256] INFO: 23 hot pixels found in step 14
[15:06:55.294] INFO: 23 hot pixels could not be trimmed and have been masked.
[15:06:55.315] INFO: PixTest::trimHotPixels() done
[15:06:55.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C0.dat
[15:06:55.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C1.dat
[15:06:55.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C2.dat
[15:06:55.349] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C3.dat
[15:06:55.358] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C4.dat
[15:06:55.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C5.dat
[15:06:55.369] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C6.dat
[15:06:55.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C7.dat
[15:06:55.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C8.dat
[15:06:55.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C9.dat
[15:06:55.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C10.dat
[15:06:55.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C11.dat
[15:06:55.402] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C12.dat
[15:06:55.407] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C13.dat
[15:06:55.412] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C14.dat
[15:06:55.418] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C15.dat
[15:06:55.423] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//defaultMaskFile.dat
[15:06:55.434] INFO: enter test to run
[15:07:30.271] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:07:30.271] INFO: running: highrate
[15:07:30.275] INFO: ----------------------------------------------------------------------
[15:07:30.275] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:07:30.275] INFO: ----------------------------------------------------------------------
[15:07:30.275] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:07:30.275] INFO: edge/corner pixel THR is adjusted
[15:07:30.275] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:07:31.233] INFO: Collecting data for 1 seconds...
[15:07:32.236] INFO: Done with hot pixel readout
[15:07:36.420] INFO: PixTest:: pg_setup set to default.
[15:07:36.421] INFO: 0 hot pixels found in step 0
[15:07:36.426] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:07:36.508] INFO: PixTest::trimHotPixels() done
[15:07:36.508] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C0.dat
[15:07:36.531] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C1.dat
[15:07:36.539] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C2.dat
[15:07:36.546] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C3.dat
[15:07:36.552] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C4.dat
[15:07:36.557] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C5.dat
[15:07:36.563] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C6.dat
[15:07:36.568] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C7.dat
[15:07:36.574] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C8.dat
[15:07:36.579] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C9.dat
[15:07:36.584] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C10.dat
[15:07:36.590] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C11.dat
[15:07:36.595] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C12.dat
[15:07:36.601] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C13.dat
[15:07:36.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C14.dat
[15:07:36.612] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//trimParameters35_C15.dat
[15:07:36.617] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-17_FPIXTest-17C-FNAL-160908-0910-300V_2016-09-08_09h10m_1473343814/000_FPIXTest_p17//defaultMaskFile.dat
[15:07:36.627] INFO: enter test to run
[15:08:02.966] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:08:02.967] INFO: running: xray
[15:08:02.968] INFO: ----------------------------------------------------------------------
[15:08:02.968] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:08:02.968] INFO: ----------------------------------------------------------------------
[15:08:03.931] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:08:15.075] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:08:44.919] INFO: Resuming triggers.
[15:08:56.069] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:09:25.009] INFO: Resuming triggers.
[15:09:36.156] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:10:07.050] INFO: Resuming triggers.
[15:10:18.198] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:10:48.527] INFO: Resuming triggers.
[15:10:59.677] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:11:29.992] INFO: Resuming triggers.
[15:11:41.140] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:12:11.558] INFO: Resuming triggers.
[15:12:22.707] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[15:12:52.730] INFO: Resuming triggers.
[15:13:03.878] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[15:13:33.468] INFO: Resuming triggers.
[15:13:44.617] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:14:13.962] INFO: Resuming triggers.
[15:14:13.990] INFO: data taking finished, elapsed time: 100 seconds.
[15:14:14.626] INFO: PixTest:: pg_setup set to default.
[15:14:14.629] INFO: PixTestXray::doPhRun() done
[15:14:14.837] INFO: enter test to run
[15:15:00.684] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:15:00.684] INFO: running: xray
[15:15:00.685] INFO: ----------------------------------------------------------------------
[15:15:00.685] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:15:00.685] INFO: ----------------------------------------------------------------------
[15:15:01.666] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:15:08.075] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:15:38.223] INFO: Resuming triggers.
[15:15:44.637] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[15:16:14.809] INFO: Resuming triggers.
[15:16:21.222] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:16:51.430] INFO: Resuming triggers.
[15:16:57.847] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[15:17:27.933] INFO: Resuming triggers.
[15:17:34.355] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[15:18:04.335] INFO: Resuming triggers.
[15:18:10.752] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[15:18:40.876] INFO: Resuming triggers.
[15:18:47.294] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:19:17.404] INFO: Resuming triggers.
[15:19:23.825] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[15:19:54.682] INFO: Resuming triggers.
[15:20:01.106] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:20:31.972] INFO: Resuming triggers.
[15:20:38.398] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[15:21:09.499] INFO: Resuming triggers.
[15:21:15.924] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[15:21:46.507] INFO: Resuming triggers.
[15:21:52.926] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[15:22:23.596] INFO: Resuming triggers.
[15:22:30.015] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:23:00.931] INFO: Resuming triggers.
[15:23:07.348] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:23:39.093] INFO: Resuming triggers.
[15:23:45.518] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[15:24:16.778] INFO: Resuming triggers.
[15:24:20.831] INFO: data taking finished, elapsed time: 100 seconds.
[15:24:40.963] INFO: PixTest:: pg_setup set to default.
[15:24:40.966] INFO: PixTestXray::doPhRun() done
[15:24:41.131] INFO: enter test to run
[15:25:10.119] INFO: test: HighRate no parameter change
[15:25:10.119] INFO: running: highrate
[15:25:10.141] INFO: ----------------------------------------------------------------------
[15:25:10.141] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:25:10.141] INFO: ----------------------------------------------------------------------
[15:25:10.299] INFO: Expecting 768 events.
[15:25:11.453] INFO: 768 events read in total (439ms).
[15:25:11.453] INFO: Test took 1300ms.
[15:25:12.256] INFO: Expecting 41600 events.
[15:25:15.367] INFO: 41600 events read in total (2584ms).
[15:25:15.368] INFO: Test took 3863ms.
[15:25:15.403] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:16.126] INFO: Expecting 41600 events.
[15:25:19.343] INFO: 41600 events read in total (2691ms).
[15:25:19.344] INFO: Test took 3925ms.
[15:25:19.379] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:20.099] INFO: Expecting 41600 events.
[15:25:23.387] INFO: 41600 events read in total (2761ms).
[15:25:23.388] INFO: Test took 3991ms.
[15:25:23.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:24.141] INFO: Expecting 41600 events.
[15:25:27.487] INFO: 41600 events read in total (2819ms).
[15:25:27.488] INFO: Test took 4049ms.
[15:25:27.532] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:28.223] INFO: Expecting 41600 events.
[15:25:31.504] INFO: 41600 events read in total (2755ms).
[15:25:31.505] INFO: Test took 3949ms.
[15:25:31.541] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:32.264] INFO: Expecting 41600 events.
[15:25:35.544] INFO: 41600 events read in total (2753ms).
[15:25:35.545] INFO: Test took 3987ms.
[15:25:35.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:36.301] INFO: Expecting 41600 events.
[15:25:39.562] INFO: 41600 events read in total (2735ms).
[15:25:39.564] INFO: Test took 3966ms.
[15:25:39.606] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:40.315] INFO: Expecting 41600 events.
[15:25:43.584] INFO: 41600 events read in total (2742ms).
[15:25:43.584] INFO: Test took 3961ms.
[15:25:43.619] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:44.337] INFO: Expecting 41600 events.
[15:25:47.624] INFO: 41600 events read in total (2761ms).
[15:25:47.625] INFO: Test took 3988ms.
[15:25:47.660] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:48.376] INFO: Expecting 41600 events.
[15:25:51.641] INFO: 41600 events read in total (2738ms).
[15:25:51.642] INFO: Test took 3964ms.
[15:25:51.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:52.401] INFO: Expecting 41600 events.
[15:25:55.654] INFO: 41600 events read in total (2726ms).
[15:25:55.655] INFO: Test took 3961ms.
[15:25:55.689] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:56.411] INFO: Expecting 41600 events.
[15:25:59.651] INFO: 41600 events read in total (2713ms).
[15:25:59.652] INFO: Test took 3945ms.
[15:25:59.686] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:00.406] INFO: Expecting 41600 events.
[15:26:03.636] INFO: 41600 events read in total (2703ms).
[15:26:03.637] INFO: Test took 3933ms.
[15:26:03.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:04.394] INFO: Expecting 41600 events.
[15:26:07.642] INFO: 41600 events read in total (2721ms).
[15:26:07.643] INFO: Test took 3955ms.
[15:26:07.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:08.400] INFO: Expecting 41600 events.
[15:26:11.663] INFO: 41600 events read in total (2737ms).
[15:26:11.664] INFO: Test took 3969ms.
[15:26:11.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:12.421] INFO: Expecting 41600 events.
[15:26:15.650] INFO: 41600 events read in total (2702ms).
[15:26:15.651] INFO: Test took 3934ms.
[15:26:15.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:16.410] INFO: Expecting 41600 events.
[15:26:19.654] INFO: 41600 events read in total (2717ms).
[15:26:19.655] INFO: Test took 3951ms.
[15:26:19.689] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:20.411] INFO: Expecting 41600 events.
[15:26:23.650] INFO: 41600 events read in total (2712ms).
[15:26:23.651] INFO: Test took 3943ms.
[15:26:23.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:24.407] INFO: Expecting 41600 events.
[15:26:27.621] INFO: 41600 events read in total (2687ms).
[15:26:27.622] INFO: Test took 3919ms.
[15:26:27.656] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:28.377] INFO: Expecting 41600 events.
[15:26:31.439] INFO: 41600 events read in total (2535ms).
[15:26:31.440] INFO: Test took 3765ms.
[15:26:31.473] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:31.837] INFO: enter test to run
[15:26:44.983] INFO: test: HighRate no parameter change
[15:26:44.983] INFO: running: highrate
[15:26:44.984] INFO: ----------------------------------------------------------------------
[15:26:44.984] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:26:44.984] INFO: ----------------------------------------------------------------------
[15:26:45.605] INFO: Expecting 208000 events.
[15:26:57.451] INFO: 208000 events read in total (11319ms).
[15:26:57.454] INFO: Test took 12459ms.
[15:26:57.598] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:57.850] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 1 0 0 0 0 1 0 0
[15:26:57.850] INFO: number of red-efficiency pixels: 109 52 109 129 174 114 147 91 65 140 153 111 95 65 16 31
[15:26:57.850] INFO: number of X-ray hits detected: 74528 45831 70101 107424 111793 112999 111934 72839 66115 98680 97458 83661 89158 54849 20895 24465
[15:26:57.850] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:26:57.850] INFO: number of Vcal hits detected: 207888 207947 207839 207866 207819 207882 207850 207906 207884 207858 207843 207888 207903 207885 207984 207969
[15:26:57.850] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:26:57.850] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0
[15:26:57.850] INFO: X-ray hit rate [MHz/cm2]: 21.8 13.4 20.5 31.5 32.8 33.1 32.8 21.3 19.4 28.9 28.6 24.5 26.1 16.1 6.1 7.2
[15:26:57.850] INFO: PixTestHighRate::doXPixelAlive() done
[15:26:57.903] INFO: PixTest:: pg_setup set to default.
[15:26:57.917] INFO: enter test to run
[15:27:46.303] INFO: test: HighRate no parameter change
[15:27:46.303] INFO: running: highrate
[15:27:46.304] INFO: ----------------------------------------------------------------------
[15:27:46.304] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:27:46.304] INFO: ----------------------------------------------------------------------
[15:27:46.918] INFO: Expecting 208000 events.
[15:28:00.712] INFO: 208000 events read in total (13268ms).
[15:28:00.717] INFO: Test took 14403ms.
[15:28:01.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:01.356] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 1 0 0 0 0 1 0 0
[15:28:01.356] INFO: number of red-efficiency pixels: 378 160 389 598 668 485 653 363 223 501 462 363 405 191 69 75
[15:28:01.356] INFO: number of X-ray hits detected: 165271 102299 155887 240675 250530 253079 251290 162820 149234 220360 217624 186353 199367 122192 46840 55380
[15:28:01.356] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:28:01.356] INFO: number of Vcal hits detected: 207568 207828 207495 207339 207245 207470 207270 207586 207712 207447 207506 207600 207565 207750 207931 207925
[15:28:01.356] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.8 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:28:01.356] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.7 99.6 99.8 99.9 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[15:28:01.356] INFO: X-ray hit rate [MHz/cm2]: 48.4 30.0 45.7 70.5 73.4 74.2 73.7 47.7 43.7 64.6 63.8 54.6 58.4 35.8 13.7 16.2
[15:28:01.356] INFO: PixTestHighRate::doXPixelAlive() done
[15:28:01.402] INFO: PixTest:: pg_setup set to default.
[15:28:01.413] INFO: enter test to run
[15:28:50.086] INFO: test: HighRate no parameter change
[15:28:50.086] INFO: running: highrate
[15:28:50.087] INFO: ----------------------------------------------------------------------
[15:28:50.087] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:28:50.087] INFO: ----------------------------------------------------------------------
[15:28:50.705] INFO: Expecting 208000 events.
[15:29:06.544] INFO: 208000 events read in total (15312ms).
[15:29:06.551] INFO: Test took 16453ms.
[15:29:07.030] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:07.390] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 1 0 0 0 0 1 0 0
[15:29:07.390] INFO: number of red-efficiency pixels: 772 339 838 1257 1506 1150 1449 818 440 1190 1110 898 941 467 91 118
[15:29:07.390] INFO: number of X-ray hits detected: 245062 152221 232389 359729 372318 376353 373578 242438 222759 327357 323295 276447 296778 182063 69805 83021
[15:29:07.390] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:29:07.390] INFO: number of Vcal hits detected: 206872 207619 206719 206336 205837 206508 205933 206918 207462 206489 206634 206889 206877 207385 207908 207879
[15:29:07.390] INFO: Vcal hit fiducial efficiency (%): 99.5 99.8 99.5 99.3 99.1 99.4 99.1 99.5 99.8 99.3 99.4 99.5 99.5 99.8 100.0 99.9
[15:29:07.390] INFO: Vcal hit overall efficiency (%): 99.5 99.8 99.4 99.2 99.0 99.3 99.0 99.5 99.7 99.3 99.3 99.5 99.5 99.7 100.0 99.9
[15:29:07.390] INFO: X-ray hit rate [MHz/cm2]: 71.8 44.6 68.1 105.4 109.1 110.3 109.5 71.1 65.3 96.0 94.8 81.0 87.0 53.4 20.5 24.3
[15:29:07.390] INFO: PixTestHighRate::doXPixelAlive() done
[15:29:07.442] INFO: PixTest:: pg_setup set to default.
[15:29:07.458] INFO: enter test to run
[15:29:16.110] INFO: test: exit no parameter change
[15:29:16.457] QUIET: Connection to board 33 closed.
[15:29:16.469] INFO: pXar: this is the end, my friend