[11:55:59.964] <TB1> INFO: *** Welcome to pxar ***
[11:55:59.964] <TB1> INFO: *** Today: 2015/09/01
[11:55:59.965] <TB1> INFO: readRocDacs: /usr/local/data/M2094_XrayQualification_2015-09-01_13h21m_1441106515//005_HRSCurves_100//dacParameters35_C0.dat .. /usr/local/data/M2094_XrayQualification_2015-09-01_13h21m_1441106515//005_HRSCurves_100//dacParameters35_C15.dat
[11:55:59.966] <TB1> INFO: readTbmDacs: /usr/local/data/M2094_XrayQualification_2015-09-01_13h21m_1441106515//005_HRSCurves_100//tbmParameters_C0a.dat .. /usr/local/data/M2094_XrayQualification_2015-09-01_13h21m_1441106515//005_HRSCurves_100//tbmParameters_C0b.dat
[11:55:59.967] <TB1> INFO: readMaskFile: /usr/local/data/M2094_XrayQualification_2015-09-01_13h21m_1441106515//005_HRSCurves_100//defaultMaskFile.dat
[11:55:59.967] <TB1> INFO: readTrimFile: /usr/local/data/M2094_XrayQualification_2015-09-01_13h21m_1441106515//005_HRSCurves_100//trimParameters35_C0.dat .. /usr/local/data/M2094_XrayQualification_2015-09-01_13h21m_1441106515//005_HRSCurves_100//trimParameters35_C15.dat
[11:56:00.050] <TB1> INFO: clk: 4
[11:56:00.050] <TB1> INFO: ctr: 4
[11:56:00.050] <TB1> INFO: sda: 19
[11:56:00.050] <TB1> INFO: tin: 9
[11:56:00.050] <TB1> INFO: level: 15
[11:56:00.050] <TB1> INFO: triggerdelay: 0
[11:56:00.050] <TB1> QUIET: Instanciating API for pxar prod-10
[11:56:00.050] <TB1> INFO: Log level: INFO
[11:56:00.062] <TB1> INFO: Found DTB DTB_WWXTQT
[11:56:00.074] <TB1> QUIET: Connection to board DTB_WWXTQT opened.
[11:56:00.078] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 147
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WWXTQT
MAC address: 40D855118093
Hostname: pixelDTB147
Comment:
------------------------------------------------------
[11:56:00.081] <TB1> INFO: RPC call hashes of host and DTB match: 397073690
[11:56:01.608] <TB1> INFO: DUT info:
[11:56:01.609] <TB1> INFO: The DUT currently contains the following objects:
[11:56:01.609] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:56:01.609] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:56:01.609] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:56:01.609] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:56:01.609] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:01.609] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:02.010] <TB1> INFO: enter 'restricted' command line mode
[11:56:02.010] <TB1> INFO: enter test to run
[11:56:02.011] <TB1> INFO: test: Highrate no parameter change
[11:56:02.011] <TB1> INFO: running: highrate
[11:56:02.011] <TB1> INFO: readGainPedestalParameters /usr/local/data/M2094_XrayQualification_2015-09-01_13h21m_1441106515//005_HRSCurves_100//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2094_XrayQualification_2015-09-01_13h21m_1441106515//005_HRSCurves_100//phCalibrationFitErr35_C15.dat
[11:56:02.155] <TB1> INFO: ----------------------------------------------------------------------
[11:56:02.155] <TB1> INFO: PixTestHighRate::xNoiseMaps() ntrig = 50, vcal = 200
[11:56:02.155] <TB1> INFO: ----------------------------------------------------------------------
[11:56:02.161] <TB1> INFO: ---> dac: vcal name: xNoiseMap ntrig: 50 dacrange: 0 .. 100 (20/-1) hits flags = 384 (plus default)
[11:56:02.174] <TB1> INFO: dacScan step from 0 .. 19
[11:56:02.174] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[11:56:02.174] <TB1> INFO: run 1 of 1
[11:56:02.773] <TB1> INFO: Expecting 4160000 events.
[11:56:35.182] <TB1> INFO: 400200 events read in total (31879ms).
[11:57:06.685] <TB1> INFO: 803050 events read in total (63382ms).
[11:57:38.249] <TB1> INFO: 1205600 events read in total (94946ms).
[11:58:09.390] <TB1> INFO: 1607750 events read in total (126087ms).
[11:58:39.502] <TB1> INFO: 2009700 events read in total (156199ms).
[11:59:09.977] <TB1> INFO: 2411750 events read in total (186674ms).
[11:59:40.786] <TB1> INFO: 2814250 events read in total (217483ms).
[12:00:11.499] <TB1> INFO: 3216350 events read in total (248196ms).
[12:00:40.547] <TB1> INFO: 3618900 events read in total (277244ms).
[12:01:13.216] <TB1> INFO: 4021350 events read in total (309913ms).
[12:01:25.154] <TB1> INFO: 4160000 events read in total (321851ms).
[12:01:25.323] <TB1> INFO: Test took 323149ms.
[12:01:27.738] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:33.647] <TB1> INFO: dacScan step from 20 .. 39
[12:01:33.647] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[12:01:33.647] <TB1> INFO: run 1 of 1
[12:01:34.244] <TB1> INFO: Expecting 4160000 events.
[12:02:07.480] <TB1> INFO: 398350 events read in total (32685ms).
[12:02:40.452] <TB1> INFO: 798650 events read in total (65658ms).
[12:03:15.167] <TB1> INFO: 1199200 events read in total (100372ms).
[12:03:49.824] <TB1> INFO: 1599250 events read in total (135029ms).
[12:04:23.722] <TB1> INFO: 1998900 events read in total (168927ms).
[12:04:58.328] <TB1> INFO: 2399000 events read in total (203533ms).
[12:05:31.042] <TB1> INFO: 2798300 events read in total (236247ms).
[12:06:02.225] <TB1> INFO: 3196950 events read in total (267430ms).
[12:06:34.459] <TB1> INFO: 3594400 events read in total (299664ms).
[12:07:08.247] <TB1> INFO: 3991700 events read in total (333452ms).
[12:07:22.605] <TB1> INFO: 4160000 events read in total (347810ms).
[12:07:22.799] <TB1> INFO: Test took 349152ms.
[12:07:24.789] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:31.219] <TB1> INFO: dacScan step from 40 .. 59
[12:07:31.219] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[12:07:31.219] <TB1> INFO: run 1 of 1
[12:07:31.825] <TB1> INFO: Expecting 4160000 events.
[12:08:02.958] <TB1> INFO: 327550 events read in total (30593ms).
[12:08:34.067] <TB1> INFO: 656550 events read in total (61702ms).
[12:09:05.757] <TB1> INFO: 984550 events read in total (93392ms).
[12:09:37.861] <TB1> INFO: 1311900 events read in total (125496ms).
[12:10:10.286] <TB1> INFO: 1638300 events read in total (157921ms).
[12:10:41.995] <TB1> INFO: 1963900 events read in total (189630ms).
[12:11:14.378] <TB1> INFO: 2288200 events read in total (222013ms).
[12:11:44.059] <TB1> INFO: 2610800 events read in total (251694ms).
[12:12:17.026] <TB1> INFO: 2931800 events read in total (284661ms).
[12:12:48.919] <TB1> INFO: 3251000 events read in total (316554ms).
[12:13:20.240] <TB1> INFO: 3569250 events read in total (347875ms).
[12:13:50.969] <TB1> INFO: 3887400 events read in total (378604ms).
[12:14:18.647] <TB1> INFO: 4160000 events read in total (406282ms).
[12:14:18.925] <TB1> INFO: Test took 407706ms.
[12:14:21.827] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:27.879] <TB1> INFO: dacScan step from 60 .. 79
[12:14:27.879] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[12:14:27.879] <TB1> INFO: run 1 of 1
[12:14:28.474] <TB1> INFO: Expecting 4160000 events.
[12:14:58.749] <TB1> INFO: 306400 events read in total (29746ms).
[12:15:28.716] <TB1> INFO: 613500 events read in total (59713ms).
[12:15:58.699] <TB1> INFO: 920950 events read in total (89696ms).
[12:16:27.405] <TB1> INFO: 1228350 events read in total (118402ms).
[12:16:56.585] <TB1> INFO: 1535350 events read in total (147582ms).
[12:17:25.750] <TB1> INFO: 1842650 events read in total (176747ms).
[12:17:53.831] <TB1> INFO: 2150100 events read in total (204828ms).
[12:18:25.471] <TB1> INFO: 2457100 events read in total (236468ms).
[12:18:57.278] <TB1> INFO: 2764300 events read in total (268275ms).
[12:19:25.084] <TB1> WARNING: Channel 2 ROC 3: Readback start marker after 2 readouts!
[12:19:25.084] <TB1> WARNING: Channel 2 ROC 3: Readback start marker after 14 readouts!
[12:19:29.867] <TB1> INFO: 3070950 events read in total (300864ms).
[12:20:02.018] <TB1> INFO: 3377900 events read in total (333015ms).
[12:20:33.971] <TB1> INFO: 3685000 events read in total (364968ms).
[12:21:05.824] <TB1> INFO: 3991850 events read in total (396821ms).
[12:21:23.574] <TB1> INFO: 4160000 events read in total (414571ms).
[12:21:23.838] <TB1> INFO: Test took 415959ms.
[12:21:26.786] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:33.164] <TB1> INFO: dacScan step from 80 .. 99
[12:21:33.164] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[12:21:33.164] <TB1> INFO: run 1 of 1
[12:21:33.770] <TB1> INFO: Expecting 4160000 events.
[12:22:06.057] <TB1> INFO: 306050 events read in total (31759ms).
[12:22:37.353] <TB1> INFO: 612800 events read in total (63055ms).
[12:22:57.030] <TB1> WARNING: Channel 2 ROC 3: Readback start marker after 32 readouts!
[12:23:09.395] <TB1> INFO: 919700 events read in total (95097ms).
[12:23:40.910] <TB1> INFO: 1226200 events read in total (126612ms).
[12:24:12.588] <TB1> INFO: 1533150 events read in total (158290ms).
[12:24:41.462] <TB1> INFO: 1840150 events read in total (187164ms).
[12:25:06.368] <TB1> INFO: 2147000 events read in total (212070ms).
[12:25:31.308] <TB1> INFO: 2453350 events read in total (237010ms).
[12:25:55.879] <TB1> INFO: 2759800 events read in total (261581ms).
[12:26:20.786] <TB1> INFO: 3066200 events read in total (286488ms).
[12:26:45.381] <TB1> INFO: 3372500 events read in total (311083ms).
[12:27:09.745] <TB1> INFO: 3679150 events read in total (335447ms).
[12:27:33.551] <TB1> INFO: 3985400 events read in total (359253ms).
[12:27:46.908] <TB1> INFO: 4160000 events read in total (372610ms).
[12:27:47.140] <TB1> INFO: Test took 373976ms.
[12:27:49.060] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:55.049] <TB1> INFO: dacScan step from 100 .. 100
[12:27:55.049] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[12:27:55.049] <TB1> INFO: run 1 of 1
[12:27:55.644] <TB1> INFO: Expecting 208000 events.
[12:28:12.261] <TB1> INFO: 208000 events read in total (16090ms).
[12:28:12.270] <TB1> INFO: Test took 17220ms.
[12:28:12.364] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:12.647] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:13.923] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:15.172] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:16.401] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:17.736] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:19.055] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:20.433] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:21.788] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:23.152] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:24.496] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:25.845] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:27.213] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:28.538] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:29.889] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:31.108] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:32.334] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:28:33.575] <TB1> INFO: PixTest:: pg_setup set to default.
[12:28:33.577] <TB1> INFO: vcal mean: 39.60 40.31 39.41 43.20 42.77 45.18 43.54 44.15 44.48 43.83 43.94 42.51 42.94 40.38 39.63 39.96
[12:28:33.577] <TB1> INFO: vcal RMS: 1.23 1.25 0.87 1.44 1.23 1.56 1.46 1.53 1.65 2.18 1.51 1.56 1.39 1.45 1.10 1.16
[12:28:33.577] <TB1> INFO: number of X-ray hits detected: 245887 254144 218088 411606 427196 527022 440773 453815 486119 455236 471615 386363 395394 235747 218976 235154
[12:28:33.577] <TB1> 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:28:33.577] <TB1> INFO: X-ray hit rate [MHz/cm2]: 72.1 74.5 63.9 120.6 125.2 154.5 129.2 133.0 142.5 133.4 138.2 113.2 115.9 69.1 64.2 68.9
[12:28:33.577] <TB1> INFO: PixTestHighRate::doXNoiseMaps() done
[12:28:33.671] <TB1> INFO: enter test to run
[12:28:33.672] <TB1> INFO: test: no parameter change
[12:28:33.843] <TB1> QUIET: Connection to board 147 closed.
[12:28:33.923] <TB1> INFO: pXar: this is the end, my friend