[12:05:55.870] INFO: *** Welcome to pxar ***
[12:05:55.870] INFO: *** Today: 2016/07/08
[12:05:55.895] INFO: *** Version: v1.9.0-814-g7497
[12:05:55.895] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//dacParameters35_C15.dat
[12:05:55.896] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:05:55.896] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//defaultMaskFile.dat
[12:05:55.896] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C15.dat
[12:05:55.986] INFO: clk: 4
[12:05:55.986] INFO: ctr: 4
[12:05:55.986] INFO: sda: 19
[12:05:55.986] INFO: tin: 9
[12:05:55.986] INFO: level: 15
[12:05:55.986] INFO: triggerdelay: 0
[12:05:55.986] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:05:55.986] INFO: Log level: INFO
[12:05:55.001] QUIET: Connection to board DTB_WREKRL opened.
[12:05:56.004] 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:
------------------------------------------------------
[12:05:56.007] INFO: RPC call hashes of host and DTB match: 398089610
[12:05:57.547] INFO: DUT info:
[12:05:57.547] INFO: The DUT currently contains the following objects:
[12:05:57.547] INFO: 2 TBM Cores tbm08c (2 ON)
[12:05:57.547] INFO: TBM Core alpha (0): 7 registers set
[12:05:57.547] INFO: TBM Core beta (1): 7 registers set
[12:05:57.547] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:05:57.547] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.547] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.548] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:05:57.951] INFO: enter 'restricted' command line mode
[12:05:57.951] INFO: enter test to run
[12:06:02.147] INFO: test: timing no parameter change
[12:06:02.147] INFO: running: timing
[12:06:02.155] INFO: ######################################################################
[12:06:02.156] INFO: PixTestTiming::doTest()
[12:06:02.156] INFO: ######################################################################
[12:06:02.156] INFO: ----------------------------------------------------------------------
[12:06:02.156] INFO: PixTestTiming::TBMPhaseScan()
[12:06:02.156] INFO: ----------------------------------------------------------------------
[12:12:21.280] INFO: TBM Phase Settings: 236
[12:12:21.280] INFO: 400MHz Phase: 3
[12:12:21.280] INFO: 160MHz Phase: 7
[12:12:21.280] INFO: Functional Phase Area: 4
[12:12:21.303] INFO: Test took 379147 ms.
[12:12:21.303] INFO: PixTestTiming::TBMPhaseScan() done.
[12:12:21.303] INFO: ----------------------------------------------------------------------
[12:12:21.303] INFO: PixTestTiming::ROCDelayScan()
[12:12:21.303] INFO: ----------------------------------------------------------------------
[12:15:47.299] INFO: ROC Delay Settings: 228
[12:15:47.299] INFO: ROC Header-Trailer/Token Delay: 11
[12:15:47.299] INFO: ROC Port 0 Delay: 4
[12:15:47.300] INFO: ROC Port 1 Delay: 4
[12:15:47.300] INFO: Functional ROC Area: 5
[12:15:47.303] INFO: Test took 206000 ms.
[12:15:47.303] INFO: PixTestTiming::ROCDelayScan() done.
[12:15:47.303] INFO: ----------------------------------------------------------------------
[12:15:47.303] INFO: PixTestTiming::TimingTest()
[12:15:47.303] INFO: ----------------------------------------------------------------------
[12:16:03.482] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:18.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:33.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:48.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:03.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:18.833] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:33.988] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:49.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:04.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:19.359] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:19.738] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:19.757] INFO: ----------------------------------------------------------------------
[12:18:19.757] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:18:19.757] INFO: ----------------------------------------------------------------------
[12:18:19.757] INFO: ----------------------------------------------------------------------
[12:18:19.757] INFO: Read back bit status: 1
[12:18:19.757] INFO: ----------------------------------------------------------------------
[12:18:19.757] INFO: ----------------------------------------------------------------------
[12:18:19.757] INFO: Timings are good!
[12:18:19.757] INFO: ----------------------------------------------------------------------
[12:18:19.757] INFO: Test took 152454 ms.
[12:18:19.757] INFO: PixTestTiming::TimingTest() done.
[12:18:19.757] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:18:19.757] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:18:19.758] INFO: PixTestTiming::doTest took 737607 ms.
[12:18:19.758] INFO: PixTestTiming::doTest() done
[12:18:19.758] INFO: Write out TBMPhaseScan_0_V0
[12:18:19.803] INFO: Write out TBMPhaseScan_1_V0
[12:18:19.803] INFO: Write out CombinedTBMPhaseScan_V0
[12:18:19.804] INFO: Write out ROCDelayScan3_V0
[12:18:19.804] INFO: enter test to run
[12:18:31.021] INFO: test: PixelAlive no parameter change
[12:18:31.021] INFO: running: pixelalive
[12:18:31.026] INFO: ----------------------------------------------------------------------
[12:18:31.026] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:18:31.026] INFO: ----------------------------------------------------------------------
[12:18:31.352] INFO: Expecting 41600 events.
[12:18:35.690] INFO: 41600 events read in total (3623ms).
[12:18:35.691] INFO: Test took 4663ms.
[12:18:35.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:36.085] INFO: PixTestAlive::aliveTest() done
[12:18:36.085] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 5 0 0 0 0 0 0
[12:18:36.088] INFO: enter test to run
[12:18:57.214] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:18:57.214] INFO: running: highrate
[12:18:57.214] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:18:57.373] INFO: ----------------------------------------------------------------------
[12:18:57.373] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:18:57.373] INFO: ----------------------------------------------------------------------
[12:18:57.373] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:18:57.373] INFO: edge/corner pixel THR is adjusted
[12:18:57.373] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:18:58.330] INFO: Collecting data for 5 seconds...
[12:19:03.349] INFO: Done with hot pixel readout
[12:19:15.666] INFO: PixTest:: pg_setup set to default.







