Test Date: 2016-08-23 13:58
Analysis date: 2016-08-26 11:23
Logfile
hrData_40.log
[09:08:44.060] INFO: *** Welcome to pxar ***
[09:08:44.060] INFO: *** Today: 2016/08/26
[09:08:44.083] INFO: *** Version: v1.9.0-818-g96727
[09:08:44.083] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//dacParameters35_C15.dat
[09:08:44.084] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:08:44.084] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//defaultMaskFile.dat
[09:08:44.084] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C15.dat
[09:08:44.161] INFO: clk: 4
[09:08:44.161] INFO: ctr: 4
[09:08:44.161] INFO: sda: 19
[09:08:44.161] INFO: tin: 9
[09:08:44.161] INFO: level: 15
[09:08:44.161] INFO: triggerdelay: 0
[09:08:44.161] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[09:08:44.161] INFO: Log level: INFO
[09:08:44.179] QUIET: Connection to board DTB_WREKRL opened.
[09:08:44.183] 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:
------------------------------------------------------
[09:08:44.186] INFO: RPC call hashes of host and DTB match: 398089610
[09:08:45.721] INFO: DUT info:
[09:08:45.721] INFO: The DUT currently contains the following objects:
[09:08:45.721] INFO: 2 TBM Cores tbm08c (2 ON)
[09:08:45.722] INFO: TBM Core alpha (0): 7 registers set
[09:08:45.722] INFO: TBM Core beta (1): 7 registers set
[09:08:45.722] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:08:45.722] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:45.722] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:08:46.177] INFO: enter 'restricted' command line mode
[09:08:46.177] INFO: enter test to run
[09:08:53.395] INFO: test: PixelAlive no parameter change
[09:08:53.395] INFO: running: pixelalive
[09:08:53.439] INFO: ----------------------------------------------------------------------
[09:08:53.439] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:08:53.439] INFO: ----------------------------------------------------------------------
[09:08:53.757] INFO: Expecting 41600 events.
[09:08:58.094] INFO: 41600 events read in total (3618ms).
[09:08:58.261] INFO: Test took 4818ms.
[09:08:58.275] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:08:58.582] INFO: PixTestAlive::aliveTest() done
[09:08:58.582] INFO: number of dead pixels (per ROC): 0 1 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:08:58.806] INFO: enter test to run
[09:09:38.035] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:09:38.035] INFO: running: highrate
[09:09:38.051] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:09:38.375] INFO: ----------------------------------------------------------------------
[09:09:38.375] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:09:38.375] INFO: ----------------------------------------------------------------------
[09:09:38.375] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:09:38.375] INFO: edge/corner pixel THR is adjusted
[09:09:38.375] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:09:39.333] INFO: Collecting data for 5 seconds...
[09:09:44.351] INFO: Done with hot pixel readout
[09:09:56.334] INFO: PixTest:: pg_setup set to default.
[09:09:56.334] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:09:56.334] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:09:56.335] INFO: 34 hot pixels found in step 0
[09:09:57.350] INFO: Collecting data for 5 seconds...
[09:10:02.367] INFO: Done with hot pixel readout
[09:10:14.359] INFO: PixTest:: pg_setup set to default.
[09:10:14.360] INFO: 24 hot pixels found in step 1
[09:10:15.349] INFO: Collecting data for 5 seconds...
[09:10:20.367] INFO: Done with hot pixel readout
[09:10:32.338] INFO: PixTest:: pg_setup set to default.
[09:10:32.338] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:10:32.339] INFO: 23 hot pixels found in step 2
[09:10:33.330] INFO: Collecting data for 5 seconds...
[09:10:38.349] INFO: Done with hot pixel readout
[09:10:50.299] INFO: PixTest:: pg_setup set to default.
[09:10:50.299] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:10:50.300] INFO: 31 hot pixels found in step 3
[09:10:51.291] INFO: Collecting data for 5 seconds...
[09:10:56.309] INFO: Done with hot pixel readout
[09:11:08.276] INFO: PixTest:: pg_setup set to default.
[09:11:08.277] INFO: 22 hot pixels found in step 4
[09:11:09.267] INFO: Collecting data for 5 seconds...
[09:11:14.285] INFO: Done with hot pixel readout
[09:11:26.193] INFO: PixTest:: pg_setup set to default.
[09:11:26.193] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:11:26.194] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:11:26.194] INFO: 31 hot pixels found in step 5
[09:11:27.184] INFO: Collecting data for 5 seconds...
[09:11:32.202] INFO: Done with hot pixel readout
[09:11:44.170] INFO: PixTest:: pg_setup set to default.
[09:11:44.170] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:11:44.170] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:11:44.171] INFO: 29 hot pixels found in step 6
[09:11:45.161] INFO: Collecting data for 5 seconds...
[09:11:50.179] INFO: Done with hot pixel readout
[09:12:02.145] INFO: PixTest:: pg_setup set to default.
[09:12:02.146] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:12:02.146] INFO: 25 hot pixels found in step 7
[09:12:03.136] INFO: Collecting data for 5 seconds...
[09:12:08.153] INFO: Done with hot pixel readout
[09:12:20.136] INFO: PixTest:: pg_setup set to default.
[09:12:20.136] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:12:20.136] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:12:20.137] INFO: 17 hot pixels found in step 8
[09:12:21.128] INFO: Collecting data for 5 seconds...
[09:12:26.145] INFO: Done with hot pixel readout
[09:12:38.093] INFO: PixTest:: pg_setup set to default.
[09:12:38.093] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:12:38.094] INFO: 22 hot pixels found in step 9
[09:12:39.084] INFO: Collecting data for 5 seconds...
[09:12:44.102] INFO: Done with hot pixel readout
[09:12:56.024] INFO: PixTest:: pg_setup set to default.
[09:12:56.024] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:12:56.025] INFO: 20 hot pixels found in step 10
[09:12:57.015] INFO: Collecting data for 5 seconds...
[09:13:02.032] INFO: Done with hot pixel readout
[09:13:13.999] INFO: PixTest:: pg_setup set to default.
[09:13:13.999] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:13.999] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:13.999] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:13.999] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:13.999] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:13.000] INFO: 21 hot pixels found in step 11
[09:13:14.990] INFO: Collecting data for 5 seconds...
[09:13:20.007] INFO: Done with hot pixel readout
[09:13:31.954] INFO: PixTest:: pg_setup set to default.
[09:13:31.954] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:31.954] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:31.954] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:31.954] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:31.954] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:31.955] INFO: 21 hot pixels found in step 12
[09:13:32.946] INFO: Collecting data for 5 seconds...
[09:13:37.962] INFO: Done with hot pixel readout
[09:13:49.928] INFO: PixTest:: pg_setup set to default.
[09:13:49.928] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:49.928] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:49.928] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:13:49.929] INFO: 12 hot pixels found in step 13
[09:13:50.920] INFO: Collecting data for 5 seconds...
[09:13:55.938] INFO: Done with hot pixel readout
[09:14:07.892] INFO: PixTest:: pg_setup set to default.
[09:14:07.892] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:14:07.892] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:14:07.892] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:14:07.892] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:14:07.892] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:14:07.893] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[09:14:07.893] INFO: 18 hot pixels found in step 14
[09:14:07.927] INFO: 18 hot pixels could not be trimmed and have been masked.
[09:14:07.930] INFO: PixTest::trimHotPixels() done
[09:14:07.933] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C0.dat
[09:14:07.939] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C1.dat
[09:14:07.945] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C2.dat
[09:14:07.950] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C3.dat
[09:14:07.956] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C4.dat
[09:14:07.961] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C5.dat
[09:14:07.966] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C6.dat
[09:14:07.971] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C7.dat
[09:14:07.977] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C8.dat
[09:14:07.982] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C9.dat
[09:14:07.987] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C10.dat
[09:14:07.992] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C11.dat
[09:14:07.998] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C12.dat
[09:14:07.003] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C13.dat
[09:14:08.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C14.dat
[09:14:08.013] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C15.dat
[09:14:08.019] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//defaultMaskFile.dat
[09:14:08.033] INFO: enter test to run
[09:14:34.297] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:14:34.297] INFO: running: highrate
[09:14:34.301] INFO: ----------------------------------------------------------------------
[09:14:34.301] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:14:34.301] INFO: ----------------------------------------------------------------------
[09:14:34.301] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:14:34.301] INFO: edge/corner pixel THR is adjusted
[09:14:34.301] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:14:35.264] INFO: Collecting data for 1 seconds...
[09:14:36.268] INFO: Done with hot pixel readout
[09:14:40.485] INFO: PixTest:: pg_setup set to default.
[09:14:40.485] INFO: 0 hot pixels found in step 0
[09:14:40.490] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:14:40.574] INFO: PixTest::trimHotPixels() done
[09:14:40.575] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C0.dat
[09:14:40.586] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C1.dat
[09:14:40.592] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C2.dat
[09:14:40.597] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C3.dat
[09:14:40.602] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C4.dat
[09:14:40.607] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C5.dat
[09:14:40.613] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C6.dat
[09:14:40.618] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C7.dat
[09:14:40.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C8.dat
[09:14:40.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C9.dat
[09:14:40.633] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C10.dat
[09:14:40.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C11.dat
[09:14:40.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C12.dat
[09:14:40.649] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C13.dat
[09:14:40.655] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C14.dat
[09:14:40.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//trimParameters35_C15.dat
[09:14:40.665] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-36_FPIXTest-17C-FNAL-160823-1253-300V_2016-08-23_12h53m_1471974812/000_FPIXTest_p17//defaultMaskFile.dat
[09:14:40.675] INFO: enter test to run
[09:15:01.416] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:15:01.416] INFO: running: xray
[09:15:01.417] INFO: ----------------------------------------------------------------------
[09:15:01.417] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:15:01.418] INFO: ----------------------------------------------------------------------
[09:15:02.398] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:15:13.432] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[09:15:43.607] INFO: Resuming triggers.
[09:15:54.641] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[09:16:24.701] INFO: Resuming triggers.
[09:16:35.735] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[09:17:05.715] INFO: Resuming triggers.
[09:17:16.756] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[09:17:46.475] INFO: Resuming triggers.
[09:17:57.517] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[09:18:27.827] INFO: Resuming triggers.
[09:18:38.865] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[09:19:08.003] INFO: Resuming triggers.
[09:19:20.038] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[09:19:49.900] INFO: Resuming triggers.
[09:20:00.940] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[09:20:30.346] INFO: Resuming triggers.
[09:20:41.381] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[09:21:10.939] INFO: Resuming triggers.
[09:21:11.985] INFO: data taking finished, elapsed time: 100 seconds.
[09:21:15.143] INFO: PixTest:: pg_setup set to default.
[09:21:15.146] INFO: PixTestXray::doPhRun() done
[09:21:15.346] INFO: enter test to run
[09:22:27.485] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:22:27.485] INFO: running: xray
[09:22:27.486] INFO: ----------------------------------------------------------------------
[09:22:27.487] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:22:27.487] INFO: ----------------------------------------------------------------------
[09:22:28.468] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:22:34.697] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:23:04.770] INFO: Resuming triggers.
[09:23:10.003] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[09:23:41.074] INFO: Resuming triggers.
[09:23:47.306] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[09:24:17.370] INFO: Resuming triggers.
[09:24:23.606] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[09:24:53.260] INFO: Resuming triggers.
[09:24:59.494] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[09:25:29.808] INFO: Resuming triggers.
[09:25:36.041] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[09:26:05.944] INFO: Resuming triggers.
[09:26:12.176] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[09:26:42.223] INFO: Resuming triggers.
[09:26:48.461] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[09:27:18.527] INFO: Resuming triggers.
[09:27:24.760] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[09:27:55.605] INFO: Resuming triggers.
[09:28:01.843] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[09:28:32.778] INFO: Resuming triggers.
[09:28:39.018] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[09:29:10.067] INFO: Resuming triggers.
[09:29:16.308] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[09:29:46.673] INFO: Resuming triggers.
[09:29:52.913] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[09:30:24.255] INFO: Resuming triggers.
[09:30:30.495] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[09:31:01.813] INFO: Resuming triggers.
[09:31:08.055] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[09:31:38.985] INFO: Resuming triggers.
[09:31:45.226] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[09:32:15.394] INFO: Resuming triggers.
[09:32:15.972] INFO: data taking finished, elapsed time: 100 seconds.
[09:32:19.145] INFO: PixTest:: pg_setup set to default.
[09:32:19.149] INFO: PixTestXray::doPhRun() done
[09:32:19.297] INFO: enter test to run
[09:39:07.959] INFO: test: HighRate no parameter change
[09:39:07.959] INFO: running: highrate
[09:39:07.975] INFO: ----------------------------------------------------------------------
[09:39:07.975] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:39:07.975] INFO: ----------------------------------------------------------------------
[09:39:08.130] INFO: Expecting 768 events.
[09:39:09.264] INFO: 768 events read in total (418ms).
[09:39:09.265] INFO: Test took 1270ms.
[09:39:10.068] INFO: Expecting 41600 events.
[09:39:13.211] INFO: 41600 events read in total (2616ms).
[09:39:13.211] INFO: Test took 3920ms.
[09:39:13.247] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:13.969] INFO: Expecting 41600 events.
[09:39:17.224] INFO: 41600 events read in total (2729ms).
[09:39:17.225] INFO: Test took 3959ms.
[09:39:17.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:17.984] INFO: Expecting 41600 events.
[09:39:21.255] INFO: 41600 events read in total (2745ms).
[09:39:21.256] INFO: Test took 3975ms.
[09:39:21.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:22.012] INFO: Expecting 41600 events.
[09:39:25.238] INFO: 41600 events read in total (2699ms).
[09:39:25.239] INFO: Test took 3926ms.
[09:39:25.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:25.991] INFO: Expecting 41600 events.
[09:39:29.126] INFO: 41600 events read in total (2608ms).
[09:39:29.127] INFO: Test took 3830ms.
[09:39:29.164] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:29.881] INFO: Expecting 41600 events.
[09:39:33.076] INFO: 41600 events read in total (2668ms).
[09:39:33.077] INFO: Test took 3893ms.
[09:39:33.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:33.833] INFO: Expecting 41600 events.
[09:39:37.104] INFO: 41600 events read in total (2744ms).
[09:39:37.105] INFO: Test took 3974ms.
[09:39:37.142] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:37.859] INFO: Expecting 41600 events.
[09:39:41.126] INFO: 41600 events read in total (2741ms).
[09:39:41.127] INFO: Test took 3967ms.
[09:39:41.164] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:41.880] INFO: Expecting 41600 events.
[09:39:45.156] INFO: 41600 events read in total (2749ms).
[09:39:45.157] INFO: Test took 3973ms.
[09:39:45.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:45.907] INFO: Expecting 41600 events.
[09:39:49.293] INFO: 41600 events read in total (2859ms).
[09:39:49.294] INFO: Test took 4081ms.
[09:39:49.331] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:50.039] INFO: Expecting 41600 events.
[09:39:53.333] INFO: 41600 events read in total (2767ms).
[09:39:53.334] INFO: Test took 3984ms.
[09:39:53.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:54.075] INFO: Expecting 41600 events.
[09:39:57.232] INFO: 41600 events read in total (2630ms).
[09:39:57.233] INFO: Test took 3842ms.
[09:39:57.272] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:57.988] INFO: Expecting 41600 events.
[09:40:01.227] INFO: 41600 events read in total (2713ms).
[09:40:01.228] INFO: Test took 3937ms.
[09:40:01.266] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:01.981] INFO: Expecting 41600 events.
[09:40:05.190] INFO: 41600 events read in total (2682ms).
[09:40:05.191] INFO: Test took 3906ms.
[09:40:05.229] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:05.945] INFO: Expecting 41600 events.
[09:40:09.223] INFO: 41600 events read in total (2751ms).
[09:40:09.224] INFO: Test took 3976ms.
[09:40:09.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:09.980] INFO: Expecting 41600 events.
[09:40:13.255] INFO: 41600 events read in total (2748ms).
[09:40:13.256] INFO: Test took 3974ms.
[09:40:13.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:14.010] INFO: Expecting 41600 events.
[09:40:17.245] INFO: 41600 events read in total (2708ms).
[09:40:17.246] INFO: Test took 3934ms.
[09:40:17.284] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:17.997] INFO: Expecting 41600 events.
[09:40:21.223] INFO: 41600 events read in total (2699ms).
[09:40:21.224] INFO: Test took 3921ms.
[09:40:21.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:21.980] INFO: Expecting 41600 events.
[09:40:25.111] INFO: 41600 events read in total (2605ms).
[09:40:25.113] INFO: Test took 3832ms.
[09:40:25.151] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:25.869] INFO: Expecting 41600 events.
[09:40:28.945] INFO: 41600 events read in total (2549ms).
[09:40:28.946] INFO: Test took 3774ms.
[09:40:28.983] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:29.349] INFO: enter test to run
[09:40:42.358] INFO: test: HighRate no parameter change
[09:40:42.358] INFO: running: highrate
[09:40:42.359] INFO: ----------------------------------------------------------------------
[09:40:42.359] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:40:42.359] INFO: ----------------------------------------------------------------------
[09:40:42.982] INFO: Expecting 208000 events.
[09:40:54.925] INFO: 208000 events read in total (11416ms).
[09:40:54.928] INFO: Test took 12560ms.
[09:40:55.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:55.353] INFO: number of dead pixels (per ROC): 0 1 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:40:55.353] INFO: number of red-efficiency pixels: 91 55 101 186 192 165 179 125 118 170 126 118 112 82 30 25
[09:40:55.353] INFO: number of X-ray hits detected: 70252 47137 73756 118500 123359 127449 124267 86888 86539 117998 106823 92687 96406 58641 23684 26724
[09:40:55.353] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:40:55.353] INFO: number of Vcal hits detected: 207907 207896 207846 207806 207800 207829 207813 207873 207880 207828 207873 207879 207887 207917 207969 207975
[09:40:55.353] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[09:40:55.353] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[09:40:55.353] INFO: X-ray hit rate [MHz/cm2]: 20.6 13.8 21.6 34.7 36.2 37.4 36.4 25.5 25.4 34.6 31.3 27.2 28.3 17.2 6.9 7.8
[09:40:55.353] INFO: PixTestHighRate::doXPixelAlive() done
[09:40:55.398] INFO: PixTest:: pg_setup set to default.
[09:40:55.409] INFO: enter test to run
[09:41:11.854] INFO: test: HighRate no parameter change
[09:41:11.854] INFO: running: highrate
[09:41:11.855] INFO: ----------------------------------------------------------------------
[09:41:11.855] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:41:11.855] INFO: ----------------------------------------------------------------------
[09:41:12.472] INFO: Expecting 208000 events.
[09:41:26.333] INFO: 208000 events read in total (13334ms).
[09:41:26.339] INFO: Test took 14473ms.
[09:41:26.689] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:26.004] INFO: number of dead pixels (per ROC): 0 1 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:41:26.004] INFO: number of red-efficiency pixels: 267 193 374 637 740 634 518 400 349 498 406 443 388 252 57 73
[09:41:26.004] INFO: number of X-ray hits detected: 147190 99202 154926 248512 256498 266141 258576 182495 180991 245888 224961 194199 202592 122924 49369 56466
[09:41:26.004] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:41:26.004] INFO: number of Vcal hits detected: 207714 207748 207529 207276 207160 207282 207428 207531 207628 207442 207567 207514 207581 207730 207941 207927
[09:41:26.004] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.6 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[09:41:26.004] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.6 99.7 99.7 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[09:41:26.004] INFO: X-ray hit rate [MHz/cm2]: 43.1 29.1 45.4 72.8 75.2 78.0 75.8 53.5 53.0 72.1 65.9 56.9 59.4 36.0 14.5 16.6
[09:41:26.004] INFO: PixTestHighRate::doXPixelAlive() done
[09:41:27.049] INFO: PixTest:: pg_setup set to default.
[09:41:27.065] INFO: enter test to run
[09:41:43.013] INFO: test: HighRate no parameter change
[09:41:43.014] INFO: running: highrate
[09:41:43.015] INFO: ----------------------------------------------------------------------
[09:41:43.015] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:41:43.015] INFO: ----------------------------------------------------------------------
[09:41:43.633] INFO: Expecting 208000 events.
[09:41:59.828] INFO: 208000 events read in total (15668ms).
[09:41:59.836] INFO: Test took 16811ms.
[09:42:00.360] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:42:00.728] INFO: number of dead pixels (per ROC): 0 1 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:42:00.728] INFO: number of red-efficiency pixels: 545 321 819 1512 1633 1421 1266 919 776 1105 838 910 873 505 110 115
[09:42:00.728] INFO: number of X-ray hits detected: 217322 144808 227907 364675 377641 391779 382252 268091 266737 361885 330133 285846 298631 180737 73168 83438
[09:42:00.728] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:42:00.728] INFO: number of Vcal hits detected: 207357 207596 206797 205939 205703 206007 206345 206744 207031 206617 206999 206890 206955 207375 207888 207883
[09:42:00.728] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.5 99.1 99.0 99.1 99.3 99.5 99.6 99.4 99.6 99.5 99.5 99.7 99.9 99.9
[09:42:00.728] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.4 99.0 98.9 99.0 99.2 99.4 99.5 99.3 99.5 99.5 99.5 99.7 99.9 99.9
[09:42:00.728] INFO: X-ray hit rate [MHz/cm2]: 63.7 42.4 66.8 106.9 110.7 114.8 112.0 78.6 78.2 106.1 96.8 83.8 87.5 53.0 21.4 24.5
[09:42:00.728] INFO: PixTestHighRate::doXPixelAlive() done
[09:42:00.775] INFO: PixTest:: pg_setup set to default.
[09:42:00.789] INFO: enter test to run
[09:42:04.293] INFO: test: exit no parameter change
[09:42:04.647] QUIET: Connection to board 33 closed.
[09:42:04.662] INFO: pXar: this is the end, my friend
MoReWeb-v0.5.1-904-gd94b9f2 on branch master