[14:25:51.023] INFO: *** Welcome to pxar ***
[14:25:51.023] INFO: *** Today: 2016/10/18
[14:25:51.044] INFO: *** Version: v1.9.0-818-g96727
[14:25:51.044] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//dacParameters35_C15.dat
[14:25:51.045] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:25:51.045] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//defaultMaskFile.dat
[14:25:51.045] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C15.dat
[14:25:51.122] INFO: clk: 4
[14:25:51.122] INFO: ctr: 4
[14:25:51.122] INFO: sda: 19
[14:25:51.122] INFO: tin: 9
[14:25:51.122] INFO: level: 15
[14:25:51.122] INFO: triggerdelay: 0
[14:25:51.122] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:25:51.122] INFO: Log level: INFO
[14:25:51.140] QUIET: Connection to board DTB_WREKRL opened.
[14:25:51.143] 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:25:51.146] INFO: RPC call hashes of host and DTB match: 398089610
[14:25:52.674] INFO: DUT info:
[14:25:52.674] INFO: The DUT currently contains the following objects:
[14:25:52.674] INFO: 2 TBM Cores tbm08c (2 ON)
[14:25:52.674] INFO: TBM Core alpha (0): 7 registers set
[14:25:52.674] INFO: TBM Core beta (1): 7 registers set
[14:25:52.674] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:25:52.674] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.674] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.675] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.675] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:52.675] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:25:53.078] INFO: enter 'restricted' command line mode
[14:25:53.078] INFO: enter test to run
[14:26:24.457] INFO: test: PixelAlive no parameter change
[14:26:24.457] INFO: running: pixelalive
[14:26:24.480] INFO: ----------------------------------------------------------------------
[14:26:24.480] 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:26:24.480] INFO: ----------------------------------------------------------------------
[14:26:24.833] INFO: Expecting 41600 events.
[14:26:29.171] INFO: 41600 events read in total (3620ms).
[14:26:29.323] INFO: Test took 4820ms.
[14:26:29.335] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:29.632] INFO: PixTestAlive::aliveTest() done
[14:26:29.632] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:26:29.664] INFO: enter test to run
[14:26:38.273] INFO: test: timing no parameter change
[14:26:38.273] INFO: running: timing
[14:26:38.295] INFO: ######################################################################
[14:26:38.295] INFO: PixTestTiming::doTest()
[14:26:38.295] INFO: ######################################################################
[14:26:38.295] INFO: ----------------------------------------------------------------------
[14:26:38.295] INFO: PixTestTiming::TBMPhaseScan()
[14:26:38.296] INFO: ----------------------------------------------------------------------
[14:31:05.905] INFO: TBM Phase Settings: 248
[14:31:05.905] INFO: 400MHz Phase: 6
[14:31:05.905] INFO: 160MHz Phase: 7
[14:31:05.905] INFO: Functional Phase Area: 4
[14:31:05.908] INFO: Test took 267613 ms.
[14:31:05.908] INFO: PixTestTiming::TBMPhaseScan() done.
[14:31:05.908] INFO: ----------------------------------------------------------------------
[14:31:05.908] INFO: PixTestTiming::ROCDelayScan()
[14:31:05.908] INFO: ----------------------------------------------------------------------
[14:33:19.069] INFO: ROC Delay Settings: 228
[14:33:19.070] INFO: ROC Header-Trailer/Token Delay: 11
[14:33:19.070] INFO: ROC Port 0 Delay: 4
[14:33:19.070] INFO: ROC Port 1 Delay: 4
[14:33:19.070] INFO: Functional ROC Area: 5
[14:33:19.073] INFO: Test took 133165 ms.
[14:33:19.073] INFO: PixTestTiming::ROCDelayScan() done.
[14:33:19.073] INFO: ----------------------------------------------------------------------
[14:33:19.073] INFO: PixTestTiming::TimingTest()
[14:33:19.073] INFO: ----------------------------------------------------------------------
[14:33:35.413] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:50.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:05.899] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:21.059] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:36.177] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:51.489] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:06.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:22.147] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:37.397] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:52.457] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:52.835] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:52.852] INFO: ----------------------------------------------------------------------
[14:35:52.852] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:35:52.852] INFO: ----------------------------------------------------------------------
[14:35:52.852] INFO: ----------------------------------------------------------------------
[14:35:52.852] INFO: Read back bit status: 1
[14:35:52.852] INFO: ----------------------------------------------------------------------
[14:35:52.852] INFO: ----------------------------------------------------------------------
[14:35:52.852] INFO: Timings are good!
[14:35:52.852] INFO: ----------------------------------------------------------------------
[14:35:52.852] INFO: Test took 153779 ms.
[14:35:52.852] INFO: PixTestTiming::TimingTest() done.
[14:35:52.868] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:35:52.869] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:35:52.869] INFO: PixTestTiming::doTest took 554577 ms.
[14:35:52.869] INFO: PixTestTiming::doTest() done
[14:35:52.869] INFO: Write out TBMPhaseScan_0_V0
[14:35:52.869] INFO: Write out TBMPhaseScan_1_V0
[14:35:52.869] INFO: Write out CombinedTBMPhaseScan_V0
[14:35:52.870] INFO: Write out ROCDelayScan3_V0
[14:35:52.870] INFO: enter test to run
[14:36:32.437] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:36:32.437] INFO: running: highrate
[14:36:32.437] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:36:32.650] INFO: ----------------------------------------------------------------------
[14:36:32.650] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:36:32.650] INFO: ----------------------------------------------------------------------
[14:36:32.650] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:36:32.668] INFO: edge/corner pixel THR is adjusted
[14:36:32.668] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:36:33.626] INFO: Collecting data for 5 seconds...
[14:36:38.643] INFO: Done with hot pixel readout









