[08:02:13.701] <TB2> INFO: *** Welcome to pxar ***
[08:02:13.701] <TB2> INFO: *** Today: 2016/10/11
[08:02:13.771] <TB2> INFO: *** Version: f5d3-dirty
[08:02:13.771] <TB2> INFO: readRocDacs: /usr/local/data/M2358_XrayQualification_2016-10-11_09h45m_1476171913//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2358_XrayQualification_2016-10-11_09h45m_1476171913//005_HRData_150//dacParameters35_C15.dat
[08:02:13.772] <TB2> INFO: readTbmDacs: /usr/local/data/M2358_XrayQualification_2016-10-11_09h45m_1476171913//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2358_XrayQualification_2016-10-11_09h45m_1476171913//005_HRData_150//tbmParameters_C0b.dat
[08:02:13.772] <TB2> INFO: readMaskFile: /usr/local/data/M2358_XrayQualification_2016-10-11_09h45m_1476171913//005_HRData_150//defaultMaskFile.dat
[08:02:13.772] <TB2> INFO: readTrimFile: /usr/local/data/M2358_XrayQualification_2016-10-11_09h45m_1476171913//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2358_XrayQualification_2016-10-11_09h45m_1476171913//005_HRData_150//trimParameters35_C15.dat
[08:02:13.862] <TB2> INFO: clk: 4
[08:02:13.862] <TB2> INFO: ctr: 4
[08:02:13.862] <TB2> INFO: sda: 19
[08:02:13.862] <TB2> INFO: tin: 9
[08:02:13.862] <TB2> INFO: level: 15
[08:02:13.862] <TB2> INFO: triggerdelay: 0
[08:02:13.862] <TB2> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[08:02:13.862] <TB2> INFO: Log level: INFO
[08:02:13.875] <TB2> INFO: Found DTB DTB_WXENWR
[08:02:13.886] <TB2> QUIET: Connection to board DTB_WXENWR opened.
[08:02:13.888] <TB2> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 162
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXENWR
MAC address: 40D8551180A2
Hostname: pixelDTB162
Comment:
------------------------------------------------------
[08:02:13.890] <TB2> INFO: RPC call hashes of host and DTB match: 486171790
[08:02:15.422] <TB2> INFO: DUT info:
[08:02:15.422] <TB2> INFO: The DUT currently contains the following objects:
[08:02:15.422] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[08:02:15.422] <TB2> INFO: TBM Core alpha (0): 7 registers set
[08:02:15.422] <TB2> INFO: TBM Core beta (1): 7 registers set
[08:02:15.422] <TB2> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[08:02:15.422] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.422] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[08:02:15.823] <TB2> INFO: enter 'restricted' command line mode
[08:02:15.823] <TB2> INFO: enter test to run
[08:02:15.823] <TB2> INFO: test: delay setting parameters: ->5<-
[08:02:15.823] <TB2> INFO: delay test by 5 seconds...
[08:02:20.823] <TB2> INFO: enter test to run
[08:02:20.823] <TB2> INFO: test: Xray no parameter change
[08:02:20.823] <TB2> INFO: running: xray
[08:02:20.824] <TB2> INFO: readGainPedestalParameters /usr/local/data/M2358_XrayQualification_2016-10-11_09h45m_1476171913//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2358_XrayQualification_2016-10-11_09h45m_1476171913//005_HRData_150//phCalibrationFitErr35_C15.dat
[08:02:20.955] <TB2> INFO: ######################################################################
[08:02:20.955] <TB2> INFO: PixTestXray::doTest()
[08:02:20.955] <TB2> INFO: ######################################################################
[08:02:20.955] <TB2> INFO: ----------------------------------------------------------------------
[08:02:20.955] <TB2> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[08:02:20.955] <TB2> INFO: ----------------------------------------------------------------------
[08:02:21.678] <TB2> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[08:02:25.597] <TB2> INFO: run duration 3 seconds, buffer almost full (81%), pausing triggers.
[08:02:51.305] <TB2> INFO: Resuming triggers.
[08:02:55.232] <TB2> INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[08:03:19.888] <TB2> INFO: Resuming triggers.
[08:03:23.812] <TB2> INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[08:03:48.943] <TB2> INFO: Resuming triggers.
[08:03:52.863] <TB2> INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[08:04:18.729] <TB2> INFO: Resuming triggers.
[08:04:22.645] <TB2> INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[08:04:30.795] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 1 Number of ROCs (5) != Token Chain Length (4)
[08:04:30.795] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[08:04:30.795] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a14f 8040 4062 6c0 244b 4062 304 2a2e 404 246a 555 204e 40e2 562 228a 608 2a4a 609 224f 60a 2662 84b 2882 4062 361 246e 48c 224a 559 204c 55a 2a48 562 224f e000 c000
[08:04:30.795] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a149 80c0 4060 20 204c 1d 2860 5 224f 548 222e 4060 42 2646 218 264f 300 244a 4060 1c 2484 d8 2a68 44c 2866 645 286c 4060 30b 2a81 405 28a2 600 2640 61b 2669 64b 246a 65c 2268 804 2a87 e000 c000
[08:04:30.795] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a14a 8000 4060 0 244f dc 224a 50d 2848 70d 2a49 40e0 cc 2461 c5 2a84 145 2463 30d 2449 31d 2265 4060 314 2a64 492 2a82 4060 19 286a 111 22a8 4c5 246a 4c5 206f 4c9 264e 613 2469 611 2847 e000 c000
[08:04:30.795] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a14b 8040 4060 14 244a 292 2266 520 2263 844 2a48 4060 90 224f 610 2a43 815 2a6e 84d 2040 85b 2a8b 4060 15 2284 319 2082 31d 2261 64b 2a67 4060 400 2a4d 45c 242f e000 c000
[08:04:30.795] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a14c 80b0 4060 100 2a64 119 224e 252 2866 762 2086 4070 4b 226c 2dd 264e 81a 244a 811 204e 4060 d1 2a61 4060 20a 2a4e 4061 ec2 2822 624 2c28 488 2192 6e8 2596 e000 c000
[08:04:30.795] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a14d 80c0 4060 254 204a 68d 204a 741 2a62 4060 319 2668 4c4 2862 503 2868 4060 322 286b 4d9 2266 6db 266b 4060 253 284d 741 244f e000 c000
[08:04:30.795] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a14e 8000 4060 4060 d1 226d 4060 d8 266e 320 204f 30b 206e 812 2089 4060 295 204e 815 2467 e000 c000
[08:04:48.558] <TB2> INFO: Resuming triggers.
[08:04:52.475] <TB2> INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[08:05:18.054] <TB2> INFO: Resuming triggers.
[08:05:21.966] <TB2> INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[08:05:49.250] <TB2> INFO: Resuming triggers.
[08:05:53.163] <TB2> INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[08:05:58.282] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 1 Number of ROCs (5) != Token Chain Length (4)
[08:05:58.283] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[08:05:58.283] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a10c 80b0 4060 294 2844 2c9 224d 692 2a42 4060 14c 244a 492 244f 40e0 4060 4a 282d cb 2081 840 2a2b e000 c000
[08:05:58.283] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a106 8000 4060 4060 4d 286b 4060 8c 244f 82 2862 162 246a 145 2861 28b 226a 45b 2889 691 2082 4061 e000 c000
[08:05:58.283] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a107 8040 4060 142 286f 4060 4ca 2869 501 224f 812 2462 4060 4060 61 2a4f e000 c000
[08:05:58.283] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a108 80b0 4060 248 2a48 80d 2043 800 264a 4060 5b 2460 44 284d 204 2a45 4da 264d 4060 c 2865 10a 26a1 559 2a4e 854 264d 4061 e000 c000
[08:05:58.283] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a109 80c0 4060 a2 286a 11d 2642 4d9 246f 4060 88 2829 31b 266d 4063 dec 2888 c6c 2a8c dee 2094 4060 544 264e 649 2682 65c 2a65 4060 48 2642 48 2a42 253 2a4e 4cc 206e 512 2086 513 2a68 601 2262 750 2466 84a 2867 e000 c000
[08:05:58.283] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a10a 8000 4060 140 264a 718 2262 4060 419 206e 74a 2643 4060 559 246b 4060 242 224f e000 c000
[08:05:58.283] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a10b 8040 4060 702 266d 4060 448 2264 741 244f 4060 8b 206f 34b 2668 4060 105 2a6c 108 2a6c 208 264f 444 2841 e000 c000
[08:06:19.169] <TB2> INFO: Resuming triggers.
[08:06:23.079] <TB2> INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[08:06:49.909] <TB2> INFO: Resuming triggers.
[08:06:53.813] <TB2> INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[08:07:20.656] <TB2> INFO: Resuming triggers.
[08:07:24.561] <TB2> INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[08:07:52.777] <TB2> INFO: Resuming triggers.
[08:07:56.678] <TB2> INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[08:08:23.045] <TB2> INFO: Resuming triggers.
[08:08:26.945] <TB2> INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[08:08:52.273] <TB2> INFO: Resuming triggers.
[08:08:56.173] <TB2> INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[08:09:21.718] <TB2> INFO: Resuming triggers.
[08:09:25.613] <TB2> INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[08:09:51.110] <TB2> INFO: Resuming triggers.
[08:09:55.006] <TB2> INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[08:10:20.685] <TB2> INFO: Resuming triggers.
[08:10:24.577] <TB2> INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[08:10:50.623] <TB2> INFO: Resuming triggers.
[08:10:54.519] <TB2> INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[08:11:20.461] <TB2> INFO: Resuming triggers.
[08:11:24.355] <TB2> INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[08:11:50.298] <TB2> INFO: Resuming triggers.
[08:11:54.192] <TB2> INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[08:12:21.145] <TB2> INFO: Resuming triggers.
[08:12:25.035] <TB2> INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[08:12:51.726] <TB2> INFO: Resuming triggers.
[08:12:55.615] <TB2> INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[08:13:21.133] <TB2> INFO: Resuming triggers.
[08:13:25.024] <TB2> INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[08:13:50.850] <TB2> INFO: Resuming triggers.
[08:13:54.737] <TB2> INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[08:14:18.521] <TB2> INFO: Resuming triggers.
[08:14:22.408] <TB2> INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[08:14:45.037] <TB2> INFO: Resuming triggers.
[08:14:47.544] <TB2> INFO: data taking finished, elapsed time: 100 seconds.
[08:15:02.542] <TB2> INFO: PixTest:: pg_setup set to default.
[08:15:02.543] <TB2> INFO: PixTestXray::doPhRun() done
[08:15:02.543] <TB2> INFO: PixTestXray::doTest() done
[08:15:02.724] <TB2> INFO: enter test to run
[08:15:02.724] <TB2> INFO: test: no parameter change
[08:15:02.963] <TB2> QUIET: Connection to board 162 closed.
[08:15:03.043] <TB2> INFO: pXar: this is the end, my friend