[15:53:32.323] INFO: *** Welcome to pxar ***
[15:53:32.323] INFO: *** Today: 2016/08/18
[15:53:32.358] INFO: *** Version: v1.9.0-818-g96727
[15:53:32.359] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//dacParameters35_C15.dat
[15:53:32.360] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:53:32.360] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//defaultMaskFile.dat
[15:53:32.360] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C15.dat
[15:53:32.440] INFO: clk: 4
[15:53:32.440] INFO: ctr: 4
[15:53:32.440] INFO: sda: 19
[15:53:32.440] INFO: tin: 9
[15:53:32.440] INFO: level: 15
[15:53:32.440] INFO: triggerdelay: 0
[15:53:32.440] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:53:32.440] INFO: Log level: INFO
[15:53:32.455] QUIET: Connection to board DTB_WREKRL opened.
[15:53:32.459] 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:
------------------------------------------------------
[15:53:32.462] INFO: RPC call hashes of host and DTB match: 398089610
[15:53:33.999] INFO: DUT info:
[15:53:33.999] INFO: The DUT currently contains the following objects:
[15:53:33.000] INFO: 2 TBM Cores tbm08c (2 ON)
[15:53:33.000] INFO: TBM Core alpha (0): 7 registers set
[15:53:33.000] INFO: TBM Core beta (1): 7 registers set
[15:53:33.000] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:53:33.000] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.000] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.000] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.000] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.000] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.000] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.000] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.000] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.000] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.000] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.000] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.001] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.001] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.001] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.001] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:33.001] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:34.404] INFO: enter 'restricted' command line mode
[15:53:34.404] INFO: enter test to run
[15:53:34.404] INFO: test: y no parameter change
[15:53:34.404] INFO: running: y
[15:53:34.424] INFO: command ->y<- not known, ignored
[15:53:34.424] INFO: enter test to run
[15:53:41.903] INFO: test: PixelAlive no parameter change
[15:53:41.903] INFO: running: pixelalive
[15:53:41.912] INFO: ----------------------------------------------------------------------
[15:53:41.912] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:53:41.912] INFO: ----------------------------------------------------------------------
[15:53:42.229] INFO: Expecting 41600 events.
[15:53:46.555] INFO: 41600 events read in total (3608ms).
[15:53:46.723] INFO: Test took 4807ms.
[15:53:46.734] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:46.998] INFO: PixTestAlive::aliveTest() done
[15:53:46.998] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[15:53:47.024] INFO: enter test to run
[15:53:49.135] INFO: test: timing no parameter change
[15:53:49.135] INFO: running: timing
[15:53:49.166] INFO: ######################################################################
[15:53:49.173] INFO: PixTestTiming::doTest()
[15:53:49.173] INFO: ######################################################################
[15:53:49.173] INFO: ----------------------------------------------------------------------
[15:53:49.173] INFO: PixTestTiming::TBMPhaseScan()
[15:53:49.173] INFO: ----------------------------------------------------------------------
[15:58:19.491] INFO: TBM Phase Settings: 244
[15:58:19.491] INFO: 400MHz Phase: 5
[15:58:19.491] INFO: 160MHz Phase: 7
[15:58:19.491] INFO: Functional Phase Area: 5
[15:58:19.494] INFO: Test took 270321 ms.
[15:58:19.494] INFO: PixTestTiming::TBMPhaseScan() done.
[15:58:19.494] INFO: ----------------------------------------------------------------------
[15:58:19.494] INFO: PixTestTiming::ROCDelayScan()
[15:58:19.494] INFO: ----------------------------------------------------------------------
[16:00:31.095] INFO: ROC Delay Settings: 228
[16:00:31.095] INFO: ROC Header-Trailer/Token Delay: 11
[16:00:31.095] INFO: ROC Port 0 Delay: 4
[16:00:31.095] INFO: ROC Port 1 Delay: 4
[16:00:31.095] INFO: Functional ROC Area: 6
[16:00:31.098] INFO: Test took 131604 ms.
[16:00:31.098] INFO: PixTestTiming::ROCDelayScan() done.
[16:00:31.099] INFO: ----------------------------------------------------------------------
[16:00:31.099] INFO: PixTestTiming::TimingTest()
[16:00:31.099] INFO: ----------------------------------------------------------------------
[16:00:47.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:02.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:17.180] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:32.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:47.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:02.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:17.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:32.014] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:46.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:01.962] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:02.339] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:02.357] INFO: ----------------------------------------------------------------------
[16:03:02.357] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[16:03:02.357] INFO: ----------------------------------------------------------------------
[16:03:02.357] INFO: ----------------------------------------------------------------------
[16:03:02.357] INFO: Read back bit status: 1
[16:03:02.357] INFO: ----------------------------------------------------------------------
[16:03:02.357] INFO: ----------------------------------------------------------------------
[16:03:02.357] INFO: Timings are good!
[16:03:02.357] INFO: ----------------------------------------------------------------------
[16:03:02.357] INFO: Test took 151259 ms.
[16:03:02.357] INFO: PixTestTiming::TimingTest() done.
[16:03:02.372] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//tbmParameters_C0a.dat
[16:03:02.372] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:03:02.372] INFO: PixTestTiming::doTest took 553209 ms.
[16:03:02.372] INFO: PixTestTiming::doTest() done
[16:03:02.373] INFO: Write out TBMPhaseScan_0_V0
[16:03:02.373] INFO: Write out TBMPhaseScan_1_V0
[16:03:02.373] INFO: Write out CombinedTBMPhaseScan_V0
[16:03:02.374] INFO: Write out ROCDelayScan3_V0
[16:03:02.374] INFO: enter test to run
[16:04:02.683] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:04:02.683] INFO: running: highrate
[16:04:02.683] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:04:02.835] INFO: ----------------------------------------------------------------------
[16:04:02.835] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:04:02.835] INFO: ----------------------------------------------------------------------
[16:04:02.835] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:04:02.835] INFO: edge/corner pixel THR is adjusted
[16:04:02.835] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:04:03.792] INFO: Collecting data for 5 seconds...
[16:04:08.809] INFO: Done with hot pixel readout
[16:04:21.574] INFO: PixTest:: pg_setup set to default.