[12:19:15.668] INFO: 109 hot pixels found in step 0
[12:19:16.664] INFO: Collecting data for 5 seconds...
[12:19:21.684] INFO: Done with hot pixel readout
[12:19:34.132] INFO: PixTest:: pg_setup set to default.





[12:19:34.134] INFO: 106 hot pixels found in step 1
[12:19:35.131] INFO: Collecting data for 5 seconds...
[12:19:40.151] INFO: Done with hot pixel readout
[12:19:52.474] INFO: PixTest:: pg_setup set to default.





[12:19:52.475] INFO: 93 hot pixels found in step 2
[12:19:53.472] INFO: Collecting data for 5 seconds...
[12:19:58.493] INFO: Done with hot pixel readout
[12:20:11.026] INFO: PixTest:: pg_setup set to default.






[12:20:11.028] INFO: 102 hot pixels found in step 3
[12:20:12.024] INFO: Collecting data for 5 seconds...
[12:20:17.046] INFO: Done with hot pixel readout
[12:20:29.298] INFO: PixTest:: pg_setup set to default.






[12:20:29.299] INFO: 94 hot pixels found in step 4
[12:20:30.295] INFO: Collecting data for 5 seconds...
[12:20:35.310] INFO: Done with hot pixel readout
[12:20:47.454] INFO: PixTest:: pg_setup set to default.





[12:20:47.455] INFO: 83 hot pixels found in step 5
[12:20:48.450] INFO: Collecting data for 5 seconds...
[12:20:53.467] INFO: Done with hot pixel readout
[12:21:05.717] INFO: PixTest:: pg_setup set to default.




[12:21:05.718] INFO: 72 hot pixels found in step 6
[12:21:06.715] INFO: Collecting data for 5 seconds...
[12:21:11.731] INFO: Done with hot pixel readout
[12:21:23.957] INFO: PixTest:: pg_setup set to default.








[12:21:23.958] INFO: 70 hot pixels found in step 7
[12:21:24.954] INFO: Collecting data for 5 seconds...
[12:21:29.971] INFO: Done with hot pixel readout
[12:21:42.210] INFO: PixTest:: pg_setup set to default.









[12:21:42.211] INFO: 63 hot pixels found in step 8
[12:21:43.207] INFO: Collecting data for 5 seconds...
[12:21:48.224] INFO: Done with hot pixel readout
[12:22:00.451] INFO: PixTest:: pg_setup set to default.










