[09:34:55.509] INFO: *** Welcome to pxar ***
[09:34:55.509] INFO: *** Today: 2016/09/02
[09:34:56.307] INFO: *** Version: v1.9.0-818-g96727
[09:34:56.307] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//dacParameters35_C15.dat
[09:34:56.365] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:34:56.365] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//defaultMaskFile.dat
[09:34:56.371] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C15.dat
[09:34:56.497] INFO: clk: 4
[09:34:56.498] INFO: ctr: 4
[09:34:56.498] INFO: sda: 19
[09:34:56.498] INFO: tin: 9
[09:34:56.498] INFO: level: 15
[09:34:56.498] INFO: triggerdelay: 0
[09:34:56.498] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[09:34:56.498] INFO: Log level: INFO
[09:34:56.514] QUIET: Connection to board DTB_WREKRL opened.
[09:34:56.517] 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:34:56.520] INFO: RPC call hashes of host and DTB match: 398089610
[09:34:58.076] INFO: DUT info:
[09:34:58.076] INFO: The DUT currently contains the following objects:
[09:34:58.076] INFO: 2 TBM Cores tbm08c (2 ON)
[09:34:58.076] INFO: TBM Core alpha (0): 7 registers set
[09:34:58.076] INFO: TBM Core beta (1): 7 registers set
[09:34:58.076] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:34:58.076] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.076] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.076] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.076] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.076] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.077] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:34:58.509] INFO: enter 'restricted' command line mode
[09:34:58.509] INFO: enter test to run
[09:35:05.266] INFO: test: PixelAlive no parameter change
[09:35:05.267] INFO: running: pixelalive
[09:35:05.329] INFO: ----------------------------------------------------------------------
[09:35:05.329] 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:35:05.329] INFO: ----------------------------------------------------------------------
[09:35:05.647] INFO: Expecting 41600 events.
[09:35:10.013] INFO: 41600 events read in total (3648ms).
[09:35:10.181] INFO: Test took 4850ms.
[09:35:10.191] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:10.725] INFO: PixTestAlive::aliveTest() done
[09:35:10.725] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[09:35:10.903] INFO: enter test to run
[09:35:34.899] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:35:34.899] INFO: running: highrate
[09:35:34.917] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:35:35.179] INFO: ----------------------------------------------------------------------
[09:35:35.179] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:35:35.179] INFO: ----------------------------------------------------------------------
[09:35:35.179] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:35:35.179] INFO: edge/corner pixel THR is adjusted
[09:35:35.179] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:35:36.137] INFO: Collecting data for 5 seconds...
[09:35:41.155] INFO: Done with hot pixel readout
[09:35:52.942] INFO: PixTest:: pg_setup set to default.
[09:35:52.942] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:35:52.942] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:35:52.967] INFO: 68 hot pixels found in step 0
[09:35:53.959] INFO: Collecting data for 5 seconds...
[09:35:58.977] INFO: Done with hot pixel readout
[09:36:10.905] INFO: PixTest:: pg_setup set to default.
[09:36:10.906] INFO: 67 hot pixels found in step 1
[09:36:11.906] INFO: Collecting data for 5 seconds...
[09:36:16.926] INFO: Done with hot pixel readout
[09:36:28.829] INFO: PixTest:: pg_setup set to default.
[09:36:28.829] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:36:28.829] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:36:28.829] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:36:28.830] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:36:28.830] INFO: 75 hot pixels found in step 2
[09:36:29.825] INFO: Collecting data for 5 seconds...
[09:36:34.846] INFO: Done with hot pixel readout
[09:36:46.690] INFO: PixTest:: pg_setup set to default.
[09:36:46.690] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:36:46.691] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:36:46.691] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:36:46.691] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:36:46.691] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:36:46.692] INFO: 69 hot pixels found in step 3
[09:36:47.687] INFO: Collecting data for 5 seconds...
[09:36:52.706] INFO: Done with hot pixel readout
[09:37:04.654] INFO: PixTest:: pg_setup set to default.
[09:37:04.654] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:04.655] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:04.655] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:04.656] INFO: 64 hot pixels found in step 4
[09:37:05.652] INFO: Collecting data for 5 seconds...
[09:37:10.671] INFO: Done with hot pixel readout
[09:37:22.885] INFO: PixTest:: pg_setup set to default.
[09:37:22.885] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:22.885] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:22.885] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:22.886] INFO: 55 hot pixels found in step 5
[09:37:23.883] INFO: Collecting data for 5 seconds...
[09:37:28.903] INFO: Done with hot pixel readout
[09:37:41.041] INFO: PixTest:: pg_setup set to default.
[09:37:41.041] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:41.041] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:41.042] INFO: 52 hot pixels found in step 6
[09:37:42.038] INFO: Collecting data for 5 seconds...
[09:37:47.057] INFO: Done with hot pixel readout
[09:37:59.387] INFO: PixTest:: pg_setup set to default.
[09:37:59.387] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:59.387] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:59.387] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:59.387] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:59.387] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:37:59.388] INFO: 40 hot pixels found in step 7
[09:38:00.383] INFO: Collecting data for 5 seconds...
[09:38:05.407] INFO: Done with hot pixel readout
[09:38:17.458] INFO: PixTest:: pg_setup set to default.
[09:38:17.458] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:17.459] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:17.459] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:17.459] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:17.459] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:17.459] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:17.459] INFO: 49 hot pixels found in step 8
[09:38:18.455] INFO: Collecting data for 5 seconds...
[09:38:23.475] INFO: Done with hot pixel readout
[09:38:35.655] INFO: PixTest:: pg_setup set to default.
[09:38:35.655] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:35.655] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:35.655] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:35.656] INFO: 39 hot pixels found in step 9
[09:38:36.651] INFO: Collecting data for 5 seconds...
[09:38:41.670] INFO: Done with hot pixel readout
[09:38:53.701] INFO: PixTest:: pg_setup set to default.
[09:38:53.701] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:53.701] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:53.701] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:53.702] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:38:53.702] INFO: 41 hot pixels found in step 10
[09:38:54.698] INFO: Collecting data for 5 seconds...
[09:38:59.718] INFO: Done with hot pixel readout
[09:39:11.819] INFO: PixTest:: pg_setup set to default.
[09:39:11.819] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:11.819] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:11.819] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:11.819] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:11.819] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:11.819] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:11.820] INFO: 46 hot pixels found in step 11
[09:39:12.815] INFO: Collecting data for 5 seconds...
[09:39:17.832] INFO: Done with hot pixel readout
[09:39:29.888] INFO: PixTest:: pg_setup set to default.
[09:39:29.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:29.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:29.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:29.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:29.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:29.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:29.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:29.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:29.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:29.888] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:29.889] INFO: 48 hot pixels found in step 12
[09:39:30.884] INFO: Collecting data for 5 seconds...
[09:39:35.901] INFO: Done with hot pixel readout
[09:39:47.950] INFO: PixTest:: pg_setup set to default.
[09:39:47.950] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:47.950] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:47.950] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:47.950] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:47.950] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:47.951] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:39:47.951] INFO: 33 hot pixels found in step 13
[09:39:48.946] INFO: Collecting data for 5 seconds...
[09:39:53.963] INFO: Done with hot pixel readout
[09:40:05.971] INFO: PixTest:: pg_setup set to default.
[09:40:05.971] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:40:05.972] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:40:05.972] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:40:05.972] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:40:05.972] INFO: 41 hot pixels found in step 14
[09:40:06.011] INFO: 41 hot pixels could not be trimmed and have been masked.
[09:40:06.029] INFO: PixTest::trimHotPixels() done
[09:40:06.043] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C0.dat
[09:40:06.052] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C1.dat
[09:40:06.058] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C2.dat
[09:40:06.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C3.dat
[09:40:06.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C4.dat
[09:40:06.074] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C5.dat
[09:40:06.079] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C6.dat
[09:40:06.084] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C7.dat
[09:40:06.090] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C8.dat
[09:40:06.095] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C9.dat
[09:40:06.100] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C10.dat
[09:40:06.105] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C11.dat
[09:40:06.111] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C12.dat
[09:40:06.116] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C13.dat
[09:40:06.121] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C14.dat
[09:40:06.127] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C15.dat
[09:40:06.132] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//defaultMaskFile.dat
[09:40:06.148] INFO: enter test to run
[09:40:47.784] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:40:47.784] INFO: running: highrate
[09:40:47.789] INFO: ----------------------------------------------------------------------
[09:40:47.789] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:40:47.789] INFO: ----------------------------------------------------------------------
[09:40:47.789] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:40:47.789] INFO: edge/corner pixel THR is adjusted
[09:40:47.789] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:40:48.746] INFO: Collecting data for 1 seconds...
[09:40:49.750] INFO: Done with hot pixel readout
[09:40:53.941] INFO: PixTest:: pg_setup set to default.
[09:40:53.942] INFO: 0 hot pixels found in step 0
[09:40:53.947] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:40:54.031] INFO: PixTest::trimHotPixels() done
[09:40:54.032] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C0.dat
[09:40:54.041] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C1.dat
[09:40:54.046] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C2.dat
[09:40:54.051] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C3.dat
[09:40:54.056] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C4.dat
[09:40:54.062] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C5.dat
[09:40:54.067] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C6.dat
[09:40:54.072] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C7.dat
[09:40:54.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C8.dat
[09:40:54.082] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C9.dat
[09:40:54.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C10.dat
[09:40:54.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C11.dat
[09:40:54.098] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C12.dat
[09:40:54.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C13.dat
[09:40:54.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C14.dat
[09:40:54.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//trimParameters35_C15.dat
[09:40:54.119] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-44_FPIXTest-17C-FNAL-160901-1223-300V_2016-09-01_12h23m_1472750627/000_FPIXTest_p17//defaultMaskFile.dat
[09:40:54.135] INFO: enter test to run
[09:41:34.368] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:41:34.368] INFO: running: xray
[09:41:34.369] INFO: ----------------------------------------------------------------------
[09:41:34.369] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:41:34.369] INFO: ----------------------------------------------------------------------
[09:41:35.347] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:41:46.623] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:42:16.056] INFO: Resuming triggers.
[09:42:27.336] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[09:42:57.042] INFO: Resuming triggers.
[09:43:08.321] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[09:43:37.879] INFO: Resuming triggers.
[09:43:49.154] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[09:44:18.719] INFO: Resuming triggers.
[09:44:29.999] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[09:44:59.465] INFO: Resuming triggers.
[09:45:10.746] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[09:45:40.306] INFO: Resuming triggers.
[09:45:51.584] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[09:46:21.087] INFO: Resuming triggers.
[09:46:32.363] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[09:47:01.969] INFO: Resuming triggers.
[09:47:12.089] INFO: data taking finished, elapsed time: 100 seconds.
[09:47:38.815] INFO: PixTest:: pg_setup set to default.
[09:47:38.818] INFO: PixTestXray::doPhRun() done
[09:47:39.051] INFO: enter test to run
[09:48:07.709] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:48:07.709] INFO: running: xray
[09:48:07.710] INFO: ----------------------------------------------------------------------
[09:48:07.710] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:48:07.710] INFO: ----------------------------------------------------------------------
[09:48:08.682] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:48:14.955] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:48:45.366] INFO: Resuming triggers.
[09:48:51.647] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[09:49:22.420] INFO: Resuming triggers.
[09:49:28.701] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[09:50:00.531] INFO: Resuming triggers.
[09:50:06.804] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[09:50:38.190] INFO: Resuming triggers.
[09:50:44.469] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[09:51:16.215] INFO: Resuming triggers.
[09:51:22.490] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[09:51:52.749] INFO: Resuming triggers.
[09:51:59.031] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[09:52:29.312] INFO: Resuming triggers.
[09:52:35.589] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[09:53:05.790] INFO: Resuming triggers.
[09:53:12.072] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[09:53:42.111] INFO: Resuming triggers.
[09:53:48.391] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[09:54:18.600] INFO: Resuming triggers.
[09:54:24.879] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[09:54:55.047] INFO: Resuming triggers.
[09:55:01.324] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[09:55:31.534] INFO: Resuming triggers.
[09:55:37.816] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[09:56:07.006] INFO: Resuming triggers.
[09:56:14.290] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[09:56:44.659] INFO: Resuming triggers.
[09:56:50.940] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[09:57:21.224] INFO: Resuming triggers.
[09:57:27.400] INFO: data taking finished, elapsed time: 100 seconds.
[09:57:57.347] INFO: PixTest:: pg_setup set to default.
[09:57:57.351] INFO: PixTestXray::doPhRun() done
[09:57:57.529] INFO: enter test to run
[09:58:34.833] INFO: test: HighRate no parameter change
[09:58:34.833] INFO: running: highrate
[09:58:34.846] INFO: ----------------------------------------------------------------------
[09:58:34.846] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:58:34.846] INFO: ----------------------------------------------------------------------
[09:58:34.001] INFO: Expecting 768 events.
[09:58:36.135] INFO: 768 events read in total (419ms).
[09:58:36.135] INFO: Test took 1269ms.
[09:58:36.938] INFO: Expecting 41600 events.
[09:58:39.005] INFO: 41600 events read in total (2540ms).
[09:58:39.006] INFO: Test took 3845ms.
[09:58:40.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:40.766] INFO: Expecting 41600 events.
[09:58:43.971] INFO: 41600 events read in total (2678ms).
[09:58:43.972] INFO: Test took 3913ms.
[09:58:44.007] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:44.731] INFO: Expecting 41600 events.
[09:58:47.976] INFO: 41600 events read in total (2718ms).
[09:58:47.977] INFO: Test took 3952ms.
[09:58:48.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:48.731] INFO: Expecting 41600 events.
[09:58:51.977] INFO: 41600 events read in total (2719ms).
[09:58:51.978] INFO: Test took 3948ms.
[09:58:52.014] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:52.736] INFO: Expecting 41600 events.
[09:58:55.982] INFO: 41600 events read in total (2719ms).
[09:58:55.983] INFO: Test took 3951ms.
[09:58:56.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:56.740] INFO: Expecting 41600 events.
[09:58:59.000] INFO: 41600 events read in total (2733ms).
[09:58:59.001] INFO: Test took 3963ms.
[09:59:00.036] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:00.754] INFO: Expecting 41600 events.
[09:59:04.022] INFO: 41600 events read in total (2742ms).
[09:59:04.023] INFO: Test took 3969ms.
[09:59:04.060] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:04.780] INFO: Expecting 41600 events.
[09:59:08.032] INFO: 41600 events read in total (2725ms).
[09:59:08.033] INFO: Test took 3955ms.
[09:59:08.068] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:08.790] INFO: Expecting 41600 events.
[09:59:12.053] INFO: 41600 events read in total (2736ms).
[09:59:12.054] INFO: Test took 3966ms.
[09:59:12.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:12.812] INFO: Expecting 41600 events.
[09:59:16.081] INFO: 41600 events read in total (2742ms).
[09:59:16.082] INFO: Test took 3973ms.
[09:59:16.118] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:16.837] INFO: Expecting 41600 events.
[09:59:20.107] INFO: 41600 events read in total (2743ms).
[09:59:20.107] INFO: Test took 3971ms.
[09:59:20.144] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:20.864] INFO: Expecting 41600 events.
[09:59:24.126] INFO: 41600 events read in total (2735ms).
[09:59:24.127] INFO: Test took 3964ms.
[09:59:24.164] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:24.884] INFO: Expecting 41600 events.
[09:59:28.165] INFO: 41600 events read in total (2755ms).
[09:59:28.166] INFO: Test took 3983ms.
[09:59:28.204] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:28.918] INFO: Expecting 41600 events.
[09:59:32.173] INFO: 41600 events read in total (2728ms).
[09:59:32.174] INFO: Test took 3952ms.
[09:59:32.211] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:32.927] INFO: Expecting 41600 events.
[09:59:36.157] INFO: 41600 events read in total (2704ms).
[09:59:36.158] INFO: Test took 3928ms.
[09:59:36.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:36.910] INFO: Expecting 41600 events.
[09:59:40.168] INFO: 41600 events read in total (2731ms).
[09:59:40.169] INFO: Test took 3956ms.
[09:59:40.206] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:40.924] INFO: Expecting 41600 events.
[09:59:44.205] INFO: 41600 events read in total (2754ms).
[09:59:44.206] INFO: Test took 3982ms.
[09:59:44.243] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:44.957] INFO: Expecting 41600 events.
[09:59:48.184] INFO: 41600 events read in total (2701ms).
[09:59:48.185] INFO: Test took 3922ms.
[09:59:48.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:48.943] INFO: Expecting 41600 events.
[09:59:52.232] INFO: 41600 events read in total (2762ms).
[09:59:52.233] INFO: Test took 3993ms.
[09:59:52.273] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:52.984] INFO: Expecting 41600 events.
[09:59:56.177] INFO: 41600 events read in total (2666ms).
[09:59:56.178] INFO: Test took 3885ms.
[09:59:56.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:56.560] INFO: enter test to run
[10:00:50.384] INFO: test: HighRate no parameter change
[10:00:50.384] INFO: running: highrate
[10:00:50.386] INFO: ----------------------------------------------------------------------
[10:00:50.386] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:00:50.386] INFO: ----------------------------------------------------------------------
[10:00:51.053] INFO: Expecting 208000 events.
[10:01:03.111] INFO: 208000 events read in total (11531ms).
[10:01:03.114] INFO: Test took 12720ms.
[10:01:03.273] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:03.530] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[10:01:03.530] INFO: number of red-efficiency pixels: 92 68 101 147 172 173 159 107 89 143 130 111 119 82 29 21
[10:01:03.530] INFO: number of X-ray hits detected: 79151 50704 73337 112923 119188 121684 121905 81821 75212 106491 107014 88347 95082 58517 23156 24405
[10:01:03.530] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:01:03.530] INFO: number of Vcal hits detected: 207906 207932 207897 207849 207823 207821 207817 207890 207908 207857 207869 207884 207881 207918 207970 207930
[10:01:03.530] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:01:03.530] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:01:03.530] INFO: X-ray hit rate [MHz/cm2]: 23.2 14.9 21.5 33.1 34.9 35.7 35.7 24.0 22.0 31.2 31.4 25.9 27.9 17.2 6.8 7.2
[10:01:03.530] INFO: PixTestHighRate::doXPixelAlive() done
[10:01:03.576] INFO: PixTest:: pg_setup set to default.
[10:01:03.591] INFO: enter test to run
[10:01:19.256] INFO: test: HighRate no parameter change
[10:01:19.256] INFO: running: highrate
[10:01:19.257] INFO: ----------------------------------------------------------------------
[10:01:19.257] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:01:19.257] INFO: ----------------------------------------------------------------------
[10:01:19.880] INFO: Expecting 208000 events.
[10:01:36.200] INFO: 208000 events read in total (15793ms).
[10:01:36.208] INFO: Test took 16942ms.
[10:01:36.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:37.096] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[10:01:37.096] INFO: number of red-efficiency pixels: 615 421 700 1432 1510 1590 1242 666 670 1278 1018 731 974 544 105 108
[10:01:37.096] INFO: number of X-ray hits detected: 250465 159378 231834 359597 378513 382745 385903 260080 241351 338593 339735 280859 302142 185582 73391 79086
[10:01:37.096] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:01:37.096] INFO: number of Vcal hits detected: 207207 207488 206976 206034 205916 205725 206293 207156 207191 206321 206740 207139 206821 207314 207888 207843
[10:01:37.096] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.1 99.1 99.0 99.3 99.6 99.6 99.3 99.4 99.6 99.5 99.7 99.9 99.9
[10:01:37.096] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.1 99.0 98.9 99.2 99.6 99.6 99.2 99.4 99.6 99.4 99.7 99.9 99.9
[10:01:37.096] INFO: X-ray hit rate [MHz/cm2]: 73.4 46.7 68.0 105.4 110.9 112.2 113.1 76.2 70.7 99.2 99.6 82.3 88.6 54.4 21.5 23.2
[10:01:37.096] INFO: PixTestHighRate::doXPixelAlive() done
[10:01:37.143] INFO: PixTest:: pg_setup set to default.
[10:01:37.156] INFO: enter test to run
[10:02:16.472] INFO: test: HighRate no parameter change
[10:02:16.472] INFO: running: highrate
[10:02:16.473] INFO: ----------------------------------------------------------------------
[10:02:16.473] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:02:16.473] INFO: ----------------------------------------------------------------------
[10:02:17.099] INFO: Expecting 208000 events.
[10:02:31.484] INFO: 208000 events read in total (13858ms).
[10:02:31.490] INFO: Test took 15008ms.
[10:02:31.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:32.125] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[10:02:32.125] INFO: number of red-efficiency pixels: 280 176 302 598 622 609 483 272 287 508 389 318 383 229 72 54
[10:02:32.125] INFO: number of X-ray hits detected: 159536 101823 148641 230450 243996 246001 247918 165698 155456 215899 216825 178853 193106 118561 46979 50174
[10:02:32.125] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:02:32.125] INFO: number of Vcal hits detected: 207695 207814 207656 207343 207309 207318 207456 207700 207692 207430 207574 207658 207591 207747 207927 207897
[10:02:32.125] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.8 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[10:02:32.125] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.9 99.9 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[10:02:32.125] INFO: X-ray hit rate [MHz/cm2]: 46.8 29.8 43.6 67.5 71.5 72.1 72.7 48.6 45.6 63.3 63.6 52.4 56.6 34.8 13.8 14.7
[10:02:32.125] INFO: PixTestHighRate::doXPixelAlive() done
[10:02:32.175] INFO: PixTest:: pg_setup set to default.
[10:02:32.190] INFO: enter test to run
[10:02:43.559] INFO: test: exit no parameter change
[10:02:44.046] QUIET: Connection to board 33 closed.
[10:02:44.057] INFO: pXar: this is the end, my friend