[14:32:44.364] INFO: *** Welcome to pxar ***
[14:32:44.364] INFO: *** Today: 2016/07/15
[14:32:44.381] INFO: *** Version: v1.9.0-814-g7497
[14:32:44.381] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//dacParameters35_C15.dat
[14:32:44.381] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:32:44.381] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//defaultMaskFile.dat
[14:32:44.381] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C15.dat
[14:32:44.454] INFO: clk: 4
[14:32:44.454] INFO: ctr: 4
[14:32:44.454] INFO: sda: 19
[14:32:44.454] INFO: tin: 9
[14:32:44.454] INFO: level: 15
[14:32:44.454] INFO: triggerdelay: 0
[14:32:44.454] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:32:44.454] INFO: Log level: INFO
[14:32:44.470] QUIET: Connection to board DTB_WREKRL opened.
[14:32:44.473] 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:
------------------------------------------------------
[14:32:44.476] INFO: RPC call hashes of host and DTB match: 398089610
[14:32:46.013] INFO: DUT info:
[14:32:46.013] INFO: The DUT currently contains the following objects:
[14:32:46.013] INFO: 2 TBM Cores tbm08c (2 ON)
[14:32:46.013] INFO: TBM Core alpha (0): 7 registers set
[14:32:46.013] INFO: TBM Core beta (1): 7 registers set
[14:32:46.013] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:32:46.013] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.013] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.013] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.013] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.013] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.013] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.013] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.014] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.014] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.014] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.014] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.014] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.014] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.014] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.014] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.014] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:32:46.417] INFO: enter 'restricted' command line mode
[14:32:46.417] INFO: enter test to run
[14:33:25.264] INFO: test: PixelAlive no parameter change
[14:33:25.264] INFO: running: pixelalive
[14:33:25.273] INFO: ----------------------------------------------------------------------
[14:33:25.273] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:33:25.274] INFO: ----------------------------------------------------------------------
[14:33:25.594] INFO: Expecting 41600 events.
[14:33:29.978] INFO: 41600 events read in total (3666ms).
[14:33:30.145] INFO: Test took 4869ms.
[14:33:30.159] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:30.423] INFO: PixTestAlive::aliveTest() done
[14:33:30.423] INFO: number of dead pixels (per ROC): 0 0 0 0 0 51 98 257 163 52 18 0 0 0 0 0
[14:33:30.454] INFO: enter test to run
[14:33:43.776] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:33:43.776] INFO: running: highrate
[14:33:43.777] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:33:43.935] INFO: ----------------------------------------------------------------------
[14:33:43.935] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:33:43.935] INFO: ----------------------------------------------------------------------
[14:33:43.935] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:33:43.935] INFO: edge/corner pixel THR is adjusted
[14:33:43.935] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:33:44.894] INFO: Collecting data for 5 seconds...
[14:33:49.913] INFO: Done with hot pixel readout
[14:34:02.266] INFO: PixTest:: pg_setup set to default.
[14:34:02.267] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:34:02.267] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:34:02.267] INFO: 293 hot pixels found in step 0
[14:34:03.260] INFO: Collecting data for 5 seconds...
[14:34:08.278] INFO: Done with hot pixel readout
[14:34:20.616] INFO: PixTest:: pg_setup set to default.
[14:34:20.616] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:34:20.617] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:34:20.617] INFO: 125 hot pixels found in step 1
[14:34:21.616] INFO: Collecting data for 5 seconds...
[14:34:26.634] INFO: Done with hot pixel readout
[14:34:38.969] INFO: PixTest:: pg_setup set to default.
[14:34:38.970] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:34:38.970] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:34:38.970] INFO: 86 hot pixels found in step 2
[14:34:39.966] INFO: Collecting data for 5 seconds...
[14:34:44.985] INFO: Done with hot pixel readout
[14:34:57.238] INFO: PixTest:: pg_setup set to default.
[14:34:57.239] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:34:57.239] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:34:57.239] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:34:57.239] INFO: 57 hot pixels found in step 3
[14:34:58.235] INFO: Collecting data for 5 seconds...
[14:35:03.253] INFO: Done with hot pixel readout
[14:35:15.318] INFO: PixTest:: pg_setup set to default.
[14:35:15.318] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:15.318] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:15.319] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:15.319] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:15.319] INFO: 43 hot pixels found in step 4
[14:35:16.313] INFO: Collecting data for 5 seconds...
[14:35:21.329] INFO: Done with hot pixel readout
[14:35:33.371] INFO: PixTest:: pg_setup set to default.
[14:35:33.371] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:33.371] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:33.371] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:33.371] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:33.372] INFO: 45 hot pixels found in step 5
[14:35:34.367] INFO: Collecting data for 5 seconds...
[14:35:39.383] INFO: Done with hot pixel readout
[14:35:51.464] INFO: PixTest:: pg_setup set to default.
[14:35:51.464] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:51.464] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:51.464] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:51.465] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:35:51.465] INFO: 36 hot pixels found in step 6
[14:35:52.460] INFO: Collecting data for 5 seconds...
[14:35:57.477] INFO: Done with hot pixel readout
[14:36:09.542] INFO: PixTest:: pg_setup set to default.
[14:36:09.543] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:09.543] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:09.543] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:09.543] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:09.543] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:09.543] INFO: 46 hot pixels found in step 7
[14:36:10.539] INFO: Collecting data for 5 seconds...
[14:36:15.555] INFO: Done with hot pixel readout
[14:36:27.624] INFO: PixTest:: pg_setup set to default.
[14:36:27.624] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:27.624] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:27.624] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:27.624] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:27.624] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:27.624] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:27.625] INFO: 50 hot pixels found in step 8
[14:36:28.620] INFO: Collecting data for 5 seconds...
[14:36:33.636] INFO: Done with hot pixel readout
[14:36:45.711] INFO: PixTest:: pg_setup set to default.
[14:36:45.711] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:45.712] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:45.712] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:45.712] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:45.712] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:45.712] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:45.712] INFO: 37 hot pixels found in step 9
[14:36:46.708] INFO: Collecting data for 5 seconds...
[14:36:51.723] INFO: Done with hot pixel readout
[14:37:03.804] INFO: PixTest:: pg_setup set to default.
[14:37:03.805] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:03.805] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:03.805] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:03.805] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:03.805] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:03.806] INFO: 46 hot pixels found in step 10
[14:37:04.801] INFO: Collecting data for 5 seconds...
[14:37:09.817] INFO: Done with hot pixel readout
[14:37:21.921] INFO: PixTest:: pg_setup set to default.
[14:37:21.921] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:21.921] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:21.921] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:21.921] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:21.921] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:21.922] INFO: 35 hot pixels found in step 11
[14:37:22.916] INFO: Collecting data for 5 seconds...
[14:37:27.932] INFO: Done with hot pixel readout
[14:37:39.985] INFO: PixTest:: pg_setup set to default.
[14:37:39.986] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:39.986] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:39.986] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:39.986] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:39.986] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:39.986] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:39.986] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:39.986] INFO: 40 hot pixels found in step 12
[14:37:40.982] INFO: Collecting data for 5 seconds...
[14:37:45.998] INFO: Done with hot pixel readout
[14:37:58.054] INFO: PixTest:: pg_setup set to default.
[14:37:58.055] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:58.055] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:58.055] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:58.055] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:58.055] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:58.055] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:58.055] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:58.055] INFO: 38 hot pixels found in step 13
[14:37:59.051] INFO: Collecting data for 5 seconds...
[14:38:04.067] INFO: Done with hot pixel readout
[14:38:16.162] INFO: PixTest:: pg_setup set to default.
[14:38:16.162] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:16.162] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:16.162] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:16.162] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:16.163] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:16.163] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:16.163] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:16.163] INFO: 50 hot pixels found in step 14
[14:38:16.203] INFO: 50 hot pixels could not be trimmed and have been masked.
[14:38:16.207] INFO: PixTest::trimHotPixels() done
[14:38:16.207] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C0.dat
[14:38:16.212] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C1.dat
[14:38:16.218] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C2.dat
[14:38:16.224] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C3.dat
[14:38:16.230] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C4.dat
[14:38:16.235] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C5.dat
[14:38:16.240] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C6.dat
[14:38:16.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C7.dat
[14:38:16.251] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C8.dat
[14:38:16.256] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C9.dat
[14:38:16.261] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C10.dat
[14:38:16.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C11.dat
[14:38:16.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C12.dat
[14:38:16.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C13.dat
[14:38:16.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C14.dat
[14:38:16.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C15.dat
[14:38:16.292] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//defaultMaskFile.dat
[14:38:16.303] INFO: enter test to run
[14:38:45.030] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:38:45.030] INFO: running: highrate
[14:38:45.035] INFO: ----------------------------------------------------------------------
[14:38:45.035] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:38:45.035] INFO: ----------------------------------------------------------------------
[14:38:45.035] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:38:45.035] INFO: edge/corner pixel THR is adjusted
[14:38:45.035] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:38:45.993] INFO: Collecting data for 1 seconds...
[14:38:46.996] INFO: Done with hot pixel readout
[14:38:50.920] INFO: PixTest:: pg_setup set to default.
[14:38:50.920] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:50.920] INFO: 1 hot pixels found in step 0
[14:38:50.926] INFO: 1 hot pixels could not be trimmed and have been masked.
[14:38:51.020] INFO: PixTest::trimHotPixels() done
[14:38:51.020] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C0.dat
[14:38:51.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C1.dat
[14:38:51.061] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C2.dat
[14:38:51.067] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C3.dat
[14:38:51.072] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C4.dat
[14:38:51.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C5.dat
[14:38:51.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C6.dat
[14:38:51.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C7.dat
[14:38:51.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C8.dat
[14:38:51.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C9.dat
[14:38:51.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C10.dat
[14:38:51.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C11.dat
[14:38:51.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C12.dat
[14:38:51.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C13.dat
[14:38:51.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C14.dat
[14:38:51.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//trimParameters35_C15.dat
[14:38:51.136] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-17_FPIXTest-17C-FNAL-160712-1214_2016-07-12_12h14m_1468343661/000_FPIXTest_p17//defaultMaskFile.dat
[14:38:51.149] INFO: enter test to run
[14:39:14.422] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:39:14.422] INFO: running: xray
[14:39:14.423] INFO: ----------------------------------------------------------------------
[14:39:14.423] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:39:14.423] INFO: ----------------------------------------------------------------------
[14:39:15.387] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:39:26.443] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:39:55.965] INFO: Resuming triggers.
[14:40:07.023] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:40:36.656] INFO: Resuming triggers.
[14:40:47.720] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:41:17.115] INFO: Resuming triggers.
[14:41:28.181] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:41:57.627] INFO: Resuming triggers.
[14:42:08.690] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:42:38.155] INFO: Resuming triggers.
[14:42:49.218] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:43:19.159] INFO: Resuming triggers.
[14:43:30.227] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:44:00.235] INFO: Resuming triggers.
[14:44:11.311] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:44:41.018] INFO: Resuming triggers.
[14:44:52.107] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:45:21.916] INFO: Resuming triggers.
[14:45:22.640] INFO: data taking finished, elapsed time: 100 seconds.
[14:45:25.008] INFO: PixTest:: pg_setup set to default.
[14:45:25.011] INFO: PixTestXray::doPhRun() done
[14:45:25.151] INFO: enter test to run
[14:49:10.746] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:49:10.746] INFO: running: xray
[14:49:10.747] INFO: ----------------------------------------------------------------------
[14:49:10.747] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:49:10.747] INFO: ----------------------------------------------------------------------
[14:49:11.734] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:49:18.599] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:49:48.834] INFO: Resuming triggers.
[14:49:55.696] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:50:25.762] INFO: Resuming triggers.
[14:50:32.617] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:51:02.789] INFO: Resuming triggers.
[14:51:09.645] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:51:39.761] INFO: Resuming triggers.
[14:51:46.620] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:52:16.729] INFO: Resuming triggers.
[14:52:23.589] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[14:52:53.890] INFO: Resuming triggers.
[14:53:00.753] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:53:30.942] INFO: Resuming triggers.
[14:53:37.808] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:54:07.959] INFO: Resuming triggers.
[14:54:14.826] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:54:44.954] INFO: Resuming triggers.
[14:54:51.820] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:55:22.681] INFO: Resuming triggers.
[14:55:29.549] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[14:56:00.802] INFO: Resuming triggers.
[14:56:07.670] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[14:56:38.389] INFO: Resuming triggers.
[14:56:45.251] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:57:17.144] INFO: Resuming triggers.
[14:57:24.003] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:57:55.255] INFO: Resuming triggers.
[14:57:59.499] INFO: data taking finished, elapsed time: 100 seconds.
[14:58:19.574] INFO: PixTest:: pg_setup set to default.
[14:58:19.577] INFO: PixTestXray::doPhRun() done
[14:58:19.727] INFO: enter test to run
[14:59:31.110] INFO: test: HighRate no parameter change
[14:59:31.110] INFO: running: highrate
[14:59:31.111] INFO: ----------------------------------------------------------------------
[14:59:31.111] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:59:31.111] INFO: ----------------------------------------------------------------------
[14:59:31.251] INFO: Expecting 768 events.
[14:59:32.385] INFO: 768 events read in total (419ms).
[14:59:32.385] INFO: Test took 1268ms.
[14:59:33.188] INFO: Expecting 41600 events.
[14:59:36.374] INFO: 41600 events read in total (2659ms).
[14:59:36.375] INFO: Test took 3982ms.
[14:59:36.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:37.129] INFO: Expecting 41600 events.
[14:59:40.384] INFO: 41600 events read in total (2728ms).
[14:59:40.385] INFO: Test took 3951ms.
[14:59:40.425] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:41.139] INFO: Expecting 41600 events.
[14:59:44.451] INFO: 41600 events read in total (2785ms).
[14:59:44.452] INFO: Test took 4006ms.
[14:59:44.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:45.201] INFO: Expecting 41600 events.
[14:59:48.485] INFO: 41600 events read in total (2757ms).
[14:59:48.487] INFO: Test took 3974ms.
[14:59:48.532] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:49.240] INFO: Expecting 41600 events.
[14:59:52.526] INFO: 41600 events read in total (2759ms).
[14:59:52.527] INFO: Test took 3974ms.
[14:59:52.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:53.278] INFO: Expecting 41600 events.
[14:59:56.573] INFO: 41600 events read in total (2769ms).
[14:59:56.574] INFO: Test took 3986ms.
[14:59:56.614] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:57.327] INFO: Expecting 41600 events.
[15:00:00.627] INFO: 41600 events read in total (2773ms).
[15:00:00.628] INFO: Test took 3994ms.
[15:00:00.668] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:01.379] INFO: Expecting 41600 events.
[15:00:04.683] INFO: 41600 events read in total (2778ms).
[15:00:04.684] INFO: Test took 3995ms.
[15:00:04.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:05.433] INFO: Expecting 41600 events.
[15:00:08.730] INFO: 41600 events read in total (2770ms).
[15:00:08.731] INFO: Test took 3987ms.
[15:00:08.771] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:09.485] INFO: Expecting 41600 events.
[15:00:12.783] INFO: 41600 events read in total (2771ms).
[15:00:12.784] INFO: Test took 3992ms.
[15:00:12.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:13.535] INFO: Expecting 41600 events.
[15:00:16.853] INFO: 41600 events read in total (2791ms).
[15:00:16.854] INFO: Test took 4009ms.
[15:00:16.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:17.608] INFO: Expecting 41600 events.
[15:00:20.920] INFO: 41600 events read in total (2785ms).
[15:00:20.921] INFO: Test took 4006ms.
[15:00:20.961] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:21.673] INFO: Expecting 41600 events.
[15:00:24.992] INFO: 41600 events read in total (2792ms).
[15:00:24.993] INFO: Test took 4011ms.
[15:00:25.032] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:25.748] INFO: Expecting 41600 events.
[15:00:29.055] INFO: 41600 events read in total (2780ms).
[15:00:29.056] INFO: Test took 4004ms.
[15:00:29.095] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:29.807] INFO: Expecting 41600 events.
[15:00:33.112] INFO: 41600 events read in total (2778ms).
[15:00:33.113] INFO: Test took 3997ms.
[15:00:33.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:33.864] INFO: Expecting 41600 events.
[15:00:37.155] INFO: 41600 events read in total (2764ms).
[15:00:37.156] INFO: Test took 3982ms.
[15:00:37.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:37.909] INFO: Expecting 41600 events.
[15:00:41.215] INFO: 41600 events read in total (2779ms).
[15:00:41.216] INFO: Test took 3998ms.
[15:00:41.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:41.970] INFO: Expecting 41600 events.
[15:00:45.247] INFO: 41600 events read in total (2750ms).
[15:00:45.248] INFO: Test took 3970ms.
[15:00:45.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:45.002] INFO: Expecting 41600 events.
[15:00:49.275] INFO: 41600 events read in total (2746ms).
[15:00:49.276] INFO: Test took 3967ms.
[15:00:49.315] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:50.030] INFO: Expecting 41600 events.
[15:00:53.110] INFO: 41600 events read in total (2553ms).
[15:00:53.111] INFO: Test took 3775ms.
[15:00:53.149] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:53.498] INFO: enter test to run
[15:03:27.732] INFO: test: HighRate no parameter change
[15:03:27.732] INFO: running: highrate
[15:03:27.733] INFO: ----------------------------------------------------------------------
[15:03:27.733] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:03:27.733] INFO: ----------------------------------------------------------------------
[15:03:28.351] INFO: Expecting 208000 events.
[15:03:40.505] INFO: 208000 events read in total (11627ms).
[15:03:40.508] INFO: Test took 12766ms.
[15:03:40.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:40.945] INFO: number of dead pixels (per ROC): 0 0 0 0 0 51 98 261 163 52 16 0 0 0 0 0
[15:03:40.945] INFO: number of red-efficiency pixels: 75 42 81 137 130 228 284 1282 1025 321 135 95 74 66 28 30
[15:03:40.945] INFO: number of X-ray hits detected: 68992 44221 62694 104947 107981 110345 111241 245803 212867 109959 91257 80756 85354 48884 23291 24909
[15:03:40.945] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:03:40.945] INFO: number of Vcal hits detected: 207923 207958 207917 207853 207867 205268 202906 193619 198860 205116 206981 207902 207926 207934 207972 207968
[15:03:40.946] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.3 99.5 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:03:40.946] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 98.7 97.6 93.1 95.6 98.6 99.5 100.0 100.0 100.0 100.0 100.0
[15:03:40.946] INFO: X-ray hit rate [MHz/cm2]: 20.2 13.0 18.4 30.8 31.7 32.3 32.6 72.0 62.4 32.2 26.7 23.7 25.0 14.3 6.8 7.3
[15:03:40.946] INFO: PixTestHighRate::doXPixelAlive() done
[15:03:40.994] INFO: PixTest:: pg_setup set to default.
[15:03:41.009] INFO: enter test to run
[15:07:04.291] INFO: test: HighRate no parameter change
[15:07:04.291] INFO: running: highrate
[15:07:04.292] INFO: ----------------------------------------------------------------------
[15:07:04.292] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:07:04.292] INFO: ----------------------------------------------------------------------
[15:07:04.917] INFO: Expecting 208000 events.
[15:07:18.685] INFO: 208000 events read in total (13241ms).
[15:07:18.691] INFO: Test took 14390ms.
[15:07:19.007] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:19.317] INFO: number of dead pixels (per ROC): 0 0 0 0 0 51 98 263 163 52 18 0 0 0 0 0
[15:07:19.317] INFO: number of red-efficiency pixels: 200 135 229 469 476 543 518 1413 1224 475 391 277 266 155 66 49
[15:07:19.317] INFO: number of X-ray hits detected: 138628 89220 128057 212759 218345 221312 215609 306456 277262 209407 185303 163156 171889 99552 47703 50392
[15:07:19.317] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:07:19.317] INFO: number of Vcal hits detected: 207790 207859 207753 207491 207481 204907 202637 193382 198612 204934 206699 207711 207712 207837 207931 207948
[15:07:19.317] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.2 99.4 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:07:19.317] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 98.5 97.4 93.0 95.5 98.5 99.4 99.9 99.9 99.9 100.0 100.0
[15:07:19.317] INFO: X-ray hit rate [MHz/cm2]: 40.6 26.2 37.5 62.4 64.0 64.9 63.2 89.8 81.3 61.4 54.3 47.8 50.4 29.2 14.0 14.8
[15:07:19.317] INFO: PixTestHighRate::doXPixelAlive() done
[15:07:19.362] INFO: PixTest:: pg_setup set to default.
[15:07:19.375] INFO: enter test to run
[15:07:47.850] INFO: test: HighRate no parameter change
[15:07:47.850] INFO: running: highrate
[15:07:47.852] INFO: ----------------------------------------------------------------------
[15:07:47.852] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:07:47.852] INFO: ----------------------------------------------------------------------
[15:07:48.478] INFO: Expecting 208000 events.
[15:08:03.975] INFO: 208000 events read in total (14971ms).
[15:08:03.982] INFO: Test took 16119ms.
[15:08:04.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:04.786] INFO: number of dead pixels (per ROC): 0 0 0 0 0 51 98 263 163 52 18 0 0 0 0 0
[15:08:04.786] INFO: number of red-efficiency pixels: 409 311 520 1031 1154 1191 1041 1655 1494 827 826 586 596 366 118 80
[15:08:04.786] INFO: number of X-ray hits detected: 208656 134369 191114 317338 326429 332072 315387 370552 345297 306327 278194 244729 258759 149265 71667 76773
[15:08:04.786] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:08:04.786] INFO: number of Vcal hits detected: 207523 207662 207372 206731 206546 203990 201954 192964 198205 204498 206146 207351 207347 207584 207874 207912
[15:08:04.786] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.4 99.3 99.5 99.1 99.2 99.6 99.6 99.7 99.7 99.8 99.9 100.0
[15:08:04.786] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.7 99.4 99.3 98.1 97.1 92.8 95.3 98.3 99.1 99.7 99.7 99.8 99.9 100.0
[15:08:04.786] INFO: X-ray hit rate [MHz/cm2]: 61.2 39.4 56.0 93.0 95.7 97.3 92.4 108.6 101.2 89.8 81.5 71.7 75.8 43.8 21.0 22.5
[15:08:04.786] INFO: PixTestHighRate::doXPixelAlive() done
[15:08:04.831] INFO: PixTest:: pg_setup set to default.
[15:08:04.851] INFO: enter test to run
[15:08:15.418] INFO: test: exit no parameter change
[15:08:15.750] QUIET: Connection to board 33 closed.
[15:08:15.751] INFO: pXar: this is the end, my friend