[11:33:32.121] INFO: *** Welcome to pxar ***
[11:33:32.121] INFO: *** Today: 2016/06/30
[11:33:32.223] INFO: *** Version: v1.9.0-814-g7497
[11:33:32.223] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//dacParameters35_C15.dat
[11:33:32.281] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:33:32.281] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//defaultMaskFile.dat
[11:33:32.284] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C15.dat
[11:33:32.410] INFO: clk: 4
[11:33:32.410] INFO: ctr: 4
[11:33:32.410] INFO: sda: 19
[11:33:32.410] INFO: tin: 9
[11:33:32.410] INFO: level: 15
[11:33:32.410] INFO: triggerdelay: 0
[11:33:32.410] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:33:32.410] INFO: Log level: INFO
[11:33:32.427] QUIET: Connection to board DTB_WREKRL opened.
[11:33:32.430] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[11:33:32.433] INFO: RPC call hashes of host and DTB match: 398089610
[11:33:33.966] INFO: DUT info:
[11:33:33.966] INFO: The DUT currently contains the following objects:
[11:33:33.966] INFO: 2 TBM Cores tbm08c (2 ON)
[11:33:33.966] INFO: TBM Core alpha (0): 7 registers set
[11:33:33.966] INFO: TBM Core beta (1): 7 registers set
[11:33:33.966] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:33:33.966] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.966] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:33.967] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:34.370] INFO: enter 'restricted' command line mode
[11:33:34.370] INFO: enter test to run
[11:33:45.610] INFO: test: PixelAlive no parameter change
[11:33:45.610] INFO: running: pixelalive
[11:33:45.619] INFO: ----------------------------------------------------------------------
[11:33:45.619] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:33:45.619] INFO: ----------------------------------------------------------------------
[11:33:45.940] INFO: Expecting 41600 events.
[11:33:50.285] INFO: 41600 events read in total (3627ms).
[11:33:50.456] INFO: Test took 4835ms.
[11:33:50.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:50.735] INFO: PixTestAlive::aliveTest() done
[11:33:50.735] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:33:50.763] INFO: enter test to run
[11:34:42.321] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:34:42.321] INFO: running: highrate
[11:34:42.322] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:34:42.542] INFO: ----------------------------------------------------------------------
[11:34:42.542] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:34:42.542] INFO: ----------------------------------------------------------------------
[11:34:42.542] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:34:42.542] INFO: edge/corner pixel THR is adjusted
[11:34:42.542] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:34:43.500] INFO: Collecting data for 5 seconds...
[11:34:48.519] INFO: Done with hot pixel readout
[11:35:01.141] INFO: PixTest:: pg_setup set to default.
[11:35:01.142] INFO: 15 hot pixels found in step 0
[11:35:02.133] INFO: Collecting data for 5 seconds...
[11:35:07.153] INFO: Done with hot pixel readout
[11:35:18.660] INFO: PixTest:: pg_setup set to default.
[11:35:18.661] INFO: 2 hot pixels found in step 1
[11:35:19.652] INFO: Collecting data for 5 seconds...
[11:35:24.671] INFO: Done with hot pixel readout
[11:35:36.117] INFO: PixTest:: pg_setup set to default.
[11:35:36.118] INFO: 2 hot pixels found in step 2
[11:35:37.110] INFO: Collecting data for 5 seconds...
[11:35:42.129] INFO: Done with hot pixel readout
[11:35:53.998] INFO: PixTest:: pg_setup set to default.
[11:35:53.999] INFO: 3 hot pixels found in step 3
[11:35:54.990] INFO: Collecting data for 5 seconds...
[11:36:00.011] INFO: Done with hot pixel readout
[11:36:11.972] INFO: PixTest:: pg_setup set to default.
[11:36:11.973] INFO: 2 hot pixels found in step 4
[11:36:12.965] INFO: Collecting data for 5 seconds...
[11:36:17.984] INFO: Done with hot pixel readout
[11:36:30.060] INFO: PixTest:: pg_setup set to default.
[11:36:30.061] INFO: 5 hot pixels found in step 5
[11:36:31.052] INFO: Collecting data for 5 seconds...
[11:36:36.072] INFO: Done with hot pixel readout
[11:36:47.955] INFO: PixTest:: pg_setup set to default.
[11:36:47.955] INFO: 3 hot pixels found in step 6
[11:36:48.950] INFO: Collecting data for 5 seconds...
[11:36:53.967] INFO: Done with hot pixel readout
[11:37:05.838] INFO: PixTest:: pg_setup set to default.
[11:37:05.839] INFO: 4 hot pixels found in step 7
[11:37:06.830] INFO: Collecting data for 5 seconds...
[11:37:11.847] INFO: Done with hot pixel readout
[11:37:23.539] INFO: PixTest:: pg_setup set to default.
[11:37:23.540] INFO: 0 hot pixels found in step 8
[11:37:23.575] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:37:23.579] INFO: PixTest::trimHotPixels() done
[11:37:23.579] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C0.dat
[11:37:23.585] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C1.dat
[11:37:23.591] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C2.dat
[11:37:23.597] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C3.dat
[11:37:23.602] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C4.dat
[11:37:23.608] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C5.dat
[11:37:23.613] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C6.dat
[11:37:23.618] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C7.dat
[11:37:23.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C8.dat
[11:37:23.629] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C9.dat
[11:37:23.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C10.dat
[11:37:23.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C11.dat
[11:37:23.645] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C12.dat
[11:37:23.650] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C13.dat
[11:37:23.655] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C14.dat
[11:37:23.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C15.dat
[11:37:23.675] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//defaultMaskFile.dat
[11:37:23.691] INFO: enter test to run
[11:37:55.968] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:37:55.968] INFO: running: highrate
[11:37:55.973] INFO: ----------------------------------------------------------------------
[11:37:55.973] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:37:55.973] INFO: ----------------------------------------------------------------------
[11:37:55.973] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:37:55.973] INFO: edge/corner pixel THR is adjusted
[11:37:55.973] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:37:56.932] INFO: Collecting data for 1 seconds...
[11:37:57.936] INFO: Done with hot pixel readout
[11:38:01.904] INFO: PixTest:: pg_setup set to default.
[11:38:01.905] INFO: 0 hot pixels found in step 0
[11:38:01.910] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:38:02.004] INFO: PixTest::trimHotPixels() done
[11:38:02.005] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C0.dat
[11:38:02.028] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C1.dat
[11:38:02.034] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C2.dat
[11:38:02.039] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C3.dat
[11:38:02.045] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C4.dat
[11:38:02.050] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C5.dat
[11:38:02.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C6.dat
[11:38:02.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C7.dat
[11:38:02.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C8.dat
[11:38:02.070] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C9.dat
[11:38:02.075] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C10.dat
[11:38:02.081] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C11.dat
[11:38:02.086] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C12.dat
[11:38:02.091] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C13.dat
[11:38:02.096] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C14.dat
[11:38:02.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C15.dat
[11:38:02.107] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-22_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//defaultMaskFile.dat
[11:38:02.117] INFO: enter test to run
[11:38:35.328] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:38:35.328] INFO: running: xray
[11:38:35.329] INFO: ----------------------------------------------------------------------
[11:38:35.329] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:38:35.329] INFO: ----------------------------------------------------------------------
[11:38:36.308] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:38:47.802] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:39:17.277] INFO: Resuming triggers.
[11:39:28.777] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:39:58.290] INFO: Resuming triggers.
[11:40:09.784] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:40:39.270] INFO: Resuming triggers.
[11:40:50.766] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:41:20.241] INFO: Resuming triggers.
[11:41:31.738] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[11:42:01.209] INFO: Resuming triggers.
[11:42:12.705] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:42:42.177] INFO: Resuming triggers.
[11:42:53.672] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[11:43:23.069] INFO: Resuming triggers.
[11:43:34.567] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[11:44:03.941] INFO: Resuming triggers.
[11:44:12.302] INFO: data taking finished, elapsed time: 100 seconds.
[11:44:33.981] INFO: PixTest:: pg_setup set to default.
[11:44:33.984] INFO: PixTestXray::doPhRun() done
[11:44:34.122] INFO: enter test to run
[11:45:22.773] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:45:22.773] INFO: running: xray
[11:45:22.774] INFO: ----------------------------------------------------------------------
[11:45:22.774] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:45:22.774] INFO: ----------------------------------------------------------------------
[11:45:23.738] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:45:30.587] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:46:01.489] INFO: Resuming triggers.
[11:46:08.343] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:46:39.174] INFO: Resuming triggers.
[11:46:46.029] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[11:47:16.481] INFO: Resuming triggers.
[11:47:23.335] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[11:47:54.516] INFO: Resuming triggers.
[11:48:01.367] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:48:32.845] INFO: Resuming triggers.
[11:48:39.703] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[11:49:10.872] INFO: Resuming triggers.
[11:49:17.723] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[11:49:47.846] INFO: Resuming triggers.
[11:49:54.698] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[11:50:24.758] INFO: Resuming triggers.
[11:50:31.617] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[11:51:01.723] INFO: Resuming triggers.
[11:51:08.581] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:51:38.768] INFO: Resuming triggers.
[11:51:45.621] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[11:52:15.768] INFO: Resuming triggers.
[11:52:22.627] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:52:52.866] INFO: Resuming triggers.
[11:52:59.720] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[11:53:30.027] INFO: Resuming triggers.
[11:53:36.878] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[11:54:07.123] INFO: Resuming triggers.
[11:54:11.514] INFO: data taking finished, elapsed time: 100 seconds.
[11:54:31.121] INFO: PixTest:: pg_setup set to default.
[11:54:31.124] INFO: PixTestXray::doPhRun() done
[11:54:31.271] INFO: enter test to run
[11:55:44.913] INFO: test: HighRate no parameter change
[11:55:44.913] INFO: running: highrate
[11:55:44.929] INFO: ----------------------------------------------------------------------
[11:55:44.929] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:55:44.929] INFO: ----------------------------------------------------------------------
[11:55:45.084] INFO: Expecting 768 events.
[11:55:46.219] INFO: 768 events read in total (419ms).
[11:55:46.219] INFO: Test took 1269ms.
[11:55:47.022] INFO: Expecting 41600 events.
[11:55:50.142] INFO: 41600 events read in total (2593ms).
[11:55:50.143] INFO: Test took 3916ms.
[11:55:50.177] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:50.903] INFO: Expecting 41600 events.
[11:55:54.080] INFO: 41600 events read in total (2650ms).
[11:55:54.080] INFO: Test took 3886ms.
[11:55:54.114] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:54.837] INFO: Expecting 41600 events.
[11:55:58.042] INFO: 41600 events read in total (2678ms).
[11:55:58.043] INFO: Test took 3912ms.
[11:55:58.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:58.800] INFO: Expecting 41600 events.
[11:56:02.038] INFO: 41600 events read in total (2711ms).
[11:56:02.039] INFO: Test took 3943ms.
[11:56:02.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:02.796] INFO: Expecting 41600 events.
[11:56:06.037] INFO: 41600 events read in total (2714ms).
[11:56:06.038] INFO: Test took 3948ms.
[11:56:06.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:06.799] INFO: Expecting 41600 events.
[11:56:10.041] INFO: 41600 events read in total (2715ms).
[11:56:10.042] INFO: Test took 3953ms.
[11:56:10.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:10.799] INFO: Expecting 41600 events.
[11:56:14.050] INFO: 41600 events read in total (2724ms).
[11:56:14.051] INFO: Test took 3959ms.
[11:56:14.084] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:14.809] INFO: Expecting 41600 events.
[11:56:18.045] INFO: 41600 events read in total (2709ms).
[11:56:18.046] INFO: Test took 3944ms.
[11:56:18.080] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:18.803] INFO: Expecting 41600 events.
[11:56:22.043] INFO: 41600 events read in total (2714ms).
[11:56:22.044] INFO: Test took 3945ms.
[11:56:22.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:22.805] INFO: Expecting 41600 events.
[11:56:26.038] INFO: 41600 events read in total (2706ms).
[11:56:26.039] INFO: Test took 3943ms.
[11:56:26.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:26.797] INFO: Expecting 41600 events.
[11:56:30.046] INFO: 41600 events read in total (2722ms).
[11:56:30.047] INFO: Test took 3956ms.
[11:56:30.081] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:30.805] INFO: Expecting 41600 events.
[11:56:34.042] INFO: 41600 events read in total (2710ms).
[11:56:34.043] INFO: Test took 3944ms.
[11:56:34.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:34.801] INFO: Expecting 41600 events.
[11:56:38.038] INFO: 41600 events read in total (2710ms).
[11:56:38.039] INFO: Test took 3944ms.
[11:56:38.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:38.797] INFO: Expecting 41600 events.
[11:56:42.038] INFO: 41600 events read in total (2714ms).
[11:56:42.039] INFO: Test took 3949ms.
[11:56:42.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:42.800] INFO: Expecting 41600 events.
[11:56:46.041] INFO: 41600 events read in total (2714ms).
[11:56:46.042] INFO: Test took 3951ms.
[11:56:46.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:46.799] INFO: Expecting 41600 events.
[11:56:50.038] INFO: 41600 events read in total (2712ms).
[11:56:50.039] INFO: Test took 3945ms.
[11:56:50.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:50.797] INFO: Expecting 41600 events.
[11:56:54.046] INFO: 41600 events read in total (2722ms).
[11:56:54.047] INFO: Test took 3957ms.
[11:56:54.081] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:54.805] INFO: Expecting 41600 events.
[11:56:58.041] INFO: 41600 events read in total (2709ms).
[11:56:58.041] INFO: Test took 3941ms.
[11:56:58.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:58.799] INFO: Expecting 41600 events.
[11:57:02.016] INFO: 41600 events read in total (2690ms).
[11:57:02.017] INFO: Test took 3925ms.
[11:57:02.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:02.777] INFO: Expecting 41600 events.
[11:57:05.838] INFO: 41600 events read in total (2534ms).
[11:57:05.839] INFO: Test took 3770ms.
[11:57:05.871] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:06.239] INFO: enter test to run
[11:57:13.008] INFO: test: HighRate no parameter change
[11:57:13.008] INFO: running: highrate
[11:57:13.010] INFO: ----------------------------------------------------------------------
[11:57:13.010] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:57:13.010] INFO: ----------------------------------------------------------------------
[11:57:13.630] INFO: Expecting 208000 events.
[11:57:25.419] INFO: 208000 events read in total (11262ms).
[11:57:25.422] INFO: Test took 12406ms.
[11:57:25.566] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:25.817] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:57:25.817] INFO: number of red-efficiency pixels: 76 39 77 107 120 118 113 81 83 128 117 95 124 53 24 27
[11:57:25.817] INFO: number of X-ray hits detected: 63233 39489 62334 100119 101097 104223 103893 76068 80773 100697 98079 87512 89967 53819 21363 24962
[11:57:25.817] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:57:25.817] INFO: number of Vcal hits detected: 207924 207960 207921 207889 207876 207881 207885 207917 207915 207871 207882 207902 207866 207946 207976 207973
[11:57:25.817] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[11:57:25.817] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[11:57:25.817] INFO: X-ray hit rate [MHz/cm2]: 18.5 11.6 18.3 29.3 29.6 30.5 30.5 22.3 23.7 29.5 28.7 25.7 26.4 15.8 6.3 7.3
[11:57:25.817] INFO: PixTestHighRate::doXPixelAlive() done
[11:57:25.863] INFO: PixTest:: pg_setup set to default.
[11:57:25.876] INFO: enter test to run
[11:57:57.456] INFO: test: HighRate no parameter change
[11:57:57.456] INFO: running: highrate
[11:57:57.457] INFO: ----------------------------------------------------------------------
[11:57:57.457] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:57:57.457] INFO: ----------------------------------------------------------------------
[11:57:58.079] INFO: Expecting 208000 events.
[11:58:11.601] INFO: 208000 events read in total (12995ms).
[11:58:11.606] INFO: Test took 14140ms.
[11:58:11.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:12.191] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:58:12.191] INFO: number of red-efficiency pixels: 176 93 233 324 299 333 345 241 272 372 362 286 285 208 39 61
[11:58:12.191] INFO: number of X-ray hits detected: 129899 81928 129002 206347 207776 214637 213485 157101 165717 207179 200550 180091 185200 110976 44151 50851
[11:58:12.191] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:58:12.191] INFO: number of Vcal hits detected: 207820 207902 207752 207656 207684 207650 207624 207741 207714 207603 207603 207696 207691 207775 207961 207939
[11:58:12.191] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.9 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[11:58:12.191] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[11:58:12.191] INFO: X-ray hit rate [MHz/cm2]: 38.1 24.0 37.8 60.5 60.9 62.9 62.6 46.0 48.6 60.7 58.8 52.8 54.3 32.5 12.9 14.9
[11:58:12.191] INFO: PixTestHighRate::doXPixelAlive() done
[11:58:12.240] INFO: PixTest:: pg_setup set to default.
[11:58:12.258] INFO: enter test to run
[11:58:44.464] INFO: test: HighRate no parameter change
[11:58:44.464] INFO: running: highrate
[11:58:44.465] INFO: ----------------------------------------------------------------------
[11:58:44.465] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:58:44.465] INFO: ----------------------------------------------------------------------
[11:58:45.086] INFO: Expecting 208000 events.
[11:59:00.460] INFO: 208000 events read in total (14847ms).
[11:59:00.467] INFO: Test took 15992ms.
[11:59:00.900] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:01.248] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:59:01.248] INFO: number of red-efficiency pixels: 347 190 562 806 767 777 762 495 661 934 878 633 609 475 72 94
[11:59:01.248] INFO: number of X-ray hits detected: 195978 123834 194913 313645 314293 324692 322587 237031 254164 314218 303867 272593 281035 169285 67152 77700
[11:59:01.248] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:59:01.248] INFO: number of Vcal hits detected: 207609 207791 207301 207055 207133 207093 207109 207428 207217 206904 206933 207259 207302 207432 207926 207906
[11:59:01.248] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.6 99.6 99.6 99.7 99.7 99.5 99.5 99.7 99.7 99.8 100.0 100.0
[11:59:01.248] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.5 99.6 99.6 99.6 99.7 99.6 99.5 99.5 99.6 99.7 99.7 100.0 100.0
[11:59:01.248] INFO: X-ray hit rate [MHz/cm2]: 57.4 36.3 57.1 91.9 92.1 95.2 94.6 69.5 74.5 92.1 89.1 79.9 82.4 49.6 19.7 22.8
[11:59:01.248] INFO: PixTestHighRate::doXPixelAlive() done
[11:59:01.296] INFO: PixTest:: pg_setup set to default.
[11:59:01.307] INFO: enter test to run
[11:59:27.335] INFO: test: exit no parameter change
[11:59:27.609] QUIET: Connection to board 33 closed.
[11:59:27.625] INFO: pXar: this is the end, my friend