[14:36:50.613] INFO: PixTest:: pg_setup set to default.




















[14:36:50.614] INFO: 50 hot pixels found in step 0
[14:36:51.609] INFO: Collecting data for 5 seconds...
[14:36:56.626] INFO: Done with hot pixel readout
[14:37:08.591] INFO: PixTest:: pg_setup set to default.































[14:37:08.592] INFO: 59 hot pixels found in step 1
[14:37:09.586] INFO: Collecting data for 5 seconds...
[14:37:14.604] INFO: Done with hot pixel readout


















[14:37:26.554] INFO: PixTest:: pg_setup set to default.
























[14:37:26.555] INFO: 54 hot pixels found in step 2
[14:37:27.550] INFO: Collecting data for 5 seconds...
[14:37:32.568] INFO: Done with hot pixel readout









[14:37:44.476] INFO: PixTest:: pg_setup set to default.


























[14:37:44.477] INFO: 48 hot pixels found in step 3
[14:37:45.472] INFO: Collecting data for 5 seconds...
[14:37:50.490] INFO: Done with hot pixel readout






















































[14:38:02.435] INFO: PixTest:: pg_setup set to default.




















[14:38:02.436] INFO: 47 hot pixels found in step 4
[14:38:03.430] INFO: Collecting data for 5 seconds...
[14:38:08.448] INFO: Done with hot pixel readout









[14:38:20.434] INFO: PixTest:: pg_setup set to default.


























[14:38:20.435] INFO: 61 hot pixels found in step 5
[14:38:21.430] INFO: Collecting data for 5 seconds...
[14:38:26.448] INFO: Done with hot pixel readout
[14:38:38.442] INFO: PixTest:: pg_setup set to default.


























[14:38:38.443] INFO: 46 hot pixels found in step 6
[14:38:39.441] INFO: Collecting data for 5 seconds...
[14:38:44.459] INFO: Done with hot pixel readout






















































[14:38:56.426] INFO: PixTest:: pg_setup set to default.


























[14:38:56.428] INFO: 48 hot pixels found in step 7
[14:38:57.421] INFO: Collecting data for 5 seconds...
[14:39:02.438] INFO: Done with hot pixel readout


















[14:39:14.321] INFO: PixTest:: pg_setup set to default.
























[14:39:14.322] INFO: 44 hot pixels found in step 8
[14:39:15.315] INFO: Collecting data for 5 seconds...
[14:39:20.334] INFO: Done with hot pixel readout









[14:39:32.238] INFO: PixTest:: pg_setup set to default.
























[14:39:32.239] INFO: 43 hot pixels found in step 9
[14:39:33.233] INFO: Collecting data for 5 seconds...
[14:39:38.250] INFO: Done with hot pixel readout


















