[11:29:52.969] INFO: *** Welcome to pxar ***
[11:29:52.969] INFO: *** Today: 2016/03/25
[11:29:52.991] INFO: *** Version: prod-12-dirty
[11:29:52.991] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//dacParameters35_C15.dat
[11:29:53.262] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:29:53.320] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//defaultMaskFile.dat
[11:29:53.396] INFO: MASKED Roc 0 col/row: 20 66
[11:29:53.396] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C15.dat
[11:29:53.396] INFO: masking Roc 0 col/row: 20 66
[11:29:54.262] INFO: clk: 4
[11:29:54.262] INFO: ctr: 4
[11:29:54.262] INFO: sda: 19
[11:29:54.262] INFO: tin: 9
[11:29:54.262] INFO: level: 15
[11:29:54.262] INFO: triggerdelay: 0
[11:29:54.262] QUIET: Instanciating API for pxar prod-12
[11:29:54.262] INFO: Log level: INFO
[11:29:54.279] QUIET: Connection to board DTB_WREKRL opened.
[11:29:54.282] 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:
------------------------------------------------------
[11:29:54.285] INFO: RPC call hashes of host and DTB match: 398089610
[11:29:55.815] INFO: DUT info:
[11:29:55.815] INFO: The DUT currently contains the following objects:
[11:29:55.816] INFO: 2 TBM Cores tbm08c (2 ON)
[11:29:55.816] INFO: TBM Core alpha (0): 7 registers set
[11:29:55.816] INFO: TBM Core beta (1): 7 registers set
[11:29:55.816] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:29:55.816] INFO: ROC 0: 19 DACs set, Pixels: 1 masked, 0 active.
[11:29:55.816] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:55.816] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:29:56.227] INFO: enter 'restricted' command line mode
[11:29:56.227] INFO: enter test to run
[11:30:08.477] INFO: test: PixelAlive no parameter change
[11:30:08.477] INFO: running: pixelalive
[11:30:08.484] INFO: ----------------------------------------------------------------------
[11:30:08.484] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:30:08.484] INFO: ----------------------------------------------------------------------
[11:30:08.486] INFO: ROC 0 masking pixel 20/66
[11:30:08.800] INFO: Expecting 41600 events.
[11:30:13.129] INFO: 41600 events read in total (3611ms).
[11:30:13.297] INFO: Test took 4811ms.
[11:30:13.311] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:30:13.574] INFO: PixTestAlive::aliveTest() done
[11:30:13.574] INFO: number of dead pixels (per ROC): 1 0 2 0 0 0 0 0 0 0 0 0 5 1 0 0
[11:30:13.574] INFO: ROC 0 masking pixel 20/66
[11:30:13.606] INFO: enter test to run
[11:30:49.925] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=150;maskuntrimmable=0<-
[11:30:49.925] INFO: running: highrate
[11:30:49.926] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:30:50.135] INFO: ----------------------------------------------------------------------
[11:30:50.136] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:30:50.136] INFO: ----------------------------------------------------------------------
[11:30:50.136] INFO: THR = 150, corresponding to ~ 80 MHz/cm2
[11:30:50.136] INFO: edge/corner pixel THR is adjusted
[11:30:50.136] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:30:51.095] INFO: Collecting data for 5 seconds...
[11:30:56.111] INFO: Done with hot pixel readout
[11:31:07.654] INFO: PixTest:: pg_setup set to default.
[11:31:07.654] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:31:07.655] INFO: 49 hot pixels found in step 0
[11:31:08.663] INFO: Collecting data for 5 seconds...
[11:31:13.680] INFO: Done with hot pixel readout
[11:31:25.104] INFO: PixTest:: pg_setup set to default.
[11:31:25.104] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:31:25.105] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:31:25.105] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:31:25.105] INFO: 53 hot pixels found in step 1
[11:31:26.092] INFO: Collecting data for 5 seconds...
[11:31:31.109] INFO: Done with hot pixel readout
[11:31:42.602] INFO: PixTest:: pg_setup set to default.
[11:31:42.603] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:31:42.603] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:31:42.604] INFO: 57 hot pixels found in step 2
[11:31:43.591] INFO: Collecting data for 5 seconds...
[11:31:48.608] INFO: Done with hot pixel readout
[11:32:00.100] INFO: PixTest:: pg_setup set to default.
[11:32:00.100] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:32:00.101] INFO: 58 hot pixels found in step 3
[11:32:01.087] INFO: Collecting data for 5 seconds...
[11:32:06.104] INFO: Done with hot pixel readout
[11:32:17.537] INFO: PixTest:: pg_setup set to default.
[11:32:17.537] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:32:17.538] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:32:17.538] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:32:17.538] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:32:17.538] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:32:17.538] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:32:17.539] INFO: 53 hot pixels found in step 4
[11:32:18.526] INFO: Collecting data for 5 seconds...
[11:32:23.542] INFO: Done with hot pixel readout
[11:32:34.866] INFO: PixTest:: pg_setup set to default.
[11:32:34.866] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:32:34.866] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:32:34.867] INFO: 62 hot pixels found in step 5
[11:32:35.853] INFO: Collecting data for 5 seconds...
[11:32:40.870] INFO: Done with hot pixel readout
[11:32:52.382] INFO: PixTest:: pg_setup set to default.
[11:32:52.383] INFO: 43 hot pixels found in step 6
[11:32:53.370] INFO: Collecting data for 5 seconds...
[11:32:58.386] INFO: Done with hot pixel readout
[11:33:09.869] INFO: PixTest:: pg_setup set to default.
[11:33:09.870] INFO: 34 hot pixels found in step 7
[11:33:10.857] INFO: Collecting data for 5 seconds...
[11:33:15.874] INFO: Done with hot pixel readout
[11:33:27.349] INFO: PixTest:: pg_setup set to default.
[11:33:27.349] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:33:27.349] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:33:27.349] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:33:27.349] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:33:27.350] INFO: 52 hot pixels found in step 8
[11:33:28.336] INFO: Collecting data for 5 seconds...
[11:33:33.353] INFO: Done with hot pixel readout
[11:33:44.802] INFO: PixTest:: pg_setup set to default.
[11:33:44.802] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:33:44.802] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:33:44.802] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:33:44.802] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:33:44.803] INFO: 53 hot pixels found in step 9
[11:33:45.790] INFO: Collecting data for 5 seconds...
[11:33:50.807] INFO: Done with hot pixel readout
[11:34:02.299] INFO: PixTest:: pg_setup set to default.
[11:34:02.299] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:02.299] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:02.300] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:02.300] INFO: 54 hot pixels found in step 10
[11:34:03.287] INFO: Collecting data for 5 seconds...
[11:34:08.303] INFO: Done with hot pixel readout
[11:34:19.792] INFO: PixTest:: pg_setup set to default.
[11:34:19.792] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:19.792] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:19.792] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:19.792] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:19.793] INFO: 48 hot pixels found in step 11
[11:34:20.779] INFO: Collecting data for 5 seconds...
[11:34:25.796] INFO: Done with hot pixel readout
[11:34:37.237] INFO: PixTest:: pg_setup set to default.
[11:34:37.237] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:37.237] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:37.238] INFO: 23 hot pixels found in step 12
[11:34:38.225] INFO: Collecting data for 5 seconds...
[11:34:43.242] INFO: Done with hot pixel readout
[11:34:54.731] INFO: PixTest:: pg_setup set to default.
[11:34:54.731] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:54.732] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:54.732] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:54.732] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:54.732] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:34:54.733] INFO: 54 hot pixels found in step 13
[11:34:55.721] INFO: Collecting data for 5 seconds...
[11:35:00.738] INFO: Done with hot pixel readout
[11:35:12.294] INFO: PixTest:: pg_setup set to default.
[11:35:12.294] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:35:12.294] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:35:12.294] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:35:12.295] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:35:12.295] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:35:12.295] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:35:12.295] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:35:12.295] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:35:12.295] INFO: 37 hot pixels found in step 14
[11:35:12.329] INFO: PixTest::trimHotPixels() done
[11:35:12.355] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C0.dat
[11:35:12.364] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C1.dat
[11:35:12.371] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C2.dat
[11:35:12.379] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C3.dat
[11:35:12.386] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C4.dat
[11:35:12.394] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C5.dat
[11:35:12.401] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C6.dat
[11:35:12.409] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C7.dat
[11:35:12.416] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C8.dat
[11:35:12.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C9.dat
[11:35:12.431] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C10.dat
[11:35:12.439] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C11.dat
[11:35:12.447] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C12.dat
[11:35:12.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C13.dat
[11:35:12.462] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C14.dat
[11:35:12.469] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C15.dat
[11:35:12.489] INFO: enter test to run
[11:35:37.971] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=150;maskuntrimmable=0<-
[11:35:37.971] INFO: running: highrate
[11:35:37.976] INFO: ----------------------------------------------------------------------
[11:35:37.976] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:35:37.976] INFO: ----------------------------------------------------------------------
[11:35:37.976] INFO: THR = 150, corresponding to ~ 400 MHz/cm2
[11:35:37.976] INFO: edge/corner pixel THR is adjusted
[11:35:37.976] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:35:38.938] INFO: Collecting data for 1 seconds...
[11:35:39.942] INFO: Done with hot pixel readout
[11:35:43.475] INFO: PixTest:: pg_setup set to default.
[11:35:43.476] INFO: 0 hot pixels found in step 0
[11:35:43.589] INFO: PixTest::trimHotPixels() done
[11:35:43.589] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C0.dat
[11:35:43.601] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C1.dat
[11:35:43.609] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C2.dat
[11:35:43.616] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C3.dat
[11:35:43.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C4.dat
[11:35:43.631] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C5.dat
[11:35:43.638] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C6.dat
[11:35:43.645] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C7.dat
[11:35:43.653] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C8.dat
[11:35:43.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C9.dat
[11:35:43.667] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C10.dat
[11:35:43.675] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C11.dat
[11:35:43.683] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C12.dat
[11:35:43.690] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C13.dat
[11:35:43.698] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C14.dat
[11:35:43.705] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//trimParameters35_C15.dat
[11:35:43.723] INFO: enter test to run
[11:36:06.307] INFO: test: Xray setting parameters: ->savemaskfile=1<-
[11:36:06.307] INFO: running: xray
[11:36:06.312] INFO: ----------------------------------------------------------------------
[11:36:06.312] INFO: PixTest::maskHotPixels() running for 10 seconds with 100 kHz trigger rate
[11:36:06.312] INFO: ----------------------------------------------------------------------
[11:36:07.270] INFO: PixTestHighRate::maskHotPixels start TriggerLoop with period 404 and duration 10 seconds and trigger rate 100 kHz
[11:36:16.313] INFO: Done with hot pixel readout
[11:36:30.397] INFO: PixTest:: pg_setup set to default.
[11:36:30.398] INFO: no hot pixel found!
[11:36:30.398] INFO: PixTest::maskHotPixels() done
[11:36:30.402] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-1-28_FPIXTest-17C-FNAL-160125-1011_2016-01-25_10h11m_1453738317/000_FPIXTest_p17//defaultMaskFile.dat
[11:36:30.569] INFO: enter test to run
[11:37:06.627] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:37:06.627] INFO: running: xray
[11:37:06.628] INFO: ----------------------------------------------------------------------
[11:37:06.628] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:37:06.628] INFO: ----------------------------------------------------------------------
[11:37:06.631] INFO: ROC 0 masking pixel 20/66
[11:37:07.592] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:37:19.329] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:37:48.870] INFO: Resuming triggers.
[11:38:00.607] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[11:38:30.103] INFO: Resuming triggers.
[11:38:41.838] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[11:39:10.600] INFO: Resuming triggers.
[11:39:22.340] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[11:39:51.820] INFO: Resuming triggers.
[11:40:03.561] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[11:40:29.917] INFO: Resuming triggers.
[11:40:41.654] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[11:41:11.109] INFO: Resuming triggers.
[11:41:22.846] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:41:52.180] INFO: Resuming triggers.
[11:42:03.919] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[11:42:33.383] INFO: Resuming triggers.
[11:42:39.807] INFO: data taking finished, elapsed time: 100 seconds.
[11:42:56.209] INFO: PixTest:: pg_setup set to default.
[11:42:56.213] INFO: PixTestXray::doPhRun() done
[11:42:56.349] INFO: enter test to run
[11:43:44.936] INFO: test: HighRate no parameter change
[11:43:44.936] INFO: running: highrate
[11:43:44.937] INFO: ----------------------------------------------------------------------
[11:43:44.937] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:43:44.937] INFO: ----------------------------------------------------------------------
[11:43:45.078] INFO: Expecting 768 events.
[11:43:46.212] INFO: 768 events read in total (418ms).
[11:43:46.213] INFO: Test took 1269ms.
[11:43:46.216] INFO: ROC 0 masking pixel 20/66
[11:43:47.016] INFO: Expecting 41600 events.
[11:43:50.032] INFO: 41600 events read in total (2489ms).
[11:43:50.033] INFO: Test took 3814ms.
[11:43:50.064] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:50.796] INFO: Expecting 41600 events.
[11:43:53.964] INFO: 41600 events read in total (2641ms).
[11:43:53.965] INFO: Test took 3884ms.
[11:43:53.998] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:54.726] INFO: Expecting 41600 events.
[11:43:57.945] INFO: 41600 events read in total (2692ms).
[11:43:57.946] INFO: Test took 3932ms.
[11:43:57.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:58.704] INFO: Expecting 41600 events.
[11:44:01.928] INFO: 41600 events read in total (2697ms).
[11:44:01.929] INFO: Test took 3932ms.
[11:44:01.961] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:02.683] INFO: Expecting 41600 events.
[11:44:05.726] INFO: 41600 events read in total (2516ms).
[11:44:05.727] INFO: Test took 3748ms.
[11:44:05.759] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:06.488] INFO: Expecting 41600 events.
[11:44:09.707] INFO: 41600 events read in total (2692ms).
[11:44:09.708] INFO: Test took 3931ms.
[11:44:09.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:10.467] INFO: Expecting 41600 events.
[11:44:13.701] INFO: 41600 events read in total (2708ms).
[11:44:13.702] INFO: Test took 3945ms.
[11:44:13.734] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:14.458] INFO: Expecting 41600 events.
[11:44:17.676] INFO: 41600 events read in total (2691ms).
[11:44:17.677] INFO: Test took 3926ms.
[11:44:17.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:18.435] INFO: Expecting 41600 events.
[11:44:21.645] INFO: 41600 events read in total (2683ms).
[11:44:21.646] INFO: Test took 3918ms.
[11:44:21.679] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:22.403] INFO: Expecting 41600 events.
[11:44:25.633] INFO: 41600 events read in total (2703ms).
[11:44:25.634] INFO: Test took 3938ms.
[11:44:25.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:26.394] INFO: Expecting 41600 events.
[11:44:29.606] INFO: 41600 events read in total (2685ms).
[11:44:29.607] INFO: Test took 3925ms.
[11:44:29.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:30.368] INFO: Expecting 41600 events.
[11:44:33.566] INFO: 41600 events read in total (2671ms).
[11:44:33.567] INFO: Test took 3911ms.
[11:44:33.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:34.328] INFO: Expecting 41600 events.
[11:44:37.550] INFO: 41600 events read in total (2695ms).
[11:44:37.551] INFO: Test took 3935ms.
[11:44:37.583] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:38.312] INFO: Expecting 41600 events.
[11:44:41.532] INFO: 41600 events read in total (2693ms).
[11:44:41.532] INFO: Test took 3932ms.
[11:44:41.565] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:42.292] INFO: Expecting 41600 events.
[11:44:45.516] INFO: 41600 events read in total (2697ms).
[11:44:45.517] INFO: Test took 3935ms.
[11:44:45.550] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:46.276] INFO: Expecting 41600 events.
[11:44:49.501] INFO: 41600 events read in total (2699ms).
[11:44:49.502] INFO: Test took 3934ms.
[11:44:49.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:50.264] INFO: Expecting 41600 events.
[11:44:53.482] INFO: 41600 events read in total (2692ms).
[11:44:53.482] INFO: Test took 3929ms.
[11:44:53.515] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:54.239] INFO: Expecting 41600 events.
[11:44:57.453] INFO: 41600 events read in total (2687ms).
[11:44:57.454] INFO: Test took 3922ms.
[11:44:57.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:58.210] INFO: Expecting 41600 events.
[11:45:01.415] INFO: 41600 events read in total (2678ms).
[11:45:01.416] INFO: Test took 3912ms.
[11:45:01.448] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:02.177] INFO: Expecting 41600 events.
[11:45:05.277] INFO: 41600 events read in total (2573ms).
[11:45:05.278] INFO: Test took 3813ms.
[11:45:05.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:05.678] INFO: enter test to run
[11:45:23.471] INFO: test: HighRate no parameter change
[11:45:23.472] INFO: running: highrate
[11:45:23.473] INFO: ----------------------------------------------------------------------
[11:45:23.473] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:45:23.473] INFO: ----------------------------------------------------------------------
[11:45:23.480] INFO: ROC 0 masking pixel 20/66
[11:45:24.089] INFO: Expecting 208000 events.
[11:45:35.856] INFO: 208000 events read in total (11240ms).
[11:45:35.859] INFO: Test took 12378ms.
[11:45:35.994] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:36.242] INFO: number of dead pixels (per ROC): 1 0 2 0 0 0 0 0 0 0 0 0 5 1 0 0
[11:45:36.242] INFO: number of red-efficiency pixels: 2702 31 72 109 131 115 159 106 95 104 103 80 94 65 23 21
[11:45:36.242] INFO: number of X-ray hits detected: 62486 40669 63636 98232 103885 105688 108640 72804 67135 90693 91906 77762 81651 48050 21395 25207
[11:45:36.242] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:45:36.242] INFO: number of Vcal hits detected: 205198 207969 207830 207891 207865 207881 207836 207893 207904 207896 207895 207918 207661 207885 207977 207978
[11:45:36.243] INFO: Vcal hit fiducial efficiency (%): 98.7 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[11:45:36.243] INFO: Vcal hit overall efficiency (%): 98.7 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 99.8 99.9 100.0 100.0
[11:45:36.243] INFO: X-ray hit rate [MHz/cm2]: 18.3 11.9 18.7 28.8 30.4 31.0 31.8 21.3 19.7 26.6 26.9 22.8 23.9 14.1 6.3 7.4
[11:45:36.243] INFO: PixTestHighRate::doXPixelAlive() done
[11:45:36.290] INFO: PixTest:: pg_setup set to default.
[11:45:36.304] INFO: enter test to run
[11:45:51.767] INFO: test: HighRate no parameter change
[11:45:51.767] INFO: running: highrate
[11:45:51.768] INFO: ----------------------------------------------------------------------
[11:45:51.768] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:45:51.768] INFO: ----------------------------------------------------------------------
[11:45:51.777] INFO: ROC 0 masking pixel 20/66
[11:45:52.385] INFO: Expecting 208000 events.
[11:46:05.895] INFO: 208000 events read in total (12983ms).
[11:46:05.900] INFO: Test took 14122ms.
[11:46:06.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:06.474] INFO: number of dead pixels (per ROC): 1 0 2 0 0 0 0 0 0 0 0 0 5 1 0 0
[11:46:06.474] INFO: number of red-efficiency pixels: 3495 120 235 324 493 368 418 286 228 315 305 297 314 169 57 53
[11:46:06.474] INFO: number of X-ray hits detected: 132619 86966 136515 211120 223998 228219 232199 155591 144565 196734 197250 167527 175784 103430 46406 54129
[11:46:06.474] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:46:06.474] INFO: number of Vcal hits detected: 204273 207876 207657 207658 207467 207610 207544 207695 207761 207662 207684 207671 207424 207764 207941 207947
[11:46:06.474] INFO: Vcal hit fiducial efficiency (%): 98.2 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[11:46:06.474] INFO: Vcal hit overall efficiency (%): 98.2 99.9 99.8 99.8 99.7 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.7 99.9 100.0 100.0
[11:46:06.474] INFO: X-ray hit rate [MHz/cm2]: 38.9 25.5 40.0 61.9 65.7 66.9 68.1 45.6 42.4 57.7 57.8 49.1 51.5 30.3 13.6 15.9
[11:46:06.474] INFO: PixTestHighRate::doXPixelAlive() done
[11:46:06.524] INFO: PixTest:: pg_setup set to default.
[11:46:06.542] INFO: enter test to run
[11:46:23.759] INFO: test: HighRate no parameter change
[11:46:23.759] INFO: running: highrate
[11:46:23.760] INFO: ----------------------------------------------------------------------
[11:46:23.760] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:46:23.760] INFO: ----------------------------------------------------------------------
[11:46:23.769] INFO: ROC 0 masking pixel 20/66
[11:46:24.378] INFO: Expecting 208000 events.
[11:46:39.215] INFO: 208000 events read in total (14310ms).
[11:46:39.222] INFO: Test took 15453ms.
[11:46:39.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:39.933] INFO: number of dead pixels (per ROC): 1 0 2 0 0 0 0 0 0 0 0 0 5 1 0 0
[11:46:39.933] INFO: number of red-efficiency pixels: 3343 203 382 638 922 709 891 559 449 583 502 534 603 306 70 78
[11:46:39.933] INFO: number of X-ray hits detected: 182433 120419 189946 291807 310877 314250 322044 215330 200869 272419 272405 232233 244480 142929 64410 75192
[11:46:39.934] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:46:39.934] INFO: number of Vcal hits detected: 204292 207781 207465 207272 206915 207195 206933 207334 207508 207354 207444 207393 207103 207613 207929 207921
[11:46:39.934] INFO: Vcal hit fiducial efficiency (%): 98.3 99.9 99.8 99.7 99.5 99.6 99.5 99.7 99.8 99.7 99.8 99.8 99.7 99.9 100.0 100.0
[11:46:39.934] INFO: Vcal hit overall efficiency (%): 98.2 99.9 99.7 99.7 99.5 99.6 99.5 99.7 99.8 99.7 99.7 99.7 99.6 99.8 100.0 100.0
[11:46:39.934] INFO: X-ray hit rate [MHz/cm2]: 53.5 35.3 55.7 85.5 91.1 92.1 94.4 63.1 58.9 79.8 79.8 68.1 71.7 41.9 18.9 22.0
[11:46:39.934] INFO: PixTestHighRate::doXPixelAlive() done
[11:46:39.984] INFO: PixTest:: pg_setup set to default.
[11:46:39.001] INFO: enter test to run
[11:46:46.551] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:46:46.551] INFO: running: xray
[11:46:46.552] INFO: ----------------------------------------------------------------------
[11:46:46.552] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:46:46.552] INFO: ----------------------------------------------------------------------
[11:46:46.557] INFO: ROC 0 masking pixel 20/66
[11:46:47.517] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:46:54.730] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[11:47:24.934] INFO: Resuming triggers.
[11:47:32.148] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[11:48:02.350] INFO: Resuming triggers.
[11:48:09.562] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[11:48:39.734] INFO: Resuming triggers.
[11:48:46.940] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[11:49:16.911] INFO: Resuming triggers.
[11:49:24.122] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[11:49:54.292] INFO: Resuming triggers.
[11:50:01.501] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[11:50:28.998] INFO: Resuming triggers.
[11:50:36.207] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[11:51:06.407] INFO: Resuming triggers.
[11:51:13.613] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[11:51:43.902] INFO: Resuming triggers.
[11:51:51.113] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[11:52:21.272] INFO: Resuming triggers.
[11:52:28.478] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[11:52:58.753] INFO: Resuming triggers.
[11:53:05.960] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[11:53:36.163] INFO: Resuming triggers.
[11:53:43.372] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[11:54:13.369] INFO: Resuming triggers.
[11:54:20.575] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[11:54:50.728] INFO: Resuming triggers.
[11:54:57.338] INFO: data taking finished, elapsed time: 100 seconds.
[11:55:25.225] INFO: PixTest:: pg_setup set to default.
[11:55:25.228] INFO: PixTestXray::doPhRun() done
[11:55:25.373] INFO: enter test to run
[11:56:14.683] INFO: test: exit no parameter change
[11:56:14.980] QUIET: Connection to board 33 closed.
[11:56:14.981] INFO: pXar: this is the end, my friend