[12:22:00.452] INFO: 66 hot pixels found in step 9
[12:22:01.448] INFO: Collecting data for 5 seconds...
[12:22:06.463] INFO: Done with hot pixel readout
[12:22:18.725] INFO: PixTest:: pg_setup set to default.













[12:22:18.727] INFO: 64 hot pixels found in step 10
[12:22:19.722] INFO: Collecting data for 5 seconds...
[12:22:24.738] INFO: Done with hot pixel readout
[12:22:37.061] INFO: PixTest:: pg_setup set to default.











[12:22:37.062] INFO: 59 hot pixels found in step 11
[12:22:38.058] INFO: Collecting data for 5 seconds...
[12:22:43.074] INFO: Done with hot pixel readout
[12:22:55.324] INFO: PixTest:: pg_setup set to default.










[12:22:55.325] INFO: 52 hot pixels found in step 12
[12:22:56.321] INFO: Collecting data for 5 seconds...
[12:23:01.338] INFO: Done with hot pixel readout
[12:23:13.588] INFO: PixTest:: pg_setup set to default.









[12:23:13.589] INFO: 45 hot pixels found in step 13
[12:23:14.585] INFO: Collecting data for 5 seconds...
[12:23:19.601] INFO: Done with hot pixel readout
[12:23:31.745] INFO: PixTest:: pg_setup set to default.












