[09:14:59.123] <TB1> INFO: *** Welcome to pxar ***
[09:14:59.123] <TB1> INFO: *** Today: 2016/09/26
[09:14:59.195] <TB1> INFO: *** Version: f5d3-dirty
[09:14:59.195] <TB1> INFO: readRocDacs: /usr/local/data/M2326_XrayQualification_2016-09-26_10h58m_1474880302//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2326_XrayQualification_2016-09-26_10h58m_1474880302//005_HRData_150//dacParameters35_C15.dat
[09:14:59.196] <TB1> INFO: readTbmDacs: /usr/local/data/M2326_XrayQualification_2016-09-26_10h58m_1474880302//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2326_XrayQualification_2016-09-26_10h58m_1474880302//005_HRData_150//tbmParameters_C0b.dat
[09:14:59.196] <TB1> INFO: readMaskFile: /usr/local/data/M2326_XrayQualification_2016-09-26_10h58m_1474880302//005_HRData_150//defaultMaskFile.dat
[09:14:59.196] <TB1> INFO: readTrimFile: /usr/local/data/M2326_XrayQualification_2016-09-26_10h58m_1474880302//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2326_XrayQualification_2016-09-26_10h58m_1474880302//005_HRData_150//trimParameters35_C15.dat
[09:14:59.310] <TB1> INFO: clk: 4
[09:14:59.310] <TB1> INFO: ctr: 4
[09:14:59.310] <TB1> INFO: sda: 19
[09:14:59.310] <TB1> INFO: tin: 9
[09:14:59.310] <TB1> INFO: level: 15
[09:14:59.310] <TB1> INFO: triggerdelay: 0
[09:14:59.310] <TB1> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[09:14:59.310] <TB1> INFO: Log level: INFO
[09:14:59.323] <TB1> INFO: Found DTB DTB_WWXTQT
[09:14:59.333] <TB1> QUIET: Connection to board DTB_WWXTQT opened.
[09:14:59.335] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 147
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWXTQT
MAC address: 40D855118093
Hostname: pixelDTB147
Comment:
------------------------------------------------------
[09:14:59.336] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[09:15:00.880] <TB1> INFO: DUT info:
[09:15:00.880] <TB1> INFO: The DUT currently contains the following objects:
[09:15:00.880] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:15:00.880] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:15:00.880] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:15:00.880] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:15:00.880] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:00.880] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:15:01.281] <TB1> INFO: enter 'restricted' command line mode
[09:15:01.281] <TB1> INFO: enter test to run
[09:15:01.281] <TB1> INFO: test: delay setting parameters: ->5<-
[09:15:01.281] <TB1> INFO: delay test by 5 seconds...
[09:15:06.281] <TB1> INFO: enter test to run
[09:15:06.281] <TB1> INFO: test: Xray no parameter change
[09:15:06.281] <TB1> INFO: running: xray
[09:15:06.281] <TB1> INFO: readGainPedestalParameters /usr/local/data/M2326_XrayQualification_2016-09-26_10h58m_1474880302//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2326_XrayQualification_2016-09-26_10h58m_1474880302//005_HRData_150//phCalibrationFitErr35_C15.dat
[09:15:06.414] <TB1> INFO: ######################################################################
[09:15:06.414] <TB1> INFO: PixTestXray::doTest()
[09:15:06.414] <TB1> INFO: ######################################################################
[09:15:06.414] <TB1> INFO: ----------------------------------------------------------------------
[09:15:06.414] <TB1> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:15:06.414] <TB1> INFO: ----------------------------------------------------------------------
[09:15:07.137] <TB1> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:15:11.035] <TB1> INFO: run duration 3 seconds, buffer almost full (81%), pausing triggers.
[09:15:36.481] <TB1> INFO: Resuming triggers.
[09:15:40.394] <TB1> INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[09:16:06.926] <TB1> INFO: Resuming triggers.
[09:16:10.836] <TB1> INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:16:20.897] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 2 Number of ROCs (5) != Token Chain Length (4)
[09:16:20.897] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[09:16:20.897] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a252 8000 41c0 14 204f 112 246b 41c0 214 282d 449 2a65 41c1 8d 204c 82 264a dd 226c 41c0 e2 2a45 24c 206f 24a 264d 549 248e 80d 244a 805 244f e000 c000
[09:16:20.897] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a24c 80b0 41c0 6a0 2464 41c0 2d4 2424 41c0 285 2649 4d9 246c 41c0 8c 2069 8b 288d 340 2847 355 2289 e000 c000
[09:16:20.897] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a24d 80c0 41c0 c3 2283 41c0 30d 286d 41c0 58 2848 50 206d a0 2481 6e0 2068 41c0 49a 244b 660 2084 68b 222f 820 202d e000 c000
[09:16:20.897] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a24e 8000 41c0 313 2884 300 2641 649 2a46 708 2026 852 2065 845 2a63 41c0 159 2869 252 2665 298 264f 298 2a45 41c0 114 284a 200 2a63 41c0 561 2285 e000 c000
[09:16:20.897] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a24f 8040 41c2 c2 286c c1 2662 108 2666 640 2841 41c2 41c3 da0 234c 9e0 23a4 c80 2970 41c1 91 2065 d1 204a 202 2486 252 2a80 41c0 354 2429 850 2045 e000 c000
[09:16:20.897] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a250 80b0 41c1 4c9 2265 615 284d 811 286d 41c1 103 2248 244 284f 29a 2a65 6c9 2a4d 715 2665 41c1 50 2444 210 226f 50c 2641 558 204e 6c1 2245 6c1 2649 41c0 302 264d e000 c000
[09:16:20.897] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a251 80c0 41c0 242 2440 69c 2020 69c 2263 41c0 149 2a2c 14d 2642 410 264f 442 2841 808 2843 41c0 b 2868 85c 284e 43c0 4da 2449 e000 c000
[09:16:36.845] <TB1> INFO: Resuming triggers.
[09:16:40.755] <TB1> INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[09:17:07.449] <TB1> INFO: Resuming triggers.
[09:17:11.361] <TB1> INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[09:17:38.450] <TB1> INFO: Resuming triggers.
[09:17:42.360] <TB1> INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[09:18:10.288] <TB1> INFO: Resuming triggers.
[09:18:14.198] <TB1> INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[09:18:41.614] <TB1> INFO: Resuming triggers.
[09:18:45.520] <TB1> INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[09:19:12.821] <TB1> INFO: Resuming triggers.
[09:19:16.730] <TB1> INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[09:19:43.976] <TB1> INFO: Resuming triggers.
[09:19:47.887] <TB1> INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[09:20:14.587] <TB1> INFO: Resuming triggers.
[09:20:18.493] <TB1> INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[09:20:44.309] <TB1> INFO: Resuming triggers.
[09:20:48.215] <TB1> INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[09:21:14.819] <TB1> INFO: Resuming triggers.
[09:21:18.726] <TB1> INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[09:21:47.177] <TB1> INFO: Resuming triggers.
[09:21:51.084] <TB1> INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[09:22:18.196] <TB1> INFO: Resuming triggers.
[09:22:22.102] <TB1> INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[09:22:48.731] <TB1> INFO: Resuming triggers.
[09:22:52.634] <TB1> INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[09:23:08.208] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 2 Number of ROCs (5) != Token Chain Length (4)
[09:23:08.209] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[09:23:08.209] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2c5 80c0 41c0 db 208f db 2a82 24b 2865 412 26a2 711 2060 41c0 6c9 2840 41c0 749 242c 41c0 408 202f e000 c000
[09:23:08.209] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2bf 8040 41c2 518 264e 711 2443 41c2 0 2a29 48 2445 608 2045 41c2 41c0 19 244e 41c 286a 41a 226f e000 c000
[09:23:08.209] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2c0 80b0 41c1 21d 2a88 2d3 206e 455 2a67 41c1 505 244f 51a 2245 548 2a40 41c1 d2 284c 24b 2860 413 2a89 41c0 c0 242d 490 2240 4cd 2a67 65c 284d e000 c000
[09:23:08.209] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2c1 80c0 41c0 c1 2069 4d9 266c 41c0 481 2665 41c0 5c 2a40 208 2266 60d 266a 69a 2a4f 41c0 405 206f 450 206f 45c 264f 54c 244d 760 2a8b e000 c000
[09:23:08.209] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2c2 8000 41c0 49d 2062 509 206f 41c1 e45 24c8 445 24a6 4e7 2486 41c0 85 262a 144 2249 210 2440 75c 264f 41c1 515 2a69 75d 202c 41c1 e000 c000
[09:23:08.209] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2c3 8040 41c0 4c 2269 512 2449 519 2a80 521 2664 41c1 d 284d 24b 204f 245 226f 493 2849 705 2865 41c0 4d1 2a62 700 2441 41c0 260 2649 29b 2682 484 204c 4cc 2465 680 264d 850 2a43 e000 c000
[09:23:08.209] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2c4 80b0 41c0 cb 2886 442 2a4a 4cc 226d 51d 2461 65d 266c 720 204e 74a 242f 860 2661 41c0 59 2a64 5b 2a65 8c 2245 441 2868 44c 222f 41c0 519 2882 60b 2663 6dd 2a69 80c 2044 41c1 e000 c000
[09:23:19.611] <TB1> INFO: Resuming triggers.
[09:23:23.518] <TB1> INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[09:23:49.971] <TB1> INFO: Resuming triggers.
[09:23:53.875] <TB1> INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[09:24:19.924] <TB1> INFO: Resuming triggers.
[09:24:23.828] <TB1> INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[09:24:50.027] <TB1> INFO: Resuming triggers.
[09:24:53.931] <TB1> INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[09:25:19.626] <TB1> INFO: Resuming triggers.
[09:25:23.530] <TB1> INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[09:25:50.207] <TB1> INFO: Resuming triggers.
[09:25:54.112] <TB1> INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[09:26:18.314] <TB1> INFO: Resuming triggers.
[09:26:22.217] <TB1> INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[09:26:45.694] <TB1> INFO: Resuming triggers.
[09:26:49.598] <TB1> INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[09:27:14.003] <TB1> INFO: Resuming triggers.
[09:27:17.906] <TB1> INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[09:27:39.869] <TB1> INFO: Resuming triggers.
[09:27:42.293] <TB1> INFO: data taking finished, elapsed time: 100 seconds.
[09:27:48.326] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 2 Number of ROCs (5) != Token Chain Length (4)
[09:27:48.326] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[09:27:48.326] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2b3 8040 41c0 562 2229 65b 2846 41c1 304 2665 451 284b 451 2a45 41c0 59 2880 342 264f 352 2a85 85d 202f 85d 2a66 41c0 413 284f 801 2649 e000 c000
[09:27:48.326] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2ad 80c0 41c0 105 2844 4e0 204c 41c0 2c2 2085 522 246f 840 244f 840 266f 41c0 2 284c 41c0 144 2681 e000 c000
[09:27:48.326] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2ae 8000 41c0 cd 2269 70c 284e 41c0 443 2a6a 640 2828 651 226b 41c0 41c0 14a 2a86 449 2aa4 490 2427 480 2a44 744 284d e000 c000
[09:27:48.326] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2af 8040 41c2 4b 2a85 519 226c 70c 2242 74d 2429 80a 2848 81a 2a61 41c2 25d 2849 245 244f 305 2464 544 2845 859 2264 41c2 743 2028 41c0 6d4 224f 855 206f 84b 244f e000 c000
[09:27:48.326] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2b0 80b0 41c1 4c0 2a44 811 206d 80c 2a2f 41c1 15c 2a6f 712 2442 721 264f 41c1 41c1 c 2443 c0 2446 4e2 2a4f 691 2a69 851 266f 41c0 353 208d 45d 248b e000 c000
[09:27:48.326] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2b1 80c0 41c0 418 228f 41c0 643 2049 68b 2a86 741 2a2c 41c0 d9 2261 6c1 2663 41c0 a2 28a1 e000 c000
[09:27:48.326] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2b2 8000 41c0 41c0 21 264c 90 284d 114 2a2d 6ca 2a45 41c1 54 2262 41c0 118 2825 112 206f 142 2a69 310 2a4f 559 288d e000 c000
[09:27:56.143] <TB1> INFO: PixTest:: pg_setup set to default.
[09:27:56.144] <TB1> INFO: PixTestXray::doPhRun() done
[09:27:56.144] <TB1> INFO: PixTestXray::doTest() done
[09:27:56.321] <TB1> INFO: enter test to run
[09:27:56.321] <TB1> INFO: test: no parameter change
[09:27:56.632] <TB1> QUIET: Connection to board 147 closed.
[09:27:56.712] <TB1> INFO: pXar: this is the end, my friend