[16:04:21.575] INFO: 247 hot pixels found in step 0
[16:04:22.576] INFO: Collecting data for 5 seconds...
[16:04:27.592] INFO: Done with hot pixel readout
[16:04:40.402] INFO: PixTest:: pg_setup set to default.











[16:04:40.403] INFO: 226 hot pixels found in step 1
[16:04:41.404] INFO: Collecting data for 5 seconds...
[16:04:46.423] INFO: Done with hot pixel readout
[16:04:58.096] INFO: PixTest:: pg_setup set to default.







[16:04:58.097] INFO: 195 hot pixels found in step 2
[16:04:59.097] INFO: Collecting data for 5 seconds...
[16:05:04.112] INFO: Done with hot pixel readout
[16:05:15.663] INFO: PixTest:: pg_setup set to default.















[16:05:15.665] INFO: 196 hot pixels found in step 3
[16:05:16.664] INFO: Collecting data for 5 seconds...
[16:05:21.682] INFO: Done with hot pixel readout
[16:05:33.848] INFO: PixTest:: pg_setup set to default.



















[16:05:33.849] INFO: 182 hot pixels found in step 4
[16:05:34.849] INFO: Collecting data for 5 seconds...
[16:05:39.867] INFO: Done with hot pixel readout
[16:05:52.510] INFO: PixTest:: pg_setup set to default.




















[16:05:52.512] INFO: 146 hot pixels found in step 5
[16:05:53.511] INFO: Collecting data for 5 seconds...
[16:05:58.530] INFO: Done with hot pixel readout
[16:06:10.003] INFO: PixTest:: pg_setup set to default.






















[16:06:10.004] INFO: 145 hot pixels found in step 6
[16:06:12.012] INFO: Collecting data for 5 seconds...
[16:06:17.031] INFO: Done with hot pixel readout
[16:06:29.595] INFO: PixTest:: pg_setup set to default.


























[16:06:29.596] INFO: 153 hot pixels found in step 7
[16:06:30.597] INFO: Collecting data for 5 seconds...
[16:06:35.616] INFO: Done with hot pixel readout
[16:06:48.121] INFO: PixTest:: pg_setup set to default.



























[16:06:48.123] INFO: 147 hot pixels found in step 8
[16:06:49.125] INFO: Collecting data for 5 seconds...
[16:06:54.144] INFO: Done with hot pixel readout
[16:07:06.700] INFO: PixTest:: pg_setup set to default.


