[12:23:31.747] INFO: 61 hot pixels found in step 14
[12:23:31.787] INFO: 61 hot pixels could not be trimmed and have been masked.
[12:23:31.790] INFO: PixTest::trimHotPixels() done
[12:23:31.790] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C0.dat
[12:23:31.796] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C1.dat
[12:23:31.802] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C2.dat
[12:23:31.807] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C3.dat
[12:23:31.813] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C4.dat
[12:23:31.818] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C5.dat
[12:23:31.824] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C6.dat
[12:23:31.829] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C7.dat
[12:23:31.834] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C8.dat
[12:23:31.840] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C9.dat
[12:23:31.845] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C10.dat
[12:23:31.850] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C11.dat
[12:23:31.856] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C12.dat
[12:23:31.861] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C13.dat
[12:23:31.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C14.dat
[12:23:31.872] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C15.dat
[12:23:31.877] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//defaultMaskFile.dat
[12:23:31.888] INFO: enter test to run
[12:26:03.139] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:26:03.139] INFO: running: highrate
[12:26:03.143] INFO: ----------------------------------------------------------------------
[12:26:03.143] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:26:03.143] INFO: ----------------------------------------------------------------------
[12:26:03.143] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:26:03.143] INFO: edge/corner pixel THR is adjusted
[12:26:03.143] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:26:04.102] INFO: Collecting data for 1 seconds...
[12:26:05.105] INFO: Done with hot pixel readout
[12:26:09.371] INFO: PixTest:: pg_setup set to default.
[12:26:09.372] INFO: 0 hot pixels found in step 0
[12:26:09.377] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:26:09.458] INFO: PixTest::trimHotPixels() done
[12:26:09.458] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C0.dat
[12:26:09.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C1.dat
[12:26:09.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C2.dat
[12:26:09.481] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C3.dat
[12:26:09.486] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C4.dat
[12:26:09.491] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C5.dat
[12:26:09.497] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C6.dat
[12:26:09.502] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C7.dat
[12:26:09.507] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C8.dat
[12:26:09.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C9.dat
[12:26:09.518] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C10.dat
[12:26:09.523] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C11.dat
[12:26:09.529] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C12.dat
[12:26:09.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C13.dat
[12:26:09.539] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C14.dat
[12:26:09.545] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//trimParameters35_C15.dat
[12:26:09.550] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-6-43_FPIXTest-17C-FNAL-160706-1430_2016-07-06_14h30m_1467833412/000_FPIXTest_p17//defaultMaskFile.dat
[12:26:09.560] INFO: enter test to run
[12:26:32.978] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:26:32.978] INFO: running: xray
[12:26:32.980] INFO: ----------------------------------------------------------------------
[12:26:32.980] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:26:32.980] INFO: ----------------------------------------------------------------------
[12:26:33.961] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:26:44.858] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:27:14.299] INFO: Resuming triggers.
[12:27:25.198] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:27:54.827] INFO: Resuming triggers.
[12:28:05.730] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:28:35.599] INFO: Resuming triggers.
[12:28:46.498] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:29:16.272] INFO: Resuming triggers.
[12:29:27.172] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:29:56.894] INFO: Resuming triggers.
[12:30:07.795] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:30:38.550] INFO: Resuming triggers.
[12:30:49.451] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:31:19.939] INFO: Resuming triggers.
[12:31:30.838] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[12:32:01.029] INFO: Resuming triggers.
[12:32:11.928] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[12:32:41.472] INFO: Resuming triggers.
[12:32:43.729] INFO: data taking finished, elapsed time: 100 seconds.
[12:32:50.162] INFO: PixTest:: pg_setup set to default.
[12:32:50.166] INFO: PixTestXray::doPhRun() done
[12:32:50.356] INFO: enter test to run
[12:34:07.367] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:34:07.367] INFO: running: xray
[12:34:07.368] INFO: ----------------------------------------------------------------------
[12:34:07.368] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:34:07.368] INFO: ----------------------------------------------------------------------
[12:34:08.351] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:34:14.511] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:34:44.707] INFO: Resuming triggers.
[12:34:50.863] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:35:21.075] INFO: Resuming triggers.
[12:35:27.235] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[12:35:57.429] INFO: Resuming triggers.
[12:36:03.591] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[12:36:33.695] INFO: Resuming triggers.
[12:36:39.854] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[12:37:10.057] INFO: Resuming triggers.
[12:37:16.216] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[12:37:46.420] INFO: Resuming triggers.
[12:37:52.580] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[12:38:22.778] INFO: Resuming triggers.
[12:38:28.936] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[12:38:59.125] INFO: Resuming triggers.
[12:39:05.285] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[12:39:35.431] INFO: Resuming triggers.
[12:39:41.594] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[12:40:11.827] INFO: Resuming triggers.
[12:40:17.988] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:40:48.900] INFO: Resuming triggers.
[12:40:55.057] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:41:25.775] INFO: Resuming triggers.
[12:41:31.936] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:42:02.907] INFO: Resuming triggers.
[12:42:09.066] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[12:42:40.518] INFO: Resuming triggers.
[12:42:46.676] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[12:43:17.407] INFO: Resuming triggers.
[12:43:23.563] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[12:43:54.078] INFO: Resuming triggers.
[12:43:55.876] INFO: data taking finished, elapsed time: 100 seconds.
[12:44:04.951] INFO: PixTest:: pg_setup set to default.
[12:44:04.955] INFO: PixTestXray::doPhRun() done
[12:44:05.105] INFO: enter test to run
[12:46:36.938] INFO: test: HighRate no parameter change
[12:46:36.938] INFO: running: highrate
[12:46:36.957] INFO: ----------------------------------------------------------------------
[12:46:36.957] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:46:36.957] INFO: ----------------------------------------------------------------------
[12:46:37.120] INFO: Expecting 768 events.
[12:46:38.254] INFO: 768 events read in total (418ms).
[12:46:38.255] INFO: Test took 1269ms.
[12:46:39.058] INFO: Expecting 41600 events.
[12:46:42.218] INFO: 41600 events read in total (2633ms).
[12:46:42.219] INFO: Test took 3939ms.
[12:46:42.257] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:42.979] INFO: Expecting 41600 events.
[12:46:46.216] INFO: 41600 events read in total (2710ms).
[12:46:46.217] INFO: Test took 3939ms.
[12:46:46.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:46.972] INFO: Expecting 41600 events.
[12:46:50.249] INFO: 41600 events read in total (2750ms).
[12:46:50.250] INFO: Test took 3975ms.
[12:46:50.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:51.006] INFO: Expecting 41600 events.
[12:46:54.278] INFO: 41600 events read in total (2746ms).
[12:46:54.279] INFO: Test took 3973ms.
[12:46:54.317] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:55.034] INFO: Expecting 41600 events.
[12:46:58.313] INFO: 41600 events read in total (2752ms).
[12:46:58.314] INFO: Test took 3979ms.
[12:46:58.352] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:59.070] INFO: Expecting 41600 events.
[12:47:02.334] INFO: 41600 events read in total (2737ms).
[12:47:02.335] INFO: Test took 3965ms.
[12:47:02.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:03.092] INFO: Expecting 41600 events.
[12:47:06.378] INFO: 41600 events read in total (2759ms).
[12:47:06.379] INFO: Test took 3988ms.
[12:47:06.418] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:07.135] INFO: Expecting 41600 events.
[12:47:10.410] INFO: 41600 events read in total (2748ms).
[12:47:10.411] INFO: Test took 3975ms.
[12:47:10.449] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:11.168] INFO: Expecting 41600 events.
[12:47:14.454] INFO: 41600 events read in total (2759ms).
[12:47:14.455] INFO: Test took 3986ms.
[12:47:14.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:15.212] INFO: Expecting 41600 events.
[12:47:18.505] INFO: 41600 events read in total (2766ms).
[12:47:18.506] INFO: Test took 3994ms.
[12:47:18.543] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:19.259] INFO: Expecting 41600 events.
[12:47:22.539] INFO: 41600 events read in total (2754ms).
[12:47:22.540] INFO: Test took 3978ms.
[12:47:22.578] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:23.294] INFO: Expecting 41600 events.
[12:47:26.571] INFO: 41600 events read in total (2750ms).
[12:47:26.572] INFO: Test took 3975ms.
[12:47:26.610] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:27.326] INFO: Expecting 41600 events.
[12:47:30.613] INFO: 41600 events read in total (2760ms).
[12:47:30.614] INFO: Test took 3985ms.
[12:47:30.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:31.366] INFO: Expecting 41600 events.
[12:47:34.646] INFO: 41600 events read in total (2753ms).
[12:47:34.647] INFO: Test took 3976ms.
[12:47:34.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:35.400] INFO: Expecting 41600 events.
[12:47:38.679] INFO: 41600 events read in total (2752ms).
[12:47:38.680] INFO: Test took 3976ms.
[12:47:38.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:39.434] INFO: Expecting 41600 events.
[12:47:42.709] INFO: 41600 events read in total (2749ms).
[12:47:42.710] INFO: Test took 3973ms.
[12:47:42.747] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:43.462] INFO: Expecting 41600 events.
[12:47:46.744] INFO: 41600 events read in total (2755ms).
[12:47:46.745] INFO: Test took 3979ms.
[12:47:46.783] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:47.497] INFO: Expecting 41600 events.
[12:47:50.776] INFO: 41600 events read in total (2752ms).
[12:47:50.777] INFO: Test took 3974ms.
[12:47:50.814] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:51.533] INFO: Expecting 41600 events.
[12:47:54.781] INFO: 41600 events read in total (2721ms).
[12:47:54.782] INFO: Test took 3949ms.
[12:47:54.819] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:55.536] INFO: Expecting 41600 events.
[12:47:58.641] INFO: 41600 events read in total (2578ms).
[12:47:58.642] INFO: Test took 3804ms.
[12:47:58.678] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:59.030] INFO: enter test to run
[12:48:57.257] INFO: test: HighRate no parameter change
[12:48:57.257] INFO: running: highrate
[12:48:57.258] INFO: ----------------------------------------------------------------------
[12:48:57.258] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:48:57.258] INFO: ----------------------------------------------------------------------
[12:48:57.875] INFO: Expecting 208000 events.
[12:49:09.977] INFO: 208000 events read in total (11575ms).
[12:49:09.980] INFO: Test took 12713ms.
[12:49:10.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:10.407] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 5 0 0 0 0 0 0
[12:49:10.407] INFO: number of red-efficiency pixels: 95 43 107 152 174 176 167 152 101 159 144 154 119 88 27 26
[12:49:10.407] INFO: number of X-ray hits detected: 71979 43899 73354 112766 123459 130832 128832 94536 91407 124978 117588 101620 103393 60768 22099 23525
[12:49:10.407] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:49:10.407] INFO: number of Vcal hits detected: 207903 207957 207889 207846 207823 207816 207829 207846 207899 207593 207853 207842 207879 207911 207973 207973
[12:49:10.407] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:49:10.407] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.8 99.9 99.9 99.9 100.0 100.0 100.0
[12:49:10.407] INFO: X-ray hit rate [MHz/cm2]: 21.1 12.9 21.5 33.1 36.2 38.3 37.8 27.7 26.8 36.6 34.5 29.8 30.3 17.8 6.5 6.9
[12:49:10.407] INFO: PixTestHighRate::doXPixelAlive() done
[12:49:10.453] INFO: PixTest:: pg_setup set to default.
[12:49:10.468] INFO: enter test to run
[12:49:35.457] INFO: test: HighRate no parameter change
[12:49:35.457] INFO: running: highrate
[12:49:35.458] INFO: ----------------------------------------------------------------------
[12:49:35.458] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:49:35.458] INFO: ----------------------------------------------------------------------
[12:49:36.071] INFO: Expecting 208000 events.
[12:49:50.170] INFO: 208000 events read in total (13572ms).
[12:49:50.176] INFO: Test took 14706ms.
[12:49:50.507] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:50.821] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 5 0 0 0 0 0 0
[12:49:50.821] INFO: number of red-efficiency pixels: 310 127 349 443 610 593 606 484 300 554 506 439 372 278 60 57
[12:49:50.821] INFO: number of X-ray hits detected: 150084 90553 152147 232134 256098 269890 265954 195447 190623 258368 245153 211764 215266 126209 46195 49063
[12:49:50.822] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:49:50.822] INFO: number of Vcal hits detected: 207656 207868 207599 207527 207318 207348 207311 207433 207679 207153 207429 207516 207603 207690 207939 207942
[12:49:50.822] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.7 99.8 99.9 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[12:49:50.822] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.8 99.7 99.7 99.7 99.7 99.8 99.6 99.7 99.8 99.8 99.9 100.0 100.0
[12:49:50.822] INFO: X-ray hit rate [MHz/cm2]: 44.0 26.5 44.6 68.0 75.1 79.1 78.0 57.3 55.9 75.7 71.9 62.1 63.1 37.0 13.5 14.4
[12:49:50.822] INFO: PixTestHighRate::doXPixelAlive() done
[12:49:50.871] INFO: PixTest:: pg_setup set to default.
[12:49:50.886] INFO: enter test to run
[12:50:04.369] INFO: test: HighRate no parameter change
[12:50:04.369] INFO: running: highrate
[12:50:04.370] INFO: ----------------------------------------------------------------------
[12:50:04.370] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:50:04.370] INFO: ----------------------------------------------------------------------
[12:50:04.986] INFO: Expecting 208000 events.
[12:50:21.422] INFO: 208000 events read in total (15909ms).
[12:50:21.430] INFO: Test took 17048ms.
[12:50:21.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:22.330] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 5 0 0 0 0 0 0
[12:50:22.330] INFO: number of red-efficiency pixels: 617 261 789 1009 1423 1370 1439 1089 676 1250 1239 1068 804 652 83 113
[12:50:22.330] INFO: number of X-ray hits detected: 225544 138257 230123 352658 387930 408901 402447 295659 286719 389840 368780 319138 323349 190658 69955 74249
[12:50:22.330] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:50:22.330] INFO: number of Vcal hits detected: 207222 207708 206826 206770 206084 206110 205987 206416 207209 206129 206302 206581 207044 207165 207916 207886
[12:50:22.330] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.5 99.5 99.2 99.2 99.2 99.3 99.6 99.3 99.3 99.4 99.6 99.6 100.0 99.9
[12:50:22.330] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.4 99.4 99.1 99.1 99.0 99.2 99.6 99.1 99.2 99.3 99.5 99.6 100.0 99.9
[12:50:22.330] INFO: X-ray hit rate [MHz/cm2]: 66.1 40.5 67.5 103.4 113.7 119.9 118.0 86.7 84.0 114.3 108.1 93.5 94.8 55.9 20.5 21.8
[12:50:22.330] INFO: PixTestHighRate::doXPixelAlive() done
[12:50:22.379] INFO: PixTest:: pg_setup set to default.
[12:50:22.397] INFO: enter test to run
[12:50:33.312] INFO: test: exit no parameter change
[12:50:33.678] QUIET: Connection to board 33 closed.
[12:50:33.694] INFO: pXar: this is the end, my friend