[14:54:13.069] INFO: *** Welcome to pxar ***
[14:54:13.070] INFO: *** Today: 2016/04/28
[14:54:13.449] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:54:13.449] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//dacParameters35_C15.dat
[14:54:13.461] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:54:13.462] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//defaultMaskFile.dat
[14:54:13.462] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C15.dat
[14:54:13.549] INFO: clk: 4
[14:54:13.549] INFO: ctr: 4
[14:54:13.549] INFO: sda: 19
[14:54:13.549] INFO: tin: 9
[14:54:13.549] INFO: level: 15
[14:54:13.549] INFO: triggerdelay: 0
[14:54:13.549] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:54:13.565] INFO: Log level: INFO
[14:54:13.587] QUIET: Connection to board DTB_WREKRL opened.
[14:54:13.591] 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:54:13.594] INFO: RPC call hashes of host and DTB match: 398089610
[14:54:15.132] INFO: DUT info:
[14:54:15.132] INFO: The DUT currently contains the following objects:
[14:54:15.133] INFO: 2 TBM Cores tbm08c (2 ON)
[14:54:15.133] INFO: TBM Core alpha (0): 7 registers set
[14:54:15.133] INFO: TBM Core beta (1): 7 registers set
[14:54:15.133] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:54:15.133] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.133] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.134] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:54:15.556] INFO: enter 'restricted' command line mode
[14:54:15.556] INFO: enter test to run
[14:54:24.933] INFO: test: PixelAlive no parameter change
[14:54:24.933] INFO: running: pixelalive
[14:54:24.974] INFO: ----------------------------------------------------------------------
[14:54:24.974] 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:54:24.974] INFO: ----------------------------------------------------------------------
[14:54:25.301] INFO: Expecting 41600 events.
[14:54:29.632] INFO: 41600 events read in total (3612ms).
[14:54:29.796] INFO: Test took 4818ms.
[14:54:29.806] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:30.080] INFO: PixTestAlive::aliveTest() done
[14:54:30.080] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:54:30.111] INFO: enter test to run
[14:55:16.140] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:55:16.140] INFO: running: highrate
[14:55:16.140] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:55:16.362] INFO: ----------------------------------------------------------------------
[14:55:16.363] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:55:16.363] INFO: ----------------------------------------------------------------------
[14:55:16.363] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:55:16.363] INFO: edge/corner pixel THR is adjusted
[14:55:16.363] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:55:17.339] INFO: Collecting data for 5 seconds...
[14:55:22.354] INFO: Done with hot pixel readout
[14:55:30.406] INFO: PixTest:: pg_setup set to default.
[14:55:30.407] INFO: 0 hot pixels found in step 0
[14:55:30.411] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:55:30.578] INFO: PixTest::trimHotPixels() done
[14:55:30.579] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C0.dat
[14:55:30.590] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C1.dat
[14:55:30.599] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C2.dat
[14:55:30.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C3.dat
[14:55:30.613] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C4.dat
[14:55:30.621] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C5.dat
[14:55:30.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C6.dat
[14:55:30.635] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C7.dat
[14:55:30.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C8.dat
[14:55:30.649] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C9.dat
[14:55:30.656] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C10.dat
[14:55:30.663] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C11.dat
[14:55:30.670] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C12.dat
[14:55:30.677] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C13.dat
[14:55:30.684] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C14.dat
[14:55:30.691] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C15.dat
[14:55:30.698] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//defaultMaskFile.dat
[14:55:30.704] INFO: enter test to run
[14:56:09.644] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:56:09.644] INFO: running: highrate
[14:56:09.648] INFO: ----------------------------------------------------------------------
[14:56:09.648] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:56:09.648] INFO: ----------------------------------------------------------------------
[14:56:09.648] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:56:09.648] INFO: edge/corner pixel THR is adjusted
[14:56:09.648] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:56:10.606] INFO: Collecting data for 5 seconds...
[14:56:15.623] INFO: Done with hot pixel readout
[14:56:27.497] INFO: PixTest:: pg_setup set to default.
[14:56:27.498] INFO: 6 hot pixels found in step 0
[14:56:28.493] INFO: Collecting data for 5 seconds...
[14:56:33.510] INFO: Done with hot pixel readout
[14:56:45.405] INFO: PixTest:: pg_setup set to default.
[14:56:45.406] INFO: 7 hot pixels found in step 1
[14:56:46.400] INFO: Collecting data for 5 seconds...
[14:56:51.417] INFO: Done with hot pixel readout
[14:57:03.305] INFO: PixTest:: pg_setup set to default.
[14:57:03.306] INFO: 3 hot pixels found in step 2
[14:57:04.302] INFO: Collecting data for 5 seconds...
[14:57:09.318] INFO: Done with hot pixel readout
[14:57:21.191] INFO: PixTest:: pg_setup set to default.
[14:57:21.192] INFO: 4 hot pixels found in step 3
[14:57:22.187] INFO: Collecting data for 5 seconds...
[14:57:27.203] INFO: Done with hot pixel readout
[14:57:39.056] INFO: PixTest:: pg_setup set to default.
[14:57:39.057] INFO: 2 hot pixels found in step 4
[14:57:40.052] INFO: Collecting data for 5 seconds...
[14:57:45.069] INFO: Done with hot pixel readout
[14:57:56.959] INFO: PixTest:: pg_setup set to default.
[14:57:56.959] INFO: 0 hot pixels found in step 5
[14:57:56.997] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:57:56.001] INFO: PixTest::trimHotPixels() done
[14:57:56.001] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C0.dat
[14:57:57.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C1.dat
[14:57:57.016] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C2.dat
[14:57:57.023] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C3.dat
[14:57:57.030] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C4.dat
[14:57:57.037] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C5.dat
[14:57:57.044] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C6.dat
[14:57:57.051] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C7.dat
[14:57:57.058] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C8.dat
[14:57:57.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C9.dat
[14:57:57.072] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C10.dat
[14:57:57.079] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C11.dat
[14:57:57.086] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C12.dat
[14:57:57.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C13.dat
[14:57:57.100] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C14.dat
[14:57:57.107] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C15.dat
[14:57:57.114] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//defaultMaskFile.dat
[14:57:57.124] INFO: enter test to run
[14:58:49.443] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:58:49.443] INFO: running: highrate
[14:58:49.447] INFO: ----------------------------------------------------------------------
[14:58:49.447] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:58:49.447] INFO: ----------------------------------------------------------------------
[14:58:49.447] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:58:49.447] INFO: edge/corner pixel THR is adjusted
[14:58:49.447] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:58:50.405] INFO: Collecting data for 1 seconds...
[14:58:51.408] INFO: Done with hot pixel readout
[14:58:55.377] INFO: PixTest:: pg_setup set to default.
[14:58:55.378] INFO: 0 hot pixels found in step 0
[14:58:55.383] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:58:55.471] INFO: PixTest::trimHotPixels() done
[14:58:55.471] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C0.dat
[14:58:55.484] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C1.dat
[14:58:55.491] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C2.dat
[14:58:55.498] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C3.dat
[14:58:55.505] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C4.dat
[14:58:55.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C5.dat
[14:58:55.520] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C6.dat
[14:58:55.527] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C7.dat
[14:58:55.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C8.dat
[14:58:55.541] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C9.dat
[14:58:55.548] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C10.dat
[14:58:55.555] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C11.dat
[14:58:55.562] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C12.dat
[14:58:55.569] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C13.dat
[14:58:55.576] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C14.dat
[14:58:55.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//trimParameters35_C15.dat
[14:58:55.590] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-11_FPIXTest-17C-FNAL-160427-1301_2016-04-27_13h02m_1461780121/000_FPIXTest_p17//defaultMaskFile.dat
[14:58:55.604] INFO: enter test to run
[14:59:10.738] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:59:10.738] INFO: running: xray
[14:59:10.740] INFO: ----------------------------------------------------------------------
[14:59:10.740] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:59:10.740] INFO: ----------------------------------------------------------------------
[14:59:11.703] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:59:23.272] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:59:52.543] INFO: Resuming triggers.
[15:00:04.112] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:00:33.331] INFO: Resuming triggers.
[15:00:44.894] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:01:14.145] INFO: Resuming triggers.
[15:01:25.718] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:01:54.954] INFO: Resuming triggers.
[15:02:06.517] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:02:35.694] INFO: Resuming triggers.
[15:02:47.267] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[15:03:16.598] INFO: Resuming triggers.
[15:03:28.171] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:03:55.511] INFO: Resuming triggers.
[15:04:07.083] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:04:36.317] INFO: Resuming triggers.
[15:04:44.079] INFO: data taking finished, elapsed time: 100 seconds.
[15:05:03.868] INFO: PixTest:: pg_setup set to default.
[15:05:03.872] INFO: PixTestXray::doPhRun() done
[15:05:04.007] INFO: enter test to run
[15:06:14.351] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:06:14.351] INFO: running: xray
[15:06:14.352] INFO: ----------------------------------------------------------------------
[15:06:14.352] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:06:14.352] INFO: ----------------------------------------------------------------------
[15:06:15.316] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:06:22.214] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:06:52.304] INFO: Resuming triggers.
[15:06:59.204] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:07:29.343] INFO: Resuming triggers.
[15:07:36.241] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:08:06.337] INFO: Resuming triggers.
[15:08:13.233] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[15:08:43.262] INFO: Resuming triggers.
[15:08:50.162] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:09:20.316] INFO: Resuming triggers.
[15:09:27.214] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[15:09:57.343] INFO: Resuming triggers.
[15:10:04.238] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[15:10:34.416] INFO: Resuming triggers.
[15:10:41.315] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:11:11.403] INFO: Resuming triggers.
[15:11:18.298] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[15:11:48.412] INFO: Resuming triggers.
[15:11:55.304] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:12:25.451] INFO: Resuming triggers.
[15:12:32.342] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[15:13:02.344] INFO: Resuming triggers.
[15:13:09.239] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[15:13:39.357] INFO: Resuming triggers.
[15:13:46.254] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:14:12.430] INFO: Resuming triggers.
[15:14:19.329] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[15:14:49.466] INFO: Resuming triggers.
[15:14:53.237] INFO: data taking finished, elapsed time: 100 seconds.
[15:15:09.932] INFO: PixTest:: pg_setup set to default.
[15:15:09.935] INFO: PixTestXray::doPhRun() done
[15:15:10.085] INFO: enter test to run
[15:15:57.035] INFO: test: HighRate no parameter change
[15:15:57.035] INFO: running: highrate
[15:15:57.036] INFO: ----------------------------------------------------------------------
[15:15:57.036] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:15:57.036] INFO: ----------------------------------------------------------------------
[15:15:57.177] INFO: Expecting 768 events.
[15:15:58.310] INFO: 768 events read in total (418ms).
[15:15:58.311] INFO: Test took 1269ms.
[15:15:59.114] INFO: Expecting 41600 events.
[15:16:02.179] INFO: 41600 events read in total (2538ms).
[15:16:02.180] INFO: Test took 3861ms.
[15:16:02.212] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:02.939] INFO: Expecting 41600 events.
[15:16:06.100] INFO: 41600 events read in total (2634ms).
[15:16:06.101] INFO: Test took 3872ms.
[15:16:06.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:06.863] INFO: Expecting 41600 events.
[15:16:10.068] INFO: 41600 events read in total (2679ms).
[15:16:10.069] INFO: Test took 3917ms.
[15:16:10.102] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:10.825] INFO: Expecting 41600 events.
[15:16:14.043] INFO: 41600 events read in total (2691ms).
[15:16:14.044] INFO: Test took 3923ms.
[15:16:14.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:14.803] INFO: Expecting 41600 events.
[15:16:17.992] INFO: 41600 events read in total (2662ms).
[15:16:17.993] INFO: Test took 3898ms.
[15:16:18.025] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:18.753] INFO: Expecting 41600 events.
[15:16:21.941] INFO: 41600 events read in total (2661ms).
[15:16:21.942] INFO: Test took 3898ms.
[15:16:21.974] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:22.704] INFO: Expecting 41600 events.
[15:16:25.932] INFO: 41600 events read in total (2701ms).
[15:16:25.934] INFO: Test took 3941ms.
[15:16:25.966] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:26.691] INFO: Expecting 41600 events.
[15:16:29.918] INFO: 41600 events read in total (2700ms).
[15:16:29.919] INFO: Test took 3936ms.
[15:16:29.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:30.679] INFO: Expecting 41600 events.
[15:16:33.890] INFO: 41600 events read in total (2684ms).
[15:16:33.891] INFO: Test took 3921ms.
[15:16:33.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:34.652] INFO: Expecting 41600 events.
[15:16:37.887] INFO: 41600 events read in total (2708ms).
[15:16:37.888] INFO: Test took 3946ms.
[15:16:37.920] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:38.647] INFO: Expecting 41600 events.
[15:16:41.870] INFO: 41600 events read in total (2696ms).
[15:16:41.871] INFO: Test took 3933ms.
[15:16:41.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:42.629] INFO: Expecting 41600 events.
[15:16:45.845] INFO: 41600 events read in total (2689ms).
[15:16:45.846] INFO: Test took 3925ms.
[15:16:45.878] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:46.608] INFO: Expecting 41600 events.
[15:16:49.848] INFO: 41600 events read in total (2713ms).
[15:16:49.849] INFO: Test took 3952ms.
[15:16:49.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:50.606] INFO: Expecting 41600 events.
[15:16:53.822] INFO: 41600 events read in total (2689ms).
[15:16:53.823] INFO: Test took 3923ms.
[15:16:53.856] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:54.581] INFO: Expecting 41600 events.
[15:16:57.806] INFO: 41600 events read in total (2698ms).
[15:16:57.807] INFO: Test took 3934ms.
[15:16:57.840] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:58.567] INFO: Expecting 41600 events.
[15:17:01.777] INFO: 41600 events read in total (2683ms).
[15:17:01.778] INFO: Test took 3921ms.
[15:17:01.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:02.536] INFO: Expecting 41600 events.
[15:17:05.765] INFO: 41600 events read in total (2702ms).
[15:17:05.766] INFO: Test took 3938ms.
[15:17:05.798] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:06.526] INFO: Expecting 41600 events.
[15:17:09.746] INFO: 41600 events read in total (2693ms).
[15:17:09.747] INFO: Test took 3931ms.
[15:17:09.779] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:10.507] INFO: Expecting 41600 events.
[15:17:13.661] INFO: 41600 events read in total (2627ms).
[15:17:13.662] INFO: Test took 3865ms.
[15:17:13.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:14.425] INFO: Expecting 41600 events.
[15:17:17.511] INFO: 41600 events read in total (2559ms).
[15:17:17.511] INFO: Test took 3798ms.
[15:17:17.544] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:17.920] INFO: enter test to run
[15:17:57.370] INFO: test: HighRate no parameter change
[15:17:57.370] INFO: running: highrate
[15:17:57.371] INFO: ----------------------------------------------------------------------
[15:17:57.371] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:17:57.371] INFO: ----------------------------------------------------------------------
[15:17:57.989] INFO: Expecting 208000 events.
[15:18:09.787] INFO: 208000 events read in total (11271ms).
[15:18:09.790] INFO: Test took 12409ms.
[15:18:09.926] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:10.175] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:18:10.175] INFO: number of red-efficiency pixels: 61 51 92 73 122 133 134 80 99 97 116 71 77 63 27 37
[15:18:10.175] INFO: number of X-ray hits detected: 55805 41695 63870 99265 110516 112316 102597 73021 72057 93906 92383 82837 81956 49920 21460 27107
[15:18:10.175] 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:18:10.175] INFO: number of Vcal hits detected: 207938 207949 207905 207927 207877 207863 207864 207919 207899 207903 207880 207926 207922 207936 207969 207962
[15:18:10.175] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[15:18:10.175] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[15:18:10.175] INFO: X-ray hit rate [MHz/cm2]: 16.4 12.2 18.7 29.1 32.4 32.9 30.1 21.4 21.1 27.5 27.1 24.3 24.0 14.6 6.3 7.9
[15:18:10.175] INFO: PixTestHighRate::doXPixelAlive() done
[15:18:10.224] INFO: PixTest:: pg_setup set to default.
[15:18:10.241] INFO: enter test to run
[15:18:52.898] INFO: test: HighRate no parameter change
[15:18:52.898] INFO: running: highrate
[15:18:52.899] INFO: ----------------------------------------------------------------------
[15:18:52.899] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:18:52.899] INFO: ----------------------------------------------------------------------
[15:18:53.519] INFO: Expecting 208000 events.
[15:19:07.164] INFO: 208000 events read in total (13118ms).
[15:19:07.169] INFO: Test took 14260ms.
[15:19:07.470] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:07.770] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:19:07.770] INFO: number of red-efficiency pixels: 185 141 309 419 457 481 506 332 289 362 440 359 344 223 52 75
[15:19:07.770] INFO: number of X-ray hits detected: 125553 92311 142390 220324 246058 250419 227927 163392 161107 208173 206333 183885 183207 111598 48162 60178
[15:19:07.770] 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:19:07.770] INFO: number of Vcal hits detected: 207803 207855 207652 207549 207505 207478 207441 207631 207688 207615 207526 207623 207629 207763 207940 207924
[15:19:07.770] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:19:07.770] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:19:07.770] INFO: X-ray hit rate [MHz/cm2]: 36.8 27.1 41.7 64.6 72.1 73.4 66.8 47.9 47.2 61.0 60.5 53.9 53.7 32.7 14.1 17.6
[15:19:07.770] INFO: PixTestHighRate::doXPixelAlive() done
[15:19:07.815] INFO: PixTest:: pg_setup set to default.
[15:19:07.832] INFO: enter test to run
[15:19:38.753] INFO: test: HighRate no parameter change
[15:19:38.753] INFO: running: highrate
[15:19:38.755] INFO: ----------------------------------------------------------------------
[15:19:38.755] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:19:38.755] INFO: ----------------------------------------------------------------------
[15:19:39.370] INFO: Expecting 208000 events.
[15:19:55.017] INFO: 208000 events read in total (15120ms).
[15:19:55.024] INFO: Test took 16260ms.
[15:19:55.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:55.836] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:19:55.836] INFO: number of red-efficiency pixels: 472 296 714 953 1105 1170 1259 760 658 799 978 766 796 509 80 101
[15:19:55.836] INFO: number of X-ray hits detected: 190858 140528 216525 336504 374021 379523 345198 248354 246190 316525 313090 280083 279080 169211 73269 91857
[15:19:55.836] 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:19:55.836] INFO: number of Vcal hits detected: 207442 207668 206998 206847 206635 206473 206386 207026 207219 207077 206791 207083 207070 207391 207911 207896
[15:19:55.836] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.5 99.4 99.3 99.3 99.6 99.7 99.6 99.5 99.6 99.6 99.7 100.0 100.0
[15:19:55.836] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.4 99.3 99.3 99.2 99.5 99.6 99.6 99.4 99.6 99.6 99.7 100.0 100.0
[15:19:55.836] INFO: X-ray hit rate [MHz/cm2]: 55.9 41.2 63.5 98.6 109.6 111.2 101.2 72.8 72.2 92.8 91.8 82.1 81.8 49.6 21.5 26.9
[15:19:55.836] INFO: PixTestHighRate::doXPixelAlive() done
[15:19:55.888] INFO: PixTest:: pg_setup set to default.
[15:19:55.905] INFO: enter test to run
[15:19:59.537] INFO: test: exit no parameter change
[15:19:59.928] QUIET: Connection to board 33 closed.
[15:19:59.929] INFO: pXar: this is the end, my friend