[12:54:13.600] <TB1> INFO: *** Welcome to pxar ***
[12:54:13.600] <TB1> INFO: *** Today: 2015/11/23
[12:54:13.830] <TB1> INFO: *** Version: 206d-dirty
[12:54:13.831] <TB1> INFO: readRocDacs: /usr/local/data/M2120_XrayQualification_2015-11-23_13h32m_1448281936//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2120_XrayQualification_2015-11-23_13h32m_1448281936//005_HRData_150//dacParameters35_C15.dat
[12:54:13.833] <TB1> INFO: readTbmDacs: /usr/local/data/M2120_XrayQualification_2015-11-23_13h32m_1448281936//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2120_XrayQualification_2015-11-23_13h32m_1448281936//005_HRData_150//tbmParameters_C0b.dat
[12:54:13.833] <TB1> INFO: readMaskFile: /usr/local/data/M2120_XrayQualification_2015-11-23_13h32m_1448281936//005_HRData_150//defaultMaskFile.dat
[12:54:13.833] <TB1> INFO: readTrimFile: /usr/local/data/M2120_XrayQualification_2015-11-23_13h32m_1448281936//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2120_XrayQualification_2015-11-23_13h32m_1448281936//005_HRData_150//trimParameters35_C15.dat
[12:54:13.907] <TB1> INFO: clk: 4
[12:54:13.907] <TB1> INFO: ctr: 4
[12:54:13.907] <TB1> INFO: sda: 19
[12:54:13.907] <TB1> INFO: tin: 9
[12:54:13.907] <TB1> INFO: level: 15
[12:54:13.907] <TB1> INFO: triggerdelay: 0
[12:54:13.907] <TB1> QUIET: Instanciating API for pxar v2.6.0+26~g89693ff
[12:54:13.907] <TB1> INFO: Log level: INFO
[12:54:13.920] <TB1> INFO: Found DTB DTB_WWXTQT
[12:54:13.935] <TB1> QUIET: Connection to board DTB_WWXTQT opened.
[12:54:13.938] <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:54:13.941] <TB1> INFO: RPC call hashes of host and DTB match: 398089610
[12:54:15.498] <TB1> INFO: DUT info:
[12:54:15.498] <TB1> INFO: The DUT currently contains the following objects:
[12:54:15.498] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:54:15.498] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:54:15.498] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:54:15.498] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:54:15.498] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.498] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.499] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:54:15.899] <TB1> INFO: enter 'restricted' command line mode
[12:54:15.900] <TB1> INFO: enter test to run
[12:54:15.900] <TB1> INFO: test: delay setting parameters: ->5<-
[12:54:15.900] <TB1> INFO: delay test by 5 seconds...
[12:54:20.900] <TB1> INFO: enter test to run
[12:54:20.900] <TB1> INFO: test: Xray no parameter change
[12:54:20.900] <TB1> INFO: running: xray
[12:54:20.907] <TB1> INFO: readGainPedestalParameters /usr/local/data/M2120_XrayQualification_2015-11-23_13h32m_1448281936//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2120_XrayQualification_2015-11-23_13h32m_1448281936//005_HRData_150//phCalibrationFitErr35_C15.dat
[12:54:21.164] <TB1> INFO: ######################################################################
[12:54:21.164] <TB1> INFO: PixTestXray::doTest()
[12:54:21.164] <TB1> INFO: ######################################################################
[12:54:21.164] <TB1> INFO: ----------------------------------------------------------------------
[12:54:21.164] <TB1> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:54:21.164] <TB1> INFO: ----------------------------------------------------------------------
[12:54:22.132] <TB1> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:54:25.078] <TB1> INFO: run duration 2 seconds, buffer almost full (81%), pausing triggers.
[12:54:58.664] <TB1> INFO: Resuming triggers.
[12:55:01.620] <TB1> INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[12:55:35.473] <TB1> INFO: Resuming triggers.
[12:55:38.426] <TB1> INFO: run duration 8 seconds, buffer almost full (81%), pausing triggers.
[12:56:11.402] <TB1> INFO: Resuming triggers.
[12:56:14.358] <TB1> INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:56:48.891] <TB1> INFO: Resuming triggers.
[12:56:51.846] <TB1> INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[12:57:26.136] <TB1> INFO: Resuming triggers.
[12:57:29.089] <TB1> INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[12:58:03.567] <TB1> INFO: Resuming triggers.
[12:58:06.515] <TB1> INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:58:40.629] <TB1> INFO: Resuming triggers.
[12:58:43.580] <TB1> INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:59:17.192] <TB1> INFO: Resuming triggers.
[12:59:20.141] <TB1> INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:59:53.768] <TB1> INFO: Resuming triggers.
[12:59:56.719] <TB1> INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[13:00:30.009] <TB1> INFO: Resuming triggers.
[13:00:32.962] <TB1> INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:01:07.078] <TB1> INFO: Resuming triggers.
[13:01:10.028] <TB1> INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:01:43.705] <TB1> INFO: Resuming triggers.
[13:01:46.654] <TB1> INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[13:02:20.159] <TB1> INFO: Resuming triggers.
[13:02:23.107] <TB1> INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[13:02:57.205] <TB1> INFO: Resuming triggers.
[13:03:00.154] <TB1> INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[13:03:32.656] <TB1> INFO: Resuming triggers.
[13:03:35.602] <TB1> INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:04:07.519] <TB1> INFO: Resuming triggers.
[13:04:10.466] <TB1> INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[13:04:41.234] <TB1> INFO: Resuming triggers.
[13:04:44.179] <TB1> INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[13:05:15.874] <TB1> INFO: Resuming triggers.
[13:05:18.821] <TB1> INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:05:51.513] <TB1> INFO: Resuming triggers.
[13:05:54.459] <TB1> INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:06:26.960] <TB1> INFO: Resuming triggers.
[13:06:29.908] <TB1> INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:07:01.068] <TB1> INFO: Resuming triggers.
[13:07:04.016] <TB1> INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[13:07:35.763] <TB1> INFO: Resuming triggers.
[13:07:38.709] <TB1> INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:07:46.515] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L488> Channel 1 Number of ROCs (5) != Token Chain Length (4)
[13:07:46.515] <TB1> ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:46.515] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a16a 8000 4078 249 2462 4078 290 286c 28a 2281 4078 113 226f 543 266c 804 244e 804 2641 407a 22 206e 1d 2069 18 2482 15 2aa8 1b 2681 45b 2484 848 2068 e000 c000
[13:07:46.515] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a164 80b1 4078 154 2a2e 4078 304 242e 348 2040 718 2261 4078 6c2 2245 4078 108 242a 145 226f 212 2a8f 30d 2a4e 608 284f 600 284d 810 2a4c e000 c000
[13:07:46.515] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a165 80c0 4078 45 2a4e 85 2260 4078 c5 2064 353 2861 422 266e 495 2868 613 2a82 4078 11a 208e 803 2062 4078 94 244a 34b 264f 653 2484 743 2048 743 2267 e000 c000
[13:07:46.515] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a166 8000 4078 4078 4d3 286f 4078 51 288c 5a 2280 499 2048 500 2668 81c 2a63 4078 34b 2482 60b 204f 642 2888 e000 c000
[13:07:46.515] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a167 8040 4078 681 2268 85a 2662 860 2660 4078 9d 286f 84 204f 21c 246f 644 2066 849 2483 840 266f 84d 2a68 4078 60 2881 113 2a6c 4078 8d 2442 4079 24ef 151 208c 142 286c 140 266a 411 266c 460 2281 64d 2849 750 206e e000 c000
[13:07:46.515] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a168 80b1 4078 100 2668 40c 2042 6cc 2a62 4078 11b 2264 299 24a5 45c 2248 4078 151 2662 404 2045 4078 10c 2648 118 2261 845 2a4f e000 c000
[13:07:46.515] <TB1> ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a169 80c0 4078 102 264f 405 266a 513 248c 65c 222e 4078 8b 2482 351 2a4a 655 2489 651 246e 810 284f 80c 222f 4078 412 204a 415 222e 45b 2862 6db 226d 4078 5 244a 449 264f 544 2869 844 2668 e000 c000
[13:08:10.927] <TB1> INFO: Resuming triggers.
[13:08:13.870] <TB1> INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:08:46.159] <TB1> INFO: Resuming triggers.
[13:08:49.103] <TB1> INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[13:09:20.378] <TB1> INFO: Resuming triggers.
[13:09:23.322] <TB1> INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[13:09:54.797] <TB1> INFO: Resuming triggers.
[13:09:57.743] <TB1> INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:10:29.146] <TB1> INFO: Resuming triggers.
[13:10:32.088] <TB1> INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:10:56.743] <TB1> INFO: Resuming triggers.
[13:10:59.686] <TB1> INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[13:11:21.888] <TB1> INFO: Resuming triggers.
[13:11:24.829] <TB1> INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[13:11:47.129] <TB1> INFO: Resuming triggers.
[13:11:50.072] <TB1> INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:12:12.358] <TB1> INFO: Resuming triggers.
[13:12:15.299] <TB1> INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[13:12:37.604] <TB1> INFO: Resuming triggers.
[13:12:40.546] <TB1> INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[13:13:02.682] <TB1> INFO: Resuming triggers.
[13:13:05.498] <TB1> INFO: data taking finished, elapsed time: 100 seconds.
[13:13:27.032] <TB1> INFO: PixTest:: pg_setup set to default.
[13:13:27.033] <TB1> INFO: PixTestXray::doPhRun() done
[13:13:27.033] <TB1> INFO: PixTestXray::doTest() done
[13:13:27.228] <TB1> INFO: enter test to run
[13:13:27.228] <TB1> INFO: test: no parameter change
[13:13:27.327] <TB1> QUIET: Connection to board 147 closed.
[13:13:27.406] <TB1> INFO: pXar: this is the end, my friend