[14:39:50.182] INFO: PixTest:: pg_setup set to default.

























[14:39:50.183] INFO: 53 hot pixels found in step 10
[14:39:51.177] INFO: Collecting data for 5 seconds...
[14:39:56.194] INFO: Done with hot pixel readout













































[14:40:08.074] INFO: PixTest:: pg_setup set to default.





















[14:40:08.076] INFO: 49 hot pixels found in step 11
[14:40:09.070] INFO: Collecting data for 5 seconds...
[14:40:14.088] INFO: Done with hot pixel readout














































[14:40:25.986] INFO: PixTest:: pg_setup set to default.























[14:40:25.987] INFO: 41 hot pixels found in step 12
[14:40:26.983] INFO: Collecting data for 5 seconds...
[14:40:31.001] INFO: Done with hot pixel readout



























[14:40:43.979] INFO: PixTest:: pg_setup set to default.


























[14:40:43.980] INFO: 38 hot pixels found in step 13
[14:40:44.974] INFO: Collecting data for 5 seconds...
[14:40:49.991] INFO: Done with hot pixel readout









[14:41:01.871] INFO: PixTest:: pg_setup set to default.
























[14:41:01.872] INFO: 46 hot pixels found in step 14
[14:41:01.911] INFO: 46 hot pixels could not be trimmed and have been masked.
[14:41:01.915] INFO: PixTest::trimHotPixels() done
[14:41:01.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C0.dat
[14:41:01.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C1.dat
[14:41:01.927] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C2.dat
[14:41:01.933] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C3.dat
[14:41:01.939] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C4.dat
[14:41:01.944] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C5.dat
[14:41:01.949] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C6.dat
[14:41:01.955] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C7.dat
[14:41:01.960] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C8.dat
[14:41:01.966] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C9.dat
[14:41:01.971] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C10.dat
[14:41:01.977] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C11.dat
[14:41:01.982] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C12.dat
[14:41:01.987] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C13.dat
[14:41:01.993] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C14.dat
[14:41:01.998] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C15.dat
[14:41:01.003] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//defaultMaskFile.dat
[14:41:02.013] INFO: enter test to run
[14:42:47.490] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:42:47.490] INFO: running: highrate
[14:42:47.494] INFO: ----------------------------------------------------------------------
[14:42:47.494] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:42:47.494] INFO: ----------------------------------------------------------------------
[14:42:47.494] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:42:47.494] INFO: edge/corner pixel THR is adjusted
[14:42:47.494] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:42:48.451] INFO: Collecting data for 1 seconds...
[14:42:49.455] INFO: Done with hot pixel readout













































[14:42:53.672] INFO: PixTest:: pg_setup set to default.
[14:42:53.673] INFO: 0 hot pixels found in step 0
[14:42:53.678] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:42:53.762] INFO: PixTest::trimHotPixels() done
[14:42:53.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C0.dat
[14:42:53.774] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C1.dat
[14:42:53.780] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C2.dat
[14:42:53.785] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C3.dat
[14:42:53.791] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C4.dat
[14:42:53.796] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C5.dat
[14:42:53.801] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C6.dat
[14:42:53.806] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C7.dat
[14:42:53.812] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C8.dat
[14:42:53.817] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C9.dat
[14:42:53.822] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C10.dat
[14:42:53.827] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C11.dat
[14:42:53.833] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C12.dat
[14:42:53.838] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C13.dat
[14:42:53.843] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C14.dat
[14:42:53.848] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//trimParameters35_C15.dat
[14:42:53.854] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-06_FPIXTest-17C-FNAL-161006-1133-150V_2016-10-06_11h36m_1475771765/000_FPIXTest_p17//defaultMaskFile.dat
[14:42:53.864] INFO: enter test to run
[14:43:49.242] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:43:49.242] INFO: running: xray
[14:43:49.243] INFO: ----------------------------------------------------------------------
[14:43:49.243] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:43:49.243] INFO: ----------------------------------------------------------------------
[14:43:50.207] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:44:01.259] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.























































[14:44:31.340] INFO: Resuming triggers.
[14:44:42.396] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.




































[14:45:12.300] INFO: Resuming triggers.
[14:45:23.351] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.



























[14:45:52.981] INFO: Resuming triggers.
[14:46:04.036] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.



























[14:46:33.967] INFO: Resuming triggers.
[14:46:45.022] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.








































































[14:47:15.710] INFO: Resuming triggers.
[14:47:26.767] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.









































































[14:47:57.668] INFO: Resuming triggers.
[14:48:08.725] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.






























[14:48:39.269] INFO: Resuming triggers.
[14:48:50.325] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.




























































































[14:49:19.982] INFO: Resuming triggers.
[14:49:31.033] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.


















[14:50:00.679] INFO: Resuming triggers.
[14:50:01.562] INFO: data taking finished, elapsed time: 100 seconds.
[14:50:04.301] INFO: PixTest:: pg_setup set to default.
[14:50:04.304] INFO: PixTestXray::doPhRun() done
[14:50:04.492] INFO: enter test to run
[14:50:25.487] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:50:25.487] INFO: running: xray
[14:50:25.488] INFO: ----------------------------------------------------------------------
[14:50:25.488] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:50:25.488] INFO: ----------------------------------------------------------------------
[14:50:26.461] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:50:32.729] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.




















































































































[14:51:01.794] INFO: Resuming triggers.
[14:51:08.064] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.


























[14:51:34.765] INFO: Resuming triggers.
[14:51:41.036] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.












[14:52:07.853] INFO: Resuming triggers.
[14:52:14.125] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.








[14:52:40.858] INFO: Resuming triggers.
[14:52:47.127] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.












[14:53:13.877] INFO: Resuming triggers.
[14:53:20.147] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.









[14:53:46.969] INFO: Resuming triggers.
[14:53:53.236] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.










[14:54:19.994] INFO: Resuming triggers.
[14:54:26.265] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.

















[14:54:53.653] INFO: Resuming triggers.
[14:54:59.921] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.












[14:55:26.932] INFO: Resuming triggers.
[14:55:33.198] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.














[14:56:00.451] INFO: Resuming triggers.
[14:56:06.715] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.






































[14:56:33.607] INFO: Resuming triggers.
[14:56:39.873] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.















[14:57:07.286] INFO: Resuming triggers.
[14:57:13.552] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.















[14:57:40.971] INFO: Resuming triggers.
[14:57:47.235] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.



















[14:58:14.894] INFO: Resuming triggers.
[14:58:21.156] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.








[14:58:48.587] INFO: Resuming triggers.
[14:58:54.850] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.




















[14:59:22.171] INFO: Resuming triggers.
[14:59:22.246] INFO: data taking finished, elapsed time: 100 seconds.
[14:59:23.056] INFO: PixTest:: pg_setup set to default.
[14:59:23.060] INFO: PixTestXray::doPhRun() done
[14:59:23.269] INFO: enter test to run
[14:59:57.611] INFO: test: HighRate no parameter change
[14:59:57.611] INFO: running: highrate
[14:59:57.653] INFO: ----------------------------------------------------------------------
[14:59:57.653] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:59:57.653] INFO: ----------------------------------------------------------------------
[14:59:57.811] INFO: Expecting 768 events.
[14:59:58.957] INFO: 768 events read in total (431ms).
[14:59:58.957] INFO: Test took 1280ms.
[14:59:59.760] INFO: Expecting 41600 events.
[15:00:02.701] INFO: 41600 events read in total (2415ms).
[15:00:02.702] INFO: Test took 3680ms.
[15:00:02.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:03.458] INFO: Expecting 41600 events.










[15:00:06.448] INFO: 41600 events read in total (2463ms).
[15:00:06.449] INFO: Test took 3629ms.
[15:00:06.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:07.202] INFO: Expecting 41600 events.











[15:00:10.206] INFO: 41600 events read in total (2477ms).
[15:00:10.207] INFO: Test took 3702ms.
[15:00:10.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:10.962] INFO: Expecting 41600 events.











[15:00:13.974] INFO: 41600 events read in total (2485ms).
[15:00:13.975] INFO: Test took 3711ms.
[15:00:14.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:14.731] INFO: Expecting 41600 events.
[15:00:17.741] INFO: 41600 events read in total (2483ms).
[15:00:17.742] INFO: Test took 3709ms.
[15:00:17.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:18.489] INFO: Expecting 41600 events.












[15:00:21.517] INFO: 41600 events read in total (2502ms).
[15:00:21.518] INFO: Test took 3718ms.
[15:00:21.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:22.275] INFO: Expecting 41600 events.










[15:00:25.251] INFO: 41600 events read in total (2449ms).
[15:00:25.252] INFO: Test took 3676ms.
[15:00:25.291] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:25.005] INFO: Expecting 41600 events.
[15:00:29.042] INFO: 41600 events read in total (2510ms).
[15:00:29.043] INFO: Test took 3731ms.
[15:00:29.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:29.794] INFO: Expecting 41600 events.











[15:00:32.932] INFO: 41600 events read in total (2610ms).
[15:00:32.933] INFO: Test took 3833ms.
[15:00:32.971] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:33.686] INFO: Expecting 41600 events.









[15:00:36.698] INFO: 41600 events read in total (2485ms).
[15:00:36.699] INFO: Test took 3708ms.
[15:00:36.738] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:37.451] INFO: Expecting 41600 events.












[15:00:40.574] INFO: 41600 events read in total (2596ms).
[15:00:40.575] INFO: Test took 3817ms.
[15:00:40.614] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:41.326] INFO: Expecting 41600 events.











[15:00:44.324] INFO: 41600 events read in total (2471ms).
[15:00:44.325] INFO: Test took 3692ms.
[15:00:44.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:45.081] INFO: Expecting 41600 events.
[15:00:48.091] INFO: 41600 events read in total (2483ms).
[15:00:48.092] INFO: Test took 3711ms.
[15:00:48.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:48.848] INFO: Expecting 41600 events.
[15:00:51.883] INFO: 41600 events read in total (2508ms).
[15:00:51.884] INFO: Test took 3735ms.
[15:00:51.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:52.640] INFO: Expecting 41600 events.










[15:00:55.551] INFO: 41600 events read in total (2384ms).
[15:00:55.552] INFO: Test took 3610ms.
[15:00:55.592] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:56.305] INFO: Expecting 41600 events.

































[15:00:59.417] INFO: 41600 events read in total (2585ms).
[15:00:59.418] INFO: Test took 3807ms.
[15:00:59.457] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:00.172] INFO: Expecting 41600 events.
[15:01:03.208] INFO: 41600 events read in total (2509ms).
[15:01:03.209] INFO: Test took 3732ms.
[15:01:03.247] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:03.959] INFO: Expecting 41600 events.


[15:01:06.985] INFO: 41600 events read in total (2499ms).
[15:01:06.986] INFO: Test took 3720ms.
[15:01:07.025] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:07.738] INFO: Expecting 41600 events.


[15:01:10.733] INFO: 41600 events read in total (2468ms).
[15:01:10.734] INFO: Test took 3690ms.
[15:01:10.773] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:11.489] INFO: Expecting 41600 events.


[15:01:14.320] INFO: 41600 events read in total (2304ms).
[15:01:14.322] INFO: Test took 3530ms.
[15:01:14.361] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:14.722] INFO: enter test to run
[15:01:23.426] INFO: test: HighRate no parameter change
[15:01:23.427] INFO: running: highrate
[15:01:23.428] INFO: ----------------------------------------------------------------------
[15:01:23.428] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:01:23.428] INFO: ----------------------------------------------------------------------
[15:01:24.060] INFO: Expecting 208000 events.
[15:01:34.966] INFO: 208000 events read in total (10379ms).
[15:01:34.970] INFO: Test took 11523ms.
[15:01:35.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:35.400] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 130 0 0 0
[15:01:35.418] INFO: number of red-efficiency pixels: 97 63 83 140 155 172 211 115 122 147 150 116 247 64 21 35
[15:01:35.418] INFO: number of X-ray hits detected: 79403 49414 73751 115677 125839 131671 133492 93165 88824 109786 110915 91683 95027 55013 22200 25123
[15:01:35.418] 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:01:35.418] INFO: number of Vcal hits detected: 207901 207935 207911 207859 207842 207826 207781 207883 207875 207851 207846 207880 201383 207936 207979 207965
[15:01:35.418] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:01:35.418] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 96.8 100.0 100.0 100.0
[15:01:35.418] INFO: X-ray hit rate [MHz/cm2]: 23.3 14.5 21.6 33.9 36.9 38.6 39.1 27.3 26.0 32.2 32.5 26.9 27.9 16.1 6.5 7.4
[15:01:35.418] INFO: PixTestHighRate::doXPixelAlive() done
[15:01:35.464] INFO: PixTest:: pg_setup set to default.
[15:01:35.481] INFO: enter test to run
[15:01:55.194] INFO: test: HighRate no parameter change
[15:01:55.194] INFO: running: highrate
[15:01:55.195] INFO: ----------------------------------------------------------------------
[15:01:55.195] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:01:55.195] INFO: ----------------------------------------------------------------------
[15:01:55.820] INFO: Expecting 208000 events.








































































































[15:02:08.741] INFO: 208000 events read in total (12395ms).
[15:02:08.747] INFO: Test took 13543ms.
[15:02:09.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:09.397] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 134 0 0 0
[15:02:09.397] INFO: number of red-efficiency pixels: 348 134 279 457 561 582 803 396 377 466 538 306 495 216 62 60
[15:02:09.398] INFO: number of X-ray hits detected: 161360 101845 151863 236432 258216 270159 272007 191574 181212 225928 226347 188273 194751 113931 46402 51680
[15:02:09.398] 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:02:09.398] INFO: number of Vcal hits detected: 207610 207856 207693 207508 207387 207359 207048 207563 207593 207482 207408 207681 200872 207765 207935 207940
[15:02:09.398] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.9 99.8 99.7 99.7 99.6 99.8 99.8 99.8 99.7 99.9 99.8 99.9 100.0 100.0
[15:02:09.398] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.9 99.8 99.7 99.7 99.5 99.8 99.8 99.8 99.7 99.8 96.6 99.9 100.0 100.0
[15:02:09.398] INFO: X-ray hit rate [MHz/cm2]: 47.3 29.9 44.5 69.3 75.7 79.2 79.7 56.2 53.1 66.2 66.3 55.2 57.1 33.4 13.6 15.1
[15:02:09.398] INFO: PixTestHighRate::doXPixelAlive() done
[15:02:09.442] INFO: PixTest:: pg_setup set to default.
[15:02:09.453] INFO: enter test to run
[15:02:26.162] INFO: test: HighRate no parameter change
[15:02:26.162] INFO: running: highrate
[15:02:26.163] INFO: ----------------------------------------------------------------------
[15:02:26.163] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:02:26.164] INFO: ----------------------------------------------------------------------
[15:02:26.784] INFO: Expecting 208000 events.









[15:02:41.965] INFO: 208000 events read in total (14654ms).
[15:02:41.973] INFO: Test took 15799ms.
[15:02:42.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:42.866] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 142 0 0 0
[15:02:42.866] INFO: number of red-efficiency pixels: 754 313 674 1020 1367 1383 1803 906 853 1121 1263 624 965 526 82 102
[15:02:42.866] INFO: number of X-ray hits detected: 246413 155681 231205 362043 393873 410800 415972 292327 277680 345009 346287 289007 297932 173179 71117 78860
[15:02:42.866] 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:02:42.866] INFO: number of Vcal hits detected: 206956 207632 207067 206725 206172 206139 205178 206781 206941 206623 206356 207274 199929 207346 207908 207896
[15:02:42.866] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.6 99.4 99.2 99.2 98.8 99.5 99.5 99.4 99.3 99.7 99.6 99.7 100.0 99.9
[15:02:42.866] INFO: Vcal hit overall efficiency (%): 99.5 99.8 99.6 99.4 99.1 99.1 98.6 99.4 99.5 99.3 99.2 99.7 96.1 99.7 100.0 100.0
[15:02:42.866] INFO: X-ray hit rate [MHz/cm2]: 72.2 45.6 67.8 106.1 115.4 120.4 121.9 85.7 81.4 101.1 101.5 84.7 87.3 50.8 20.8 23.1
[15:02:42.866] INFO: PixTestHighRate::doXPixelAlive() done
[15:02:42.911] INFO: PixTest:: pg_setup set to default.
[15:02:42.929] INFO: enter test to run
[15:03:12.386] INFO: test: exit no parameter change
[15:03:13.218] QUIET: Connection to board 33 closed.
[15:03:13.394] INFO: pXar: this is the end, my friend