[16:07:06.702] INFO: 132 hot pixels found in step 9
[16:07:07.701] INFO: Collecting data for 5 seconds...
[16:07:12.722] INFO: Done with hot pixel readout
[16:07:25.294] INFO: PixTest:: pg_setup set to default.



























[16:07:25.296] INFO: 115 hot pixels found in step 10
[16:07:26.297] INFO: Collecting data for 5 seconds...
[16:07:31.316] INFO: Done with hot pixel readout
[16:07:44.440] INFO: PixTest:: pg_setup set to default.

































[16:07:44.442] INFO: 116 hot pixels found in step 11
[16:07:45.443] INFO: Collecting data for 5 seconds...
[16:07:50.464] INFO: Done with hot pixel readout
[16:08:03.154] INFO: PixTest:: pg_setup set to default.


































[16:08:03.156] INFO: 106 hot pixels found in step 12
[16:08:04.154] INFO: Collecting data for 5 seconds...
[16:08:09.172] INFO: Done with hot pixel readout
[16:08:21.753] INFO: PixTest:: pg_setup set to default.





































[16:08:21.755] INFO: 119 hot pixels found in step 13
[16:08:22.755] INFO: Collecting data for 5 seconds...
[16:08:27.776] INFO: Done with hot pixel readout
[16:08:40.360] INFO: PixTest:: pg_setup set to default.



































[16:08:40.362] INFO: 111 hot pixels found in step 14
[16:08:40.405] INFO: 111 hot pixels could not be trimmed and have been masked.
[16:08:40.408] INFO: PixTest::trimHotPixels() done
[16:08:40.408] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C0.dat
[16:08:40.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C1.dat
[16:08:40.421] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C2.dat
[16:08:40.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C3.dat
[16:08:40.434] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C4.dat
[16:08:40.440] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C5.dat
[16:08:40.446] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C6.dat
[16:08:40.452] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C7.dat
[16:08:40.458] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C8.dat
[16:08:40.465] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C9.dat
[16:08:40.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C10.dat
[16:08:40.476] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C11.dat
[16:08:40.481] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C12.dat
[16:08:40.486] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C13.dat
[16:08:40.492] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C14.dat
[16:08:40.497] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C15.dat
[16:08:40.513] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//defaultMaskFile.dat
[16:08:40.523] INFO: enter test to run
[16:09:00.768] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:09:00.768] INFO: running: highrate
[16:09:00.773] INFO: ----------------------------------------------------------------------
[16:09:00.773] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:09:00.773] INFO: ----------------------------------------------------------------------
[16:09:00.773] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:09:00.773] INFO: edge/corner pixel THR is adjusted
[16:09:00.773] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:09:01.730] INFO: Collecting data for 1 seconds...
[16:09:02.734] INFO: Done with hot pixel readout
[16:09:07.389] INFO: PixTest:: pg_setup set to default.
[16:09:07.389] INFO: 0 hot pixels found in step 0
[16:09:07.395] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:09:07.450] INFO: PixTest::trimHotPixels() done
[16:09:07.450] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C0.dat
[16:09:07.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C1.dat
[16:09:07.480] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C2.dat
[16:09:07.489] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C3.dat
[16:09:07.498] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C4.dat
[16:09:07.507] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C5.dat
[16:09:07.515] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C6.dat
[16:09:07.521] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C7.dat
[16:09:07.527] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C8.dat
[16:09:07.532] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C9.dat
[16:09:07.538] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C10.dat
[16:09:07.543] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C11.dat
[16:09:07.549] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C12.dat
[16:09:07.554] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C13.dat
[16:09:07.559] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C14.dat
[16:09:07.565] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C15.dat
[16:09:07.570] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//defaultMaskFile.dat
[16:09:07.580] INFO: enter test to run
[16:09:29.953] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:09:29.953] INFO: running: xray
[16:09:29.954] INFO: ----------------------------------------------------------------------
[16:09:29.954] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:09:29.954] INFO: ----------------------------------------------------------------------
[16:09:30.917] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:09:41.315] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[16:10:10.517] INFO: Resuming triggers.
[16:10:21.034] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.









































[16:10:50.282] INFO: Resuming triggers.
[16:11:00.690] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.





































[16:11:30.286] INFO: Resuming triggers.
[16:11:40.689] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
























































[16:12:10.482] INFO: Resuming triggers.
[16:12:20.886] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.

































































































































































[16:12:50.651] INFO: Resuming triggers.
[16:13:01.057] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.







































[16:13:30.747] INFO: Resuming triggers.
[16:13:41.155] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[16:14:10.628] INFO: Resuming triggers.
[16:14:21.033] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[16:14:50.600] INFO: Resuming triggers.
[16:15:00.004] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.


















[16:15:30.607] INFO: Resuming triggers.
[16:15:37.298] INFO: data taking finished, elapsed time: 100 seconds.









[16:15:56.531] INFO: PixTest:: pg_setup set to default.
[16:15:56.534] INFO: PixTestXray::doPhRun() done
[16:15:56.674] INFO: enter test to run
[16:16:25.254] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:16:25.254] INFO: running: xray
[16:16:25.255] INFO: ----------------------------------------------------------------------
[16:16:25.255] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:16:25.255] INFO: ----------------------------------------------------------------------
[16:16:26.219] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:16:31.881] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[16:17:02.018] INFO: Resuming triggers.
[16:17:07.678] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.




















































































[16:17:38.796] INFO: Resuming triggers.
[16:17:44.456] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.






























































































































[16:18:14.914] INFO: Resuming triggers.
[16:18:20.576] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.






































[16:18:51.508] INFO: Resuming triggers.
[16:18:57.167] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
















































































































































[16:19:28.678] INFO: Resuming triggers.
[16:19:34.337] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.


























































































































[16:20:06.255] INFO: Resuming triggers.
[16:20:11.919] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[16:20:43.593] INFO: Resuming triggers.
[16:20:49.257] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[16:21:19.587] INFO: Resuming triggers.
[16:21:25.247] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[16:21:55.251] INFO: Resuming triggers.
[16:22:00.911] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[16:22:31.054] INFO: Resuming triggers.
[16:22:36.718] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[16:23:06.835] INFO: Resuming triggers.
[16:23:12.501] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:23:42.601] INFO: Resuming triggers.
[16:23:48.264] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[16:24:18.401] INFO: Resuming triggers.
[16:24:24.067] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[16:24:54.198] INFO: Resuming triggers.
[16:24:59.858] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[16:25:30.035] INFO: Resuming triggers.
[16:25:35.698] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[16:26:05.870] INFO: Resuming triggers.
[16:26:11.533] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[16:26:41.607] INFO: Resuming triggers.
[16:26:45.700] INFO: data taking finished, elapsed time: 100 seconds.
[16:27:07.683] INFO: PixTest:: pg_setup set to default.
[16:27:07.686] INFO: PixTestXray::doPhRun() done
[16:27:07.836] INFO: enter test to run
[16:29:11.921] INFO: test: HighRate no parameter change
[16:29:11.921] INFO: running: highrate
[16:29:11.942] INFO: ----------------------------------------------------------------------
[16:29:11.943] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:29:11.943] INFO: ----------------------------------------------------------------------
[16:29:12.088] INFO: Expecting 768 events.
[16:29:13.222] INFO: 768 events read in total (418ms).
[16:29:13.222] INFO: Test took 1268ms.
[16:29:14.025] INFO: Expecting 41600 events.
[16:29:17.233] INFO: 41600 events read in total (2681ms).
[16:29:17.234] INFO: Test took 4004ms.
[16:29:17.272] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:17.986] INFO: Expecting 41600 events.
[16:29:21.286] INFO: 41600 events read in total (2773ms).
[16:29:21.287] INFO: Test took 3995ms.
[16:29:21.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:22.032] INFO: Expecting 41600 events.
[16:29:25.322] INFO: 41600 events read in total (2764ms).
[16:29:25.323] INFO: Test took 3976ms.
[16:29:25.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:26.071] INFO: Expecting 41600 events.
[16:29:29.366] INFO: 41600 events read in total (2768ms).
[16:29:29.367] INFO: Test took 3984ms.
[16:29:29.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:30.120] INFO: Expecting 41600 events.
[16:29:33.422] INFO: 41600 events read in total (2775ms).
[16:29:33.423] INFO: Test took 3996ms.
[16:29:33.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:34.173] INFO: Expecting 41600 events.
[16:29:37.448] INFO: 41600 events read in total (2748ms).
[16:29:37.449] INFO: Test took 3966ms.
[16:29:37.489] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:38.197] INFO: Expecting 41600 events.
[16:29:41.424] INFO: 41600 events read in total (2700ms).
[16:29:41.425] INFO: Test took 3917ms.
[16:29:41.465] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:42.172] INFO: Expecting 41600 events.
[16:29:45.371] INFO: 41600 events read in total (2672ms).
[16:29:45.372] INFO: Test took 3888ms.
[16:29:45.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:46.128] INFO: Expecting 41600 events.
[16:29:49.411] INFO: 41600 events read in total (2756ms).
[16:29:49.412] INFO: Test took 3980ms.
[16:29:49.452] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:50.166] INFO: Expecting 41600 events.
[16:29:53.464] INFO: 41600 events read in total (2772ms).
[16:29:53.465] INFO: Test took 3994ms.
[16:29:53.504] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:54.217] INFO: Expecting 41600 events.
[16:29:57.559] INFO: 41600 events read in total (2815ms).
[16:29:57.560] INFO: Test took 4036ms.
[16:29:57.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:58.313] INFO: Expecting 41600 events.
[16:30:01.630] INFO: 41600 events read in total (2791ms).
[16:30:01.631] INFO: Test took 4012ms.
[16:30:01.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:02.382] INFO: Expecting 41600 events.
[16:30:05.659] INFO: 41600 events read in total (2750ms).
[16:30:05.660] INFO: Test took 3969ms.
[16:30:05.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:06.413] INFO: Expecting 41600 events.
[16:30:09.728] INFO: 41600 events read in total (2788ms).
[16:30:09.729] INFO: Test took 4010ms.
[16:30:09.770] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:10.484] INFO: Expecting 41600 events.
[16:30:13.746] INFO: 41600 events read in total (2736ms).
[16:30:13.746] INFO: Test took 3957ms.
[16:30:13.787] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:14.499] INFO: Expecting 41600 events.
[16:30:17.722] INFO: 41600 events read in total (2696ms).
[16:30:17.723] INFO: Test took 3917ms.
[16:30:17.763] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:18.467] INFO: Expecting 41600 events.
[16:30:21.831] INFO: 41600 events read in total (2837ms).
[16:30:21.832] INFO: Test took 4049ms.
[16:30:21.872] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:22.572] INFO: Expecting 41600 events.
[16:30:25.850] INFO: 41600 events read in total (2751ms).
[16:30:25.851] INFO: Test took 3959ms.
[16:30:25.891] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:26.598] INFO: Expecting 41600 events.
[16:30:29.834] INFO: 41600 events read in total (2709ms).
[16:30:29.835] INFO: Test took 3924ms.
[16:30:29.875] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:30.585] INFO: Expecting 41600 events.
[16:30:33.619] INFO: 41600 events read in total (2508ms).
[16:30:33.620] INFO: Test took 3726ms.
[16:30:33.670] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:33.994] INFO: enter test to run
[16:31:03.496] INFO: test: HighRate no parameter change
[16:31:03.496] INFO: running: highrate
[16:31:03.497] INFO: ----------------------------------------------------------------------
[16:31:03.497] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:31:03.497] INFO: ----------------------------------------------------------------------
[16:31:04.118] INFO: Expecting 208000 events.
[16:31:16.344] INFO: 208000 events read in total (11700ms).
[16:31:16.347] INFO: Test took 12841ms.
[16:31:16.524] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:16.787] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[16:31:16.787] INFO: number of red-efficiency pixels: 88 53 83 181 216 183 197 144 93 162 184 137 112 79 25 30
[16:31:16.787] INFO: number of X-ray hits detected: 75369 50290 76743 130987 140156 138062 134993 94959 81672 116972 117397 102162 101855 62309 25462 28079
[16:31:16.787] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:31:16.787] INFO: number of Vcal hits detected: 207814 207946 207914 207814 207776 207800 207795 207855 207907 207835 207810 207861 207886 207920 207973 207872
[16:31:16.787] 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
[16:31:16.787] INFO: Vcal hit overall efficiency (%): 99.9 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 99.9
[16:31:16.787] INFO: X-ray hit rate [MHz/cm2]: 22.1 14.7 22.5 38.4 41.1 40.5 39.6 27.8 23.9 34.3 34.4 29.9 29.9 18.3 7.5 8.2
[16:31:16.787] INFO: PixTestHighRate::doXPixelAlive() done
[16:31:16.832] INFO: PixTest:: pg_setup set to default.
[16:31:16.840] INFO: enter test to run
[16:31:35.759] INFO: test: HighRate no parameter change
[16:31:35.760] INFO: running: highrate
[16:31:35.761] INFO: ----------------------------------------------------------------------
[16:31:35.761] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:31:35.761] INFO: ----------------------------------------------------------------------
[16:31:36.382] INFO: Expecting 208000 events.
[16:31:51.316] INFO: 208000 events read in total (14407ms).
[16:31:51.323] INFO: Test took 15553ms.
[16:31:51.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:31:52.029] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[16:31:52.029] INFO: number of red-efficiency pixels: 321 210 340 824 980 676 870 547 363 636 756 532 370 330 82 76
[16:31:52.029] INFO: number of X-ray hits detected: 168062 113778 171690 292898 314911 308645 299391 212620 182868 263681 263800 228822 228163 139589 57176 63274
[16:31:52.029] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:31:52.029] INFO: number of Vcal hits detected: 207545 207778 207630 207035 206825 207212 206959 207351 207604 207271 207147 207402 207591 207632 207915 207825
[16:31:52.030] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.5 99.7 99.5 99.7 99.8 99.7 99.6 99.7 99.8 99.8 100.0 100.0
[16:31:52.030] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.5 99.4 99.6 99.5 99.7 99.8 99.6 99.6 99.7 99.8 99.8 100.0 99.9
[16:31:52.030] INFO: X-ray hit rate [MHz/cm2]: 49.3 33.3 50.3 85.9 92.3 90.5 87.8 62.3 53.6 77.3 77.3 67.1 66.9 40.9 16.8 18.5
[16:31:52.030] INFO: PixTestHighRate::doXPixelAlive() done
[16:31:52.079] INFO: PixTest:: pg_setup set to default.
[16:31:52.097] INFO: enter test to run
[16:32:09.136] INFO: test: HighRate no parameter change
[16:32:09.136] INFO: running: highrate
[16:32:09.137] INFO: ----------------------------------------------------------------------
[16:32:09.137] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:32:09.137] INFO: ----------------------------------------------------------------------
[16:32:09.756] INFO: Expecting 208000 events.
[16:32:27.738] INFO: 208000 events read in total (17455ms).
[16:32:27.748] INFO: Test took 18602ms.
[16:32:28.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:32:28.774] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[16:32:28.775] INFO: number of red-efficiency pixels: 761 464 780 2177 2320 1819 2196 1367 857 1674 1802 1370 971 773 123 141
[16:32:28.775] INFO: number of X-ray hits detected: 262454 177210 268838 456871 490086 480124 467875 331961 287241 411152 412571 357646 356815 218545 89871 100117
[16:32:28.775] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:32:28.775] INFO: number of Vcal hits detected: 206910 207471 206943 204517 203881 205213 204414 205717 206914 205626 205316 206087 206841 206928 207872 207756
[16:32:28.775] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.5 98.5 98.2 98.8 98.4 99.0 99.5 99.0 98.8 99.2 99.5 99.6 99.9 99.9
[16:32:28.775] INFO: Vcal hit overall efficiency (%): 99.5 99.7 99.5 98.3 98.0 98.7 98.3 98.9 99.5 98.9 98.7 99.1 99.4 99.5 99.9 99.9
[16:32:28.775] INFO: X-ray hit rate [MHz/cm2]: 76.9 51.9 78.8 133.9 143.6 140.7 137.1 97.3 84.2 120.5 120.9 104.8 104.6 64.1 26.3 29.3
[16:32:28.775] INFO: PixTestHighRate::doXPixelAlive() done
[16:32:28.820] INFO: PixTest:: pg_setup set to default.
[16:32:28.834] INFO: enter test to run
[16:32:35.889] INFO: test: exit no parameter change
[16:32:36.192] QUIET: Connection to board 33 closed.
[16:32:36.204] INFO: pXar: this is the end, my friend