[12:14:40.393] INFO: *** Welcome to pxar ***
[12:14:40.393] INFO: *** Today: 2016/05/11
[12:14:40.489] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:14:40.489] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//dacParameters35_C15.dat
[12:14:40.903] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:14:40.903] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//defaultMaskFile.dat
[12:14:40.927] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C15.dat
[12:14:41.828] INFO: clk: 4
[12:14:41.828] INFO: ctr: 4
[12:14:41.828] INFO: sda: 19
[12:14:41.828] INFO: tin: 9
[12:14:41.828] INFO: level: 15
[12:14:41.828] INFO: triggerdelay: 0
[12:14:41.828] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:14:41.828] INFO: Log level: INFO
[12:14:41.846] QUIET: Connection to board DTB_WREKRL opened.
[12:14:41.850] 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:14:41.853] INFO: RPC call hashes of host and DTB match: 398089610
[12:14:43.395] INFO: DUT info:
[12:14:43.395] INFO: The DUT currently contains the following objects:
[12:14:43.395] INFO: 2 TBM Cores tbm08c (2 ON)
[12:14:43.395] INFO: TBM Core alpha (0): 7 registers set
[12:14:43.395] INFO: TBM Core beta (1): 7 registers set
[12:14:43.395] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:14:43.395] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.395] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:14:43.823] INFO: enter 'restricted' command line mode
[12:14:43.823] INFO: enter test to run
[12:14:58.833] INFO: test: PixelAlive no parameter change
[12:14:58.834] INFO: running: pixelalive
[12:14:58.840] INFO: ----------------------------------------------------------------------
[12:14:58.840] 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:14:58.840] INFO: ----------------------------------------------------------------------
[12:14:59.158] INFO: Expecting 41600 events.
[12:15:03.433] INFO: 41600 events read in total (3557ms).
[12:15:03.599] INFO: Test took 4756ms.
[12:15:03.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:03.874] INFO: PixTestAlive::aliveTest() done
[12:15:03.874] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 16 0 4 0 0 0 0 0 0 0
[12:15:03.909] INFO: enter test to run
[12:16:35.889] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:16:35.889] INFO: running: highrate
[12:16:35.889] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:16:37.261] INFO: ----------------------------------------------------------------------
[12:16:37.261] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:16:37.261] INFO: ----------------------------------------------------------------------
[12:16:37.261] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:16:37.261] INFO: edge/corner pixel THR is adjusted
[12:16:37.261] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:16:38.219] INFO: Collecting data for 5 seconds...
[12:16:43.238] INFO: Done with hot pixel readout
[12:16:54.824] INFO: PixTest:: pg_setup set to default.
[12:16:54.825] INFO: 9 hot pixels found in step 0
[12:16:55.818] INFO: Collecting data for 5 seconds...
[12:17:00.837] INFO: Done with hot pixel readout
[12:17:12.346] INFO: PixTest:: pg_setup set to default.
[12:17:12.346] INFO: 6 hot pixels found in step 1
[12:17:13.341] INFO: Collecting data for 5 seconds...
[12:17:18.360] INFO: Done with hot pixel readout
[12:17:30.062] INFO: PixTest:: pg_setup set to default.
[12:17:30.062] INFO: 7 hot pixels found in step 2
[12:17:31.057] INFO: Collecting data for 5 seconds...
[12:17:36.074] INFO: Done with hot pixel readout
[12:17:47.950] INFO: PixTest:: pg_setup set to default.
[12:17:47.951] INFO: 5 hot pixels found in step 3
[12:17:48.944] INFO: Collecting data for 5 seconds...
[12:17:53.964] INFO: Done with hot pixel readout
[12:18:05.684] INFO: PixTest:: pg_setup set to default.
[12:18:05.685] INFO: 3 hot pixels found in step 4
[12:18:06.679] INFO: Collecting data for 5 seconds...
[12:18:11.698] INFO: Done with hot pixel readout
[12:18:23.890] INFO: PixTest:: pg_setup set to default.
[12:18:23.891] INFO: 8 hot pixels found in step 5
[12:18:24.886] INFO: Collecting data for 5 seconds...
[12:18:29.904] INFO: Done with hot pixel readout
[12:18:42.053] INFO: PixTest:: pg_setup set to default.
[12:18:42.054] INFO: 0 hot pixels found in step 6
[12:18:42.093] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:18:42.096] INFO: PixTest::trimHotPixels() done
[12:18:42.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C0.dat
[12:18:42.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C1.dat
[12:18:42.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C2.dat
[12:18:42.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C3.dat
[12:18:42.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C4.dat
[12:18:42.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C5.dat
[12:18:42.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C6.dat
[12:18:42.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C7.dat
[12:18:42.142] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C8.dat
[12:18:42.147] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C9.dat
[12:18:42.153] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C10.dat
[12:18:42.159] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C11.dat
[12:18:42.164] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C12.dat
[12:18:42.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C13.dat
[12:18:42.175] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C14.dat
[12:18:42.181] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C15.dat
[12:18:42.186] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//defaultMaskFile.dat
[12:18:42.196] INFO: enter test to run
[12:19:11.736] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:19:11.736] INFO: running: highrate
[12:19:11.740] INFO: ----------------------------------------------------------------------
[12:19:11.740] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:19:11.740] INFO: ----------------------------------------------------------------------
[12:19:11.740] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:19:11.740] INFO: edge/corner pixel THR is adjusted
[12:19:11.740] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:19:12.698] INFO: Collecting data for 1 seconds...
[12:19:13.702] INFO: Done with hot pixel readout
[12:19:17.936] INFO: PixTest:: pg_setup set to default.
[12:19:17.937] INFO: 0 hot pixels found in step 0
[12:19:17.942] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:19:18.026] INFO: PixTest::trimHotPixels() done
[12:19:18.026] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C0.dat
[12:19:18.034] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C1.dat
[12:19:18.041] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C2.dat
[12:19:18.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C3.dat
[12:19:18.052] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C4.dat
[12:19:18.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C5.dat
[12:19:18.062] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C6.dat
[12:19:18.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C7.dat
[12:19:18.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C8.dat
[12:19:18.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C9.dat
[12:19:18.084] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C10.dat
[12:19:18.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C11.dat
[12:19:18.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C12.dat
[12:19:18.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C13.dat
[12:19:18.105] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C14.dat
[12:19:18.110] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//trimParameters35_C15.dat
[12:19:18.115] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-J-NK_FPIXTest-17C-FNAL-160506-1228_2016-05-06_12h28m_1462555703/000_FPIXTest_p17//defaultMaskFile.dat
[12:19:18.125] INFO: enter test to run
[12:19:41.655] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:19:41.655] INFO: running: xray
[12:19:41.657] INFO: ----------------------------------------------------------------------
[12:19:41.657] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:19:41.657] INFO: ----------------------------------------------------------------------
[12:19:42.620] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:19:54.016] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:20:23.288] INFO: Resuming triggers.
[12:20:34.693] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:21:04.165] INFO: Resuming triggers.
[12:21:15.561] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:21:45.007] INFO: Resuming triggers.
[12:21:56.409] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:22:25.821] INFO: Resuming triggers.
[12:22:37.216] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:23:06.615] INFO: Resuming triggers.
[12:23:18.013] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:23:47.413] INFO: Resuming triggers.
[12:23:58.816] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:24:28.193] INFO: Resuming triggers.
[12:24:39.594] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[12:25:08.917] INFO: Resuming triggers.
[12:25:18.050] INFO: data taking finished, elapsed time: 100 seconds.
[12:25:41.736] INFO: PixTest:: pg_setup set to default.
[12:25:41.739] INFO: PixTestXray::doPhRun() done
[12:25:41.874] INFO: enter test to run
[12:25:59.796] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:25:59.796] INFO: running: xray
[12:25:59.797] INFO: ----------------------------------------------------------------------
[12:25:59.797] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:25:59.797] INFO: ----------------------------------------------------------------------
[12:26:00.762] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:26:07.072] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:26:37.375] INFO: Resuming triggers.
[12:26:43.687] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:27:13.766] INFO: Resuming triggers.
[12:27:20.079] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[12:27:50.270] INFO: Resuming triggers.
[12:27:56.586] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[12:28:26.640] INFO: Resuming triggers.
[12:28:32.955] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[12:29:03.837] INFO: Resuming triggers.
[12:29:10.153] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[12:29:41.128] INFO: Resuming triggers.
[12:29:47.444] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[12:30:17.595] INFO: Resuming triggers.
[12:30:23.910] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[12:30:54.015] INFO: Resuming triggers.
[12:31:00.326] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:31:30.381] INFO: Resuming triggers.
[12:31:36.692] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[12:32:06.746] INFO: Resuming triggers.
[12:32:13.056] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[12:32:43.142] INFO: Resuming triggers.
[12:32:49.454] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[12:33:19.479] INFO: Resuming triggers.
[12:33:25.791] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[12:33:55.741] INFO: Resuming triggers.
[12:34:02.057] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:34:32.151] INFO: Resuming triggers.
[12:34:38.467] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[12:35:08.501] INFO: Resuming triggers.
[12:35:14.132] INFO: data taking finished, elapsed time: 100 seconds.
[12:35:41.218] INFO: PixTest:: pg_setup set to default.
[12:35:41.222] INFO: PixTestXray::doPhRun() done
[12:35:41.368] INFO: enter test to run
[12:35:55.784] INFO: test: HighRate no parameter change
[12:35:55.784] INFO: running: highrate
[12:35:55.785] INFO: ----------------------------------------------------------------------
[12:35:55.785] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:35:55.785] INFO: ----------------------------------------------------------------------
[12:35:55.927] INFO: Expecting 768 events.
[12:35:57.061] INFO: 768 events read in total (418ms).
[12:35:57.062] INFO: Test took 1269ms.
[12:35:57.865] INFO: Expecting 41600 events.
[12:36:01.018] INFO: 41600 events read in total (2627ms).
[12:36:01.019] INFO: Test took 3950ms.
[12:36:01.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:01.775] INFO: Expecting 41600 events.
[12:36:05.018] INFO: 41600 events read in total (2716ms).
[12:36:05.019] INFO: Test took 3944ms.
[12:36:05.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:05.774] INFO: Expecting 41600 events.
[12:36:09.076] INFO: 41600 events read in total (2775ms).
[12:36:09.077] INFO: Test took 4003ms.
[12:36:09.115] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:09.830] INFO: Expecting 41600 events.
[12:36:13.106] INFO: 41600 events read in total (2749ms).
[12:36:13.107] INFO: Test took 3972ms.
[12:36:13.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:13.859] INFO: Expecting 41600 events.
[12:36:17.149] INFO: 41600 events read in total (2763ms).
[12:36:17.150] INFO: Test took 3985ms.
[12:36:17.187] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:17.902] INFO: Expecting 41600 events.
[12:36:21.184] INFO: 41600 events read in total (2755ms).
[12:36:21.185] INFO: Test took 3978ms.
[12:36:21.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:21.943] INFO: Expecting 41600 events.
[12:36:25.240] INFO: 41600 events read in total (2771ms).
[12:36:25.241] INFO: Test took 3999ms.
[12:36:25.279] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:25.998] INFO: Expecting 41600 events.
[12:36:29.293] INFO: 41600 events read in total (2768ms).
[12:36:29.294] INFO: Test took 3994ms.
[12:36:29.332] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:30.050] INFO: Expecting 41600 events.
[12:36:33.341] INFO: 41600 events read in total (2764ms).
[12:36:33.342] INFO: Test took 3990ms.
[12:36:33.380] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:34.099] INFO: Expecting 41600 events.
[12:36:37.416] INFO: 41600 events read in total (2790ms).
[12:36:37.417] INFO: Test took 4016ms.
[12:36:37.456] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:38.170] INFO: Expecting 41600 events.
[12:36:41.463] INFO: 41600 events read in total (2767ms).
[12:36:41.464] INFO: Test took 3988ms.
[12:36:41.501] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:42.218] INFO: Expecting 41600 events.
[12:36:45.520] INFO: 41600 events read in total (2775ms).
[12:36:45.521] INFO: Test took 4000ms.
[12:36:45.558] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:46.276] INFO: Expecting 41600 events.
[12:36:49.566] INFO: 41600 events read in total (2764ms).
[12:36:49.567] INFO: Test took 3989ms.
[12:36:49.605] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:50.324] INFO: Expecting 41600 events.
[12:36:53.629] INFO: 41600 events read in total (2778ms).
[12:36:53.630] INFO: Test took 4005ms.
[12:36:53.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:54.383] INFO: Expecting 41600 events.
[12:36:57.687] INFO: 41600 events read in total (2777ms).
[12:36:57.688] INFO: Test took 4001ms.
[12:36:57.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:58.442] INFO: Expecting 41600 events.
[12:37:01.743] INFO: 41600 events read in total (2774ms).
[12:37:01.744] INFO: Test took 4001ms.
[12:37:01.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:02.498] INFO: Expecting 41600 events.
[12:37:05.808] INFO: 41600 events read in total (2783ms).
[12:37:05.809] INFO: Test took 4009ms.
[12:37:05.847] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:06.560] INFO: Expecting 41600 events.
[12:37:09.842] INFO: 41600 events read in total (2755ms).
[12:37:09.843] INFO: Test took 3975ms.
[12:37:09.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:10.597] INFO: Expecting 41600 events.
[12:37:13.874] INFO: 41600 events read in total (2750ms).
[12:37:13.875] INFO: Test took 3974ms.
[12:37:13.912] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:14.630] INFO: Expecting 41600 events.
[12:37:17.769] INFO: 41600 events read in total (2612ms).
[12:37:17.770] INFO: Test took 3837ms.
[12:37:17.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:18.166] INFO: enter test to run
[12:37:25.783] INFO: test: HighRate no parameter change
[12:37:25.783] INFO: running: highrate
[12:37:25.785] INFO: ----------------------------------------------------------------------
[12:37:25.785] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:37:25.785] INFO: ----------------------------------------------------------------------
[12:37:26.396] INFO: Expecting 208000 events.
[12:37:38.408] INFO: 208000 events read in total (11485ms).
[12:37:38.412] INFO: Test took 12620ms.
[12:37:38.573] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:38.831] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 14 0 4 0 0 0 0 0 0 0
[12:37:38.831] INFO: number of red-efficiency pixels: 73 69 100 149 190 201 221 140 103 113 147 116 119 62 23 38
[12:37:38.831] INFO: number of X-ray hits detected: 72072 49458 78140 121630 133232 138793 136433 95590 87066 101067 107282 94809 96326 57958 25321 31629
[12:37:38.831] 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:37:38.831] INFO: number of Vcal hits detected: 207925 207928 207898 207846 207785 207792 206891 207854 207701 207886 207846 207881 207879 207937 207977 207960
[12:37:38.831] 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:37:38.831] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.5 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:37:38.831] INFO: X-ray hit rate [MHz/cm2]: 21.1 14.5 22.9 35.7 39.1 40.7 40.0 28.0 25.5 29.6 31.4 27.8 28.2 17.0 7.4 9.3
[12:37:38.831] INFO: PixTestHighRate::doXPixelAlive() done
[12:37:38.880] INFO: PixTest:: pg_setup set to default.
[12:37:38.895] INFO: enter test to run
[12:37:49.815] INFO: test: HighRate no parameter change
[12:37:49.815] INFO: running: highrate
[12:37:49.816] INFO: ----------------------------------------------------------------------
[12:37:49.816] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:37:49.816] INFO: ----------------------------------------------------------------------
[12:37:50.431] INFO: Expecting 208000 events.
[12:38:04.372] INFO: 208000 events read in total (13414ms).
[12:38:04.377] INFO: Test took 14552ms.
[12:38:04.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:05.006] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 12 0 4 0 0 0 0 0 0 0
[12:38:05.006] INFO: number of red-efficiency pixels: 225 124 308 612 560 751 730 452 278 383 425 338 397 181 61 74
[12:38:05.006] INFO: number of X-ray hits detected: 143043 97944 154873 241160 264522 275447 270861 190347 172826 201697 213412 188873 189937 114483 50021 62636
[12:38:05.006] 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:38:05.006] INFO: number of Vcal hits detected: 207761 207872 207651 207330 207334 207136 206302 207503 207512 207585 207546 207640 207585 207806 207937 207926
[12:38:05.006] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.6 99.6 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[12:38:05.006] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.6 99.2 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[12:38:05.006] INFO: X-ray hit rate [MHz/cm2]: 41.9 28.7 45.4 70.7 77.5 80.7 79.4 55.8 50.7 59.1 62.6 55.4 55.7 33.6 14.7 18.4
[12:38:05.006] INFO: PixTestHighRate::doXPixelAlive() done
[12:38:05.054] INFO: PixTest:: pg_setup set to default.
[12:38:05.069] INFO: enter test to run
[12:38:17.183] INFO: test: HighRate no parameter change
[12:38:17.183] INFO: running: highrate
[12:38:17.184] INFO: ----------------------------------------------------------------------
[12:38:17.184] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:38:17.184] INFO: ----------------------------------------------------------------------
[12:38:17.801] INFO: Expecting 208000 events.
[12:38:34.081] INFO: 208000 events read in total (15753ms).
[12:38:34.089] INFO: Test took 16897ms.
[12:38:34.603] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:34.970] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 12 0 3 0 0 0 0 0 0 0
[12:38:34.970] INFO: number of red-efficiency pixels: 469 265 745 1388 1256 1761 1758 1065 597 922 1026 748 828 398 98 110
[12:38:34.970] INFO: number of X-ray hits detected: 216878 147866 232468 363812 396476 411611 407356 285757 261055 302209 321192 283846 286020 172642 76360 95248
[12:38:34.970] 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:38:34.970] INFO: number of Vcal hits detected: 207431 207714 206943 206106 206240 205439 204686 206604 207130 206891 206720 207094 207011 207549 207897 207890
[12:38:34.970] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.2 99.2 98.9 98.9 99.4 99.7 99.5 99.4 99.6 99.6 99.8 100.0 99.9
[12:38:34.970] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.5 99.1 99.2 98.8 98.4 99.3 99.6 99.5 99.4 99.6 99.5 99.8 100.0 99.9
[12:38:34.970] INFO: X-ray hit rate [MHz/cm2]: 63.6 43.3 68.1 106.6 116.2 120.6 119.4 83.8 76.5 88.6 94.1 83.2 83.8 50.6 22.4 27.9
[12:38:34.970] INFO: PixTestHighRate::doXPixelAlive() done
[12:38:35.015] INFO: PixTest:: pg_setup set to default.
[12:38:35.027] INFO: enter test to run
[12:38:36.807] INFO: test: exit no parameter change
[12:38:37.092] QUIET: Connection to board 33 closed.
[12:38:37.093] INFO: pXar: this is the end, my friend