[12:18:36.131] INFO: *** Welcome to pxar ***
[12:18:36.131] INFO: *** Today: 2016/04/20
[12:18:36.153] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:18:36.153] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//dacParameters35_C15.dat
[12:18:36.154] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:18:36.155] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//defaultMaskFile.dat
[12:18:36.165] INFO: MASKED Roc 0 col/row: 1 4
[12:18:36.165] INFO: MASKED Roc 0 col/row: 1 7
[12:18:36.165] INFO: MASKED Roc 3 col/row: 44 33
[12:18:36.165] INFO: MASKED Roc 4 col/row: 12 26
[12:18:36.165] INFO: MASKED Roc 6 col/row: 7 48
[12:18:36.165] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C15.dat
[12:18:36.165] INFO: masking Roc 0 col/row: 1 4
[12:18:36.165] INFO: masking Roc 0 col/row: 1 7
[12:18:36.190] INFO: masking Roc 3 col/row: 44 33
[12:18:36.194] INFO: masking Roc 4 col/row: 12 26
[12:18:36.203] INFO: masking Roc 6 col/row: 7 48
[12:18:36.244] INFO: clk: 4
[12:18:36.244] INFO: ctr: 4
[12:18:36.244] INFO: sda: 19
[12:18:36.244] INFO: tin: 9
[12:18:36.244] INFO: level: 15
[12:18:36.244] INFO: triggerdelay: 0
[12:18:36.244] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:18:36.244] INFO: Log level: INFO
[12:18:36.258] QUIET: Connection to board DTB_WREKRL opened.
[12:18:36.261] 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:
------------------------------------------------------
[12:18:36.264] INFO: RPC call hashes of host and DTB match: 398089610
[12:18:37.793] INFO: DUT info:
[12:18:37.793] INFO: The DUT currently contains the following objects:
[12:18:37.793] INFO: 2 TBM Cores tbm08c (2 ON)
[12:18:37.793] INFO: TBM Core alpha (0): 7 registers set
[12:18:37.793] INFO: TBM Core beta (1): 7 registers set
[12:18:37.793] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:18:37.793] INFO: ROC 0: 19 DACs set, Pixels: 2 masked, 0 active.
[12:18:37.793] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.793] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.793] INFO: ROC 3: 19 DACs set, Pixels: 1 masked, 0 active.
[12:18:37.793] INFO: ROC 4: 19 DACs set, Pixels: 1 masked, 0 active.
[12:18:37.793] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.794] INFO: ROC 6: 19 DACs set, Pixels: 1 masked, 0 active.
[12:18:37.794] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.794] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.794] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.794] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.794] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.794] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.794] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.794] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:37.794] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:18:38.197] INFO: enter 'restricted' command line mode
[12:18:38.197] INFO: enter test to run
[12:18:57.702] INFO: test: PixelAlive no parameter change
[12:18:57.702] INFO: running: pixelalive
[12:18:57.711] INFO: ----------------------------------------------------------------------
[12:18:57.711] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:18:57.711] INFO: ----------------------------------------------------------------------
[12:18:57.715] INFO: ROC 0 masking pixel 1/4
[12:18:57.715] INFO: ROC 0 masking pixel 1/7
[12:18:57.715] INFO: ROC 3 masking pixel 44/33
[12:18:57.715] INFO: ROC 4 masking pixel 12/26
[12:18:57.715] INFO: ROC 6 masking pixel 7/48
[12:18:58.031] INFO: Expecting 41600 events.
[12:19:02.369] INFO: 41600 events read in total (3619ms).
[12:19:02.534] INFO: Test took 4819ms.
[12:19:02.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:02.805] INFO: PixTestAlive::aliveTest() done
[12:19:02.805] INFO: number of dead pixels (per ROC): 2 0 0 1 1 0 1 0 0 3 0 0 0 0 0 0
[12:19:02.805] INFO: ROC 0 masking pixel 1/4
[12:19:02.805] INFO: ROC 0 masking pixel 1/7
[12:19:02.805] INFO: ROC 3 masking pixel 44/33
[12:19:02.806] INFO: ROC 4 masking pixel 12/26
[12:19:02.806] INFO: ROC 6 masking pixel 7/48
[12:19:02.836] INFO: enter test to run
[12:19:14.990] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:19:14.990] INFO: running: highrate
[12:19:14.990] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:19:15.152] INFO: ----------------------------------------------------------------------
[12:19:15.152] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:19:15.152] INFO: ----------------------------------------------------------------------
[12:19:15.152] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:19:15.152] INFO: edge/corner pixel THR is adjusted
[12:19:15.152] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:19:16.112] INFO: Collecting data for 5 seconds...
[12:19:21.129] INFO: Done with hot pixel readout
[12:19:30.978] INFO: PixTest:: pg_setup set to default.
[12:19:30.978] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:19:30.979] INFO: 13 hot pixels found in step 0
[12:19:31.971] INFO: Collecting data for 5 seconds...
[12:19:36.984] INFO: Done with hot pixel readout
[12:19:47.884] INFO: PixTest:: pg_setup set to default.
[12:19:47.884] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:19:47.884] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:19:47.885] INFO: 9 hot pixels found in step 1
[12:19:48.881] INFO: Collecting data for 5 seconds...
[12:19:53.897] INFO: Done with hot pixel readout
[12:20:06.208] INFO: PixTest:: pg_setup set to default.
[12:20:06.208] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:06.209] INFO: 8 hot pixels found in step 2
[12:20:07.205] INFO: Collecting data for 5 seconds...
[12:20:12.221] INFO: Done with hot pixel readout
[12:20:24.544] INFO: PixTest:: pg_setup set to default.
[12:20:24.544] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:24.544] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:24.545] INFO: 12 hot pixels found in step 3
[12:20:25.541] INFO: Collecting data for 5 seconds...
[12:20:30.559] INFO: Done with hot pixel readout
[12:20:42.923] INFO: PixTest:: pg_setup set to default.
[12:20:42.923] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:20:42.923] INFO: 6 hot pixels found in step 4
[12:20:43.921] INFO: Collecting data for 5 seconds...
[12:20:48.937] INFO: Done with hot pixel readout
[12:21:01.274] INFO: PixTest:: pg_setup set to default.
[12:21:01.274] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:01.274] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:01.275] INFO: 14 hot pixels found in step 5
[12:21:02.272] INFO: Collecting data for 5 seconds...
[12:21:07.288] INFO: Done with hot pixel readout
[12:21:19.599] INFO: PixTest:: pg_setup set to default.
[12:21:19.600] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:19.600] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:19.600] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:19.601] INFO: 13 hot pixels found in step 6
[12:21:20.599] INFO: Collecting data for 5 seconds...
[12:21:25.616] INFO: Done with hot pixel readout
[12:21:37.927] INFO: PixTest:: pg_setup set to default.
[12:21:37.927] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:37.927] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:37.927] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:37.927] INFO: 11 hot pixels found in step 7
[12:21:38.924] INFO: Collecting data for 5 seconds...
[12:21:43.941] INFO: Done with hot pixel readout
[12:21:56.322] INFO: PixTest:: pg_setup set to default.
[12:21:56.322] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:21:56.323] INFO: 8 hot pixels found in step 8
[12:21:57.320] INFO: Collecting data for 5 seconds...
[12:22:02.337] INFO: Done with hot pixel readout
[12:22:14.693] INFO: PixTest:: pg_setup set to default.
[12:22:14.693] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:14.694] INFO: 7 hot pixels found in step 9
[12:22:15.690] INFO: Collecting data for 5 seconds...
[12:22:20.707] INFO: Done with hot pixel readout
[12:22:33.054] INFO: PixTest:: pg_setup set to default.
[12:22:33.054] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:33.054] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:33.055] INFO: 9 hot pixels found in step 10
[12:22:34.052] INFO: Collecting data for 5 seconds...
[12:22:39.069] INFO: Done with hot pixel readout
[12:22:51.424] INFO: PixTest:: pg_setup set to default.
[12:22:51.424] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:22:51.425] INFO: 9 hot pixels found in step 11
[12:22:52.422] INFO: Collecting data for 5 seconds...
[12:22:57.438] INFO: Done with hot pixel readout
[12:23:09.798] INFO: PixTest:: pg_setup set to default.
[12:23:09.798] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:23:09.798] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:23:09.799] INFO: 10 hot pixels found in step 12
[12:23:10.795] INFO: Collecting data for 5 seconds...
[12:23:15.812] INFO: Done with hot pixel readout
[12:23:28.190] INFO: PixTest:: pg_setup set to default.
[12:23:28.190] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:23:28.190] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:23:28.191] INFO: 13 hot pixels found in step 13
[12:23:29.187] INFO: Collecting data for 5 seconds...
[12:23:34.204] INFO: Done with hot pixel readout
[12:23:46.550] INFO: PixTest:: pg_setup set to default.
[12:23:46.550] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:23:46.550] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:23:46.550] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:23:46.551] INFO: 16 hot pixels found in step 14
[12:23:46.591] INFO: 16 hot pixels could not be trimmed and have been masked.
[12:23:46.595] INFO: PixTest::trimHotPixels() done
[12:23:46.595] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C0.dat
[12:23:46.600] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C1.dat
[12:23:46.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C2.dat
[12:23:46.613] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C3.dat
[12:23:46.618] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C4.dat
[12:23:46.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C5.dat
[12:23:46.629] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C6.dat
[12:23:46.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C7.dat
[12:23:46.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C8.dat
[12:23:46.645] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C9.dat
[12:23:46.650] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C10.dat
[12:23:46.656] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C11.dat
[12:23:46.662] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C12.dat
[12:23:46.667] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C13.dat
[12:23:46.673] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C14.dat
[12:23:46.678] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C15.dat
[12:23:46.683] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//defaultMaskFile.dat
[12:23:46.694] INFO: enter test to run
[12:24:02.132] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:24:02.132] INFO: running: highrate
[12:24:02.137] INFO: ----------------------------------------------------------------------
[12:24:02.137] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:24:02.137] INFO: ----------------------------------------------------------------------
[12:24:02.137] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:24:02.137] INFO: edge/corner pixel THR is adjusted
[12:24:02.137] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:24:03.095] INFO: Collecting data for 1 seconds...
[12:24:04.099] INFO: Done with hot pixel readout
[12:24:08.349] INFO: PixTest:: pg_setup set to default.
[12:24:08.350] INFO: 0 hot pixels found in step 0
[12:24:08.356] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:24:08.431] INFO: PixTest::trimHotPixels() done
[12:24:08.432] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C0.dat
[12:24:08.443] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C1.dat
[12:24:08.448] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C2.dat
[12:24:08.453] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C3.dat
[12:24:08.459] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C4.dat
[12:24:08.464] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C5.dat
[12:24:08.469] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C6.dat
[12:24:08.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C7.dat
[12:24:08.480] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C8.dat
[12:24:08.485] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C9.dat
[12:24:08.491] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C10.dat
[12:24:08.496] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C11.dat
[12:24:08.501] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C12.dat
[12:24:08.507] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C13.dat
[12:24:08.512] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C14.dat
[12:24:08.518] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//trimParameters35_C15.dat
[12:24:08.523] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-4-18_FPIXTest-17C-FNAL-160415-0903_2016-04-15_09h03m_1460729024/000_FPIXTest_p17//defaultMaskFile.dat
[12:24:08.533] INFO: enter test to run
[12:24:50.364] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:24:50.364] INFO: running: xray
[12:24:50.365] INFO: ----------------------------------------------------------------------
[12:24:50.365] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:24:50.365] INFO: ----------------------------------------------------------------------
[12:24:50.368] INFO: ROC 0 masking pixel 1/4
[12:24:50.368] INFO: ROC 0 masking pixel 1/7
[12:24:50.368] INFO: ROC 3 masking pixel 44/33
[12:24:50.368] INFO: ROC 4 masking pixel 12/26
[12:24:50.368] INFO: ROC 6 masking pixel 7/48
[12:24:51.329] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:25:02.250] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:25:31.861] INFO: Resuming triggers.
[12:25:42.778] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:26:12.338] INFO: Resuming triggers.
[12:26:23.254] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:26:52.805] INFO: Resuming triggers.
[12:27:03.725] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:27:33.285] INFO: Resuming triggers.
[12:27:44.201] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:28:13.726] INFO: Resuming triggers.
[12:28:24.645] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:28:54.059] INFO: Resuming triggers.
[12:29:04.975] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:29:33.937] INFO: Resuming triggers.
[12:29:44.853] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:30:12.517] INFO: Resuming triggers.
[12:30:23.430] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[12:30:52.967] INFO: Resuming triggers.
[12:30:55.039] INFO: data taking finished, elapsed time: 100 seconds.
[12:31:00.997] INFO: PixTest:: pg_setup set to default.
[12:31:00.000] INFO: PixTestXray::doPhRun() done
[12:31:01.140] INFO: enter test to run
[12:31:13.921] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:31:13.921] INFO: running: xray
[12:31:13.922] INFO: ----------------------------------------------------------------------
[12:31:13.922] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:31:13.922] INFO: ----------------------------------------------------------------------
[12:31:13.938] INFO: ROC 0 masking pixel 1/4
[12:31:13.938] INFO: ROC 0 masking pixel 1/7
[12:31:13.938] INFO: ROC 3 masking pixel 44/33
[12:31:13.938] INFO: ROC 4 masking pixel 12/26
[12:31:13.938] INFO: ROC 6 masking pixel 7/48
[12:31:14.897] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:31:21.018] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:31:51.119] INFO: Resuming triggers.
[12:31:57.239] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:32:27.270] INFO: Resuming triggers.
[12:32:33.387] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[12:33:03.451] INFO: Resuming triggers.
[12:33:09.573] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[12:33:39.651] INFO: Resuming triggers.
[12:33:45.769] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[12:34:15.824] INFO: Resuming triggers.
[12:34:21.943] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[12:34:52.046] INFO: Resuming triggers.
[12:34:58.169] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[12:35:28.270] INFO: Resuming triggers.
[12:35:34.389] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[12:36:04.382] INFO: Resuming triggers.
[12:36:10.500] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:36:40.627] INFO: Resuming triggers.
[12:36:46.751] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[12:37:16.856] INFO: Resuming triggers.
[12:37:22.980] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:37:53.037] INFO: Resuming triggers.
[12:37:59.157] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:38:29.306] INFO: Resuming triggers.
[12:38:35.429] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:39:05.490] INFO: Resuming triggers.
[12:39:11.611] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[12:39:41.945] INFO: Resuming triggers.
[12:39:48.064] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:40:16.695] INFO: Resuming triggers.
[12:40:22.812] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[12:40:52.804] INFO: Resuming triggers.
[12:40:55.202] INFO: data taking finished, elapsed time: 100 seconds.
[12:41:07.280] INFO: PixTest:: pg_setup set to default.
[12:41:07.284] INFO: PixTestXray::doPhRun() done
[12:41:07.434] INFO: enter test to run
[12:41:21.316] INFO: test: HighRate no parameter change
[12:41:21.316] INFO: running: highrate
[12:41:21.334] INFO: ----------------------------------------------------------------------
[12:41:21.334] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:41:21.334] INFO: ----------------------------------------------------------------------
[12:41:21.498] INFO: Expecting 768 events.
[12:41:22.631] INFO: 768 events read in total (418ms).
[12:41:22.632] INFO: Test took 1269ms.
[12:41:22.637] INFO: ROC 0 masking pixel 1/4
[12:41:22.637] INFO: ROC 0 masking pixel 1/7
[12:41:22.637] INFO: ROC 3 masking pixel 44/33
[12:41:22.637] INFO: ROC 4 masking pixel 12/26
[12:41:22.637] INFO: ROC 6 masking pixel 7/48
[12:41:23.435] INFO: Expecting 41600 events.
[12:41:26.576] INFO: 41600 events read in total (2614ms).
[12:41:26.577] INFO: Test took 3937ms.
[12:41:26.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:27.334] INFO: Expecting 41600 events.
[12:41:30.535] INFO: 41600 events read in total (2673ms).
[12:41:30.536] INFO: Test took 3900ms.
[12:41:30.575] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:31.291] INFO: Expecting 41600 events.
[12:41:34.553] INFO: 41600 events read in total (2735ms).
[12:41:34.555] INFO: Test took 3961ms.
[12:41:34.593] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:35.307] INFO: Expecting 41600 events.
[12:41:38.598] INFO: 41600 events read in total (2764ms).
[12:41:38.599] INFO: Test took 3986ms.
[12:41:38.638] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:39.350] INFO: Expecting 41600 events.
[12:41:42.645] INFO: 41600 events read in total (2768ms).
[12:41:42.646] INFO: Test took 3989ms.
[12:41:42.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:43.402] INFO: Expecting 41600 events.
[12:41:46.687] INFO: 41600 events read in total (2758ms).
[12:41:46.689] INFO: Test took 3983ms.
[12:41:46.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:47.441] INFO: Expecting 41600 events.
[12:41:50.732] INFO: 41600 events read in total (2764ms).
[12:41:50.733] INFO: Test took 3984ms.
[12:41:50.772] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:51.487] INFO: Expecting 41600 events.
[12:41:54.799] INFO: 41600 events read in total (2785ms).
[12:41:54.800] INFO: Test took 4008ms.
[12:41:54.839] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:55.553] INFO: Expecting 41600 events.
[12:41:58.835] INFO: 41600 events read in total (2755ms).
[12:41:58.836] INFO: Test took 3978ms.
[12:41:58.876] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:59.593] INFO: Expecting 41600 events.
[12:42:02.873] INFO: 41600 events read in total (2753ms).
[12:42:02.874] INFO: Test took 3978ms.
[12:42:02.913] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:03.624] INFO: Expecting 41600 events.
[12:42:06.931] INFO: 41600 events read in total (2780ms).
[12:42:06.932] INFO: Test took 4000ms.
[12:42:06.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:07.683] INFO: Expecting 41600 events.
[12:42:10.974] INFO: 41600 events read in total (2764ms).
[12:42:10.975] INFO: Test took 3982ms.
[12:42:11.014] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:11.728] INFO: Expecting 41600 events.
[12:42:15.019] INFO: 41600 events read in total (2764ms).
[12:42:15.020] INFO: Test took 3986ms.
[12:42:15.059] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:15.772] INFO: Expecting 41600 events.
[12:42:19.076] INFO: 41600 events read in total (2777ms).
[12:42:19.077] INFO: Test took 3999ms.
[12:42:19.116] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:19.831] INFO: Expecting 41600 events.
[12:42:23.143] INFO: 41600 events read in total (2785ms).
[12:42:23.144] INFO: Test took 4009ms.
[12:42:23.184] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:23.896] INFO: Expecting 41600 events.
[12:42:27.200] INFO: 41600 events read in total (2777ms).
[12:42:27.201] INFO: Test took 3997ms.
[12:42:27.240] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:27.955] INFO: Expecting 41600 events.
[12:42:31.245] INFO: 41600 events read in total (2763ms).
[12:42:31.246] INFO: Test took 3986ms.
[12:42:31.285] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:31.001] INFO: Expecting 41600 events.
[12:42:35.288] INFO: 41600 events read in total (2761ms).
[12:42:35.289] INFO: Test took 3984ms.
[12:42:35.327] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:36.042] INFO: Expecting 41600 events.
[12:42:39.318] INFO: 41600 events read in total (2750ms).
[12:42:39.319] INFO: Test took 3971ms.
[12:42:39.358] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:40.069] INFO: Expecting 41600 events.
[12:42:43.193] INFO: 41600 events read in total (2598ms).
[12:42:43.194] INFO: Test took 3816ms.
[12:42:43.234] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:43.595] INFO: enter test to run
[12:42:46.060] INFO: test: HighRate no parameter change
[12:42:46.060] INFO: running: highrate
[12:42:46.061] INFO: ----------------------------------------------------------------------
[12:42:46.061] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:42:46.061] INFO: ----------------------------------------------------------------------
[12:42:46.067] INFO: ROC 0 masking pixel 1/4
[12:42:46.067] INFO: ROC 0 masking pixel 1/7
[12:42:46.067] INFO: ROC 3 masking pixel 44/33
[12:42:46.067] INFO: ROC 4 masking pixel 12/26
[12:42:46.067] INFO: ROC 6 masking pixel 7/48
[12:42:46.667] INFO: Expecting 208000 events.
[12:42:58.932] INFO: 208000 events read in total (11739ms).
[12:42:58.935] INFO: Test took 12867ms.
[12:42:59.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:59.368] INFO: number of dead pixels (per ROC): 2 0 0 1 1 0 1 0 0 3 0 0 0 0 0 0
[12:42:59.368] INFO: number of red-efficiency pixels: 75 54 110 153 206 146 197 121 117 188 169 147 130 84 27 45
[12:42:59.368] INFO: number of X-ray hits detected: 74474 48543 75030 121013 128893 131536 131099 95655 96050 123877 122359 107793 111873 64114 25294 28860
[12:42:59.368] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:42:59.368] INFO: number of Vcal hits detected: 207822 207945 207888 207794 207740 207852 207750 207878 207881 207661 207828 207845 207869 207916 207973 207955
[12:42:59.368] 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 99.9 100.0 100.0 100.0
[12:42:59.368] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0 100.0
[12:42:59.368] INFO: X-ray hit rate [MHz/cm2]: 21.8 14.2 22.0 35.5 37.8 38.6 38.4 28.0 28.2 36.3 35.9 31.6 32.8 18.8 7.4 8.5
[12:42:59.368] INFO: PixTestHighRate::doXPixelAlive() done
[12:42:59.413] INFO: PixTest:: pg_setup set to default.
[12:42:59.423] INFO: enter test to run
[12:43:11.771] INFO: test: HighRate no parameter change
[12:43:11.772] INFO: running: highrate
[12:43:11.773] INFO: ----------------------------------------------------------------------
[12:43:11.773] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:43:11.773] INFO: ----------------------------------------------------------------------
[12:43:11.781] INFO: ROC 0 masking pixel 1/4
[12:43:11.781] INFO: ROC 0 masking pixel 1/7
[12:43:11.781] INFO: ROC 3 masking pixel 44/33
[12:43:11.781] INFO: ROC 4 masking pixel 12/26
[12:43:11.781] INFO: ROC 6 masking pixel 7/48
[12:43:12.391] INFO: Expecting 208000 events.
[12:43:26.542] INFO: 208000 events read in total (13624ms).
[12:43:26.548] INFO: Test took 14767ms.
[12:43:26.884] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:27.197] INFO: number of dead pixels (per ROC): 2 0 0 1 1 0 1 0 0 3 0 0 0 0 0 0
[12:43:27.197] INFO: number of red-efficiency pixels: 204 143 331 569 642 485 686 396 341 526 436 398 389 258 82 47
[12:43:27.197] INFO: number of X-ray hits detected: 144814 94186 147540 237735 250929 256680 257403 186713 187852 242486 240207 210345 219253 125614 50733 56694
[12:43:27.197] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:43:27.197] INFO: number of Vcal hits detected: 207686 207850 207631 207313 207242 207474 207173 207557 207631 207273 207521 207573 207593 207720 207916 207953
[12:43:27.197] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.8 99.7 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[12:43:27.197] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.7 99.6 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[12:43:27.197] INFO: X-ray hit rate [MHz/cm2]: 42.4 27.6 43.2 69.7 73.5 75.2 75.4 54.7 55.1 71.1 70.4 61.7 64.3 36.8 14.9 16.6
[12:43:27.197] INFO: PixTestHighRate::doXPixelAlive() done
[12:43:27.243] INFO: PixTest:: pg_setup set to default.
[12:43:27.260] INFO: enter test to run
[12:43:43.259] INFO: test: HighRate no parameter change
[12:43:43.259] INFO: running: highrate
[12:43:43.260] INFO: ----------------------------------------------------------------------
[12:43:43.260] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:43:43.260] INFO: ----------------------------------------------------------------------
[12:43:43.268] INFO: ROC 0 masking pixel 1/4
[12:43:43.268] INFO: ROC 0 masking pixel 1/7
[12:43:43.268] INFO: ROC 3 masking pixel 44/33
[12:43:43.268] INFO: ROC 4 masking pixel 12/26
[12:43:43.268] INFO: ROC 6 masking pixel 7/48
[12:43:43.879] INFO: Expecting 208000 events.
[12:44:00.337] INFO: 208000 events read in total (15931ms).
[12:44:00.345] INFO: Test took 17076ms.
[12:44:00.859] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:01.228] INFO: number of dead pixels (per ROC): 2 0 0 1 1 0 1 0 0 3 0 0 0 0 0 0
[12:44:01.228] INFO: number of red-efficiency pixels: 410 329 738 1300 1557 1159 1585 896 806 1290 1015 999 790 582 115 129
[12:44:01.228] INFO: number of X-ray hits detected: 219177 143410 224430 360140 381229 387416 389122 283864 285844 366946 363679 319835 333485 191514 76544 86470
[12:44:01.228] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:44:01.228] INFO: number of Vcal hits detected: 207433 207640 206981 205985 205817 206501 205774 206854 207040 206188 206734 206741 207070 207256 207880 207868
[12:44:01.228] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.6 99.1 99.1 99.4 99.0 99.5 99.6 99.3 99.4 99.5 99.6 99.7 99.9 99.9
[12:44:01.228] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.0 99.0 99.3 98.9 99.4 99.5 99.1 99.4 99.4 99.6 99.6 99.9 99.9
[12:44:01.229] INFO: X-ray hit rate [MHz/cm2]: 64.2 42.0 65.8 105.6 111.7 113.6 114.1 83.2 83.8 107.6 106.6 93.7 97.7 56.1 22.4 25.3
[12:44:01.229] INFO: PixTestHighRate::doXPixelAlive() done
[12:44:01.277] INFO: PixTest:: pg_setup set to default.
[12:44:01.294] INFO: enter test to run
[12:44:03.107] INFO: test: exit no parameter change
[12:44:03.480] QUIET: Connection to board 33 closed.
[12:44:03.481] INFO: pXar: this is the end, my friend