[12:33:49.425] <TB1> INFO: *** Welcome to pxar ***
[12:33:49.425] <TB1> INFO: *** Today: 2016/01/12
[12:33:49.484] <TB1> INFO: *** Version: b2d3
[12:33:49.484] <TB1> INFO: readRocDacs: /usr/local/data/M2132_XrayQualification_2016-01-12_12h57m_1452599828//006_HRSCurves_100//dacParameters35_C0.dat .. /usr/local/data/M2132_XrayQualification_2016-01-12_12h57m_1452599828//006_HRSCurves_100//dacParameters35_C15.dat
[12:33:49.484] <TB1> INFO: readTbmDacs: /usr/local/data/M2132_XrayQualification_2016-01-12_12h57m_1452599828//006_HRSCurves_100//tbmParameters_C0a.dat .. /usr/local/data/M2132_XrayQualification_2016-01-12_12h57m_1452599828//006_HRSCurves_100//tbmParameters_C0b.dat
[12:33:49.485] <TB1> INFO: readMaskFile: /usr/local/data/M2132_XrayQualification_2016-01-12_12h57m_1452599828//006_HRSCurves_100//defaultMaskFile.dat
[12:33:49.485] <TB1> INFO: readTrimFile: /usr/local/data/M2132_XrayQualification_2016-01-12_12h57m_1452599828//006_HRSCurves_100//trimParameters35_C0.dat .. /usr/local/data/M2132_XrayQualification_2016-01-12_12h57m_1452599828//006_HRSCurves_100//trimParameters35_C15.dat
[12:33:49.553] <TB1> INFO: clk: 4
[12:33:49.553] <TB1> INFO: ctr: 4
[12:33:49.553] <TB1> INFO: sda: 19
[12:33:49.553] <TB1> INFO: tin: 9
[12:33:49.553] <TB1> INFO: level: 15
[12:33:49.553] <TB1> INFO: triggerdelay: 0
[12:33:49.553] <TB1> QUIET: Instanciating API for pxar prod-12
[12:33:49.553] <TB1> INFO: Log level: INFO
[12:33:49.565] <TB1> INFO: Found DTB DTB_WWXTQT
[12:33:49.575] <TB1> QUIET: Connection to board DTB_WWXTQT opened.
[12:33:49.578] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 147
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WWXTQT
MAC address: 40D855118093
Hostname: pixelDTB147
Comment:
------------------------------------------------------
[12:33:49.581] <TB1> INFO: RPC call hashes of host and DTB match: 398089610
[12:33:51.160] <TB1> INFO: DUT info:
[12:33:51.161] <TB1> INFO: The DUT currently contains the following objects:
[12:33:51.161] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:33:51.161] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:33:51.161] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:33:51.161] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:33:51.161] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.161] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:33:51.562] <TB1> INFO: enter 'restricted' command line mode
[12:33:51.562] <TB1> INFO: enter test to run
[12:33:51.562] <TB1> INFO: test: Highrate no parameter change
[12:33:51.562] <TB1> INFO: running: highrate
[12:33:51.562] <TB1> INFO: readGainPedestalParameters /usr/local/data/M2132_XrayQualification_2016-01-12_12h57m_1452599828//006_HRSCurves_100//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2132_XrayQualification_2016-01-12_12h57m_1452599828//006_HRSCurves_100//phCalibrationFitErr35_C15.dat
[12:33:51.785] <TB1> INFO: ----------------------------------------------------------------------
[12:33:51.785] <TB1> INFO: PixTestHighRate::xNoiseMaps() ntrig = 50, vcal = 200
[12:33:51.785] <TB1> INFO: ----------------------------------------------------------------------
[12:33:51.792] <TB1> INFO: ---> dac: vcal name: xNoiseMap ntrig: 50 dacrange: 15 .. 75 (20/-1) hits flags = 896 (plus default)
[12:33:51.806] <TB1> INFO: dacScan step from 15 .. 34
[12:33:51.807] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[12:33:51.807] <TB1> INFO: run 1 of 1
[12:33:52.431] <TB1> INFO: Expecting 4160000 events.
[12:34:28.735] <TB1> INFO: 441350 events read in total (35774ms).
[12:35:03.412] <TB1> INFO: 884300 events read in total (70451ms).
[12:35:38.054] <TB1> INFO: 1327550 events read in total (105093ms).
[12:36:13.057] <TB1> INFO: 1770150 events read in total (140096ms).
[12:36:47.769] <TB1> INFO: 2212750 events read in total (174808ms).
[12:37:22.478] <TB1> INFO: 2655350 events read in total (209517ms).
[12:37:57.095] <TB1> INFO: 3097350 events read in total (244134ms).
[12:38:21.756] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (5) != Token Chain Length (4)
[12:38:21.756] <TB1> ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[12:38:21.756] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cc 80b1 4788 859 2240 4788 81b 2667 4788 21a 286a 220 224f 420 2082 41d 284f 611 2462 6c9 246d 80a 224a 4788 2d0 224c 649 2061 e002 c000
[12:38:21.756] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c6 8000 4788 43 284d 4788 254 2269 54d 2444 61a 282d 4788 28d 2669 84b 2269 4788 10d 2645 222 284c 68a 2663 e002 c000
[12:38:21.756] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c7 8040 4788 491 2a80 4788 54d 2465 4788 42 2862 4788 e002 c000
[12:38:21.756] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c8 80b1 4788 2ca 2a41 4788 4c 2845 4c1 2266 4c8 2a68 4788 4a 2245 21c 2265 30c 2445 844 262f 4788 d 2060 310 204c e002 c000
[12:38:21.756] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1c9 80c0 4788 652 2869 4788 8d 244f 99 266f 14a 2a45 402 226e 815 244d 822 2262 4788 15c 2644 459 2842 4788 478b 284c e002 c000
[12:38:21.756] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ca 8000 4789 448 2864 4789 c8 2241 70a 2245 4789 14 2864 c 2845 84d 2680 4789 fff 2fff fff 2fff e002 c000
[12:38:21.756] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cb 8040 4788 4788 102 2a41 4788 50 2829 51 2a4f 8d 2264 cb 2447 4e2 2a6c 501 262d 4788 343 2245 403 284d 75b 2041 e002 c000
[12:38:31.959] <TB1> INFO: 3539100 events read in total (278998ms).
[12:39:05.560] <TB1> INFO: 3980650 events read in total (312599ms).
[12:39:20.611] <TB1> INFO: 4160000 events read in total (327650ms).
[12:39:20.965] <TB1> INFO: Test took 329158ms.
[12:39:22.753] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:28.898] <TB1> INFO: dacScan step from 35 .. 54
[12:39:28.898] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[12:39:28.898] <TB1> INFO: run 1 of 1
[12:39:29.517] <TB1> INFO: Expecting 4160000 events.
[12:40:05.778] <TB1> INFO: 371900 events read in total (35734ms).
[12:40:41.139] <TB1> INFO: 744850 events read in total (71095ms).
[12:41:16.956] <TB1> INFO: 1116900 events read in total (106912ms).
[12:41:52.567] <TB1> INFO: 1488200 events read in total (142523ms).
[12:42:27.218] <TB1> INFO: 1858350 events read in total (177174ms).
[12:43:01.370] <TB1> INFO: 2226500 events read in total (211326ms).
[12:43:35.706] <TB1> INFO: 2592150 events read in total (245662ms).
[12:44:09.666] <TB1> INFO: 2955000 events read in total (279622ms).
[12:44:44.639] <TB1> INFO: 3315300 events read in total (314595ms).
[12:45:15.943] <TB1> INFO: 3673550 events read in total (345899ms).
[12:45:49.093] <TB1> INFO: 4031400 events read in total (379049ms).
[12:46:01.770] <TB1> INFO: 4160000 events read in total (391726ms).
[12:46:01.963] <TB1> INFO: Test took 393065ms.
[12:46:03.820] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:09.896] <TB1> INFO: dacScan step from 55 .. 74
[12:46:09.896] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[12:46:09.896] <TB1> INFO: run 1 of 1
[12:46:10.515] <TB1> INFO: Expecting 4160000 events.
[12:46:45.256] <TB1> INFO: 329600 events read in total (34213ms).
[12:47:19.497] <TB1> INFO: 659900 events read in total (68454ms).
[12:47:53.861] <TB1> INFO: 990050 events read in total (102818ms).
[12:48:28.419] <TB1> INFO: 1320450 events read in total (137376ms).
[12:49:02.810] <TB1> INFO: 1651050 events read in total (171767ms).
[12:49:39.082] <TB1> INFO: 1981400 events read in total (208039ms).
[12:50:14.483] <TB1> INFO: 2311850 events read in total (243440ms).
[12:50:50.419] <TB1> INFO: 2641900 events read in total (279377ms).
[12:51:25.602] <TB1> INFO: 2971850 events read in total (314559ms).
[12:52:00.136] <TB1> INFO: 3302150 events read in total (349093ms).
[12:52:32.234] <TB1> INFO: 3632500 events read in total (381191ms).
[12:53:00.351] <TB1> INFO: 3962600 events read in total (409308ms).
[12:53:16.774] <TB1> INFO: 4160000 events read in total (425731ms).
[12:53:16.965] <TB1> INFO: Test took 427069ms.
[12:53:18.846] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:25.005] <TB1> INFO: dacScan step from 75 .. 75
[12:53:25.005] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[12:53:25.005] <TB1> INFO: run 1 of 1
[12:53:25.608] <TB1> INFO: Expecting 208000 events.
[12:53:44.361] <TB1> INFO: 208000 events read in total (18226ms).
[12:53:44.368] <TB1> INFO: Test took 19362ms.
[12:53:44.457] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:44.727] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:45.810] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:46.845] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:47.882] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:48.952] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:50.021] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:51.126] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:52.211] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:53.300] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:54.382] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:55.438] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:56.522] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:57.577] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:58.618] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:53:59.628] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:54:00.646] <TB1> INFO: dumping ASCII scurve output file: XSCurveData
[12:54:01.671] <TB1> INFO: PixTest:: pg_setup set to default.
[12:54:01.672] <TB1> INFO: vcal mean: 39.46 39.13 38.66 41.08 41.97 43.83 43.23 42.46 42.59 42.24 43.12 41.59 41.52 38.95 38.97 39.33
[12:54:01.672] <TB1> INFO: vcal RMS: 1.18 1.26 1.24 1.39 1.40 1.46 1.51 1.44 1.44 1.51 1.45 1.51 1.33 1.37 1.07 1.17
[12:54:01.672] <TB1> INFO: number of X-ray hits detected: 234541 213600 201092 332731 352562 441598 402520 392072 391133 382846 414798 326276 340197 193071 203419 214551
[12:54:01.672] <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:54:01.672] <TB1> INFO: X-ray hit rate [MHz/cm2]: 68.7 62.6 58.9 97.5 103.3 129.4 118.0 114.9 114.6 112.2 121.6 95.6 99.7 56.6 59.6 62.9
[12:54:01.672] <TB1> INFO: PixTestHighRate::doXNoiseMaps() done
[12:54:01.777] <TB1> INFO: enter test to run
[12:54:01.778] <TB1> INFO: test: no parameter change
[12:54:01.947] <TB1> QUIET: Connection to board 147 closed.
[12:54:02.043] <TB1> INFO: pXar: this is the end, my friend