[15:48:02.018] <TB2> INFO: *** Welcome to pxar ***
[15:48:02.018] <TB2> INFO: *** Today: 2016/09/27
[15:48:02.085] <TB2> INFO: *** Version: f5d3-dirty
[15:48:02.085] <TB2> INFO: readRocDacs: /usr/local/data/M2345_XrayQualification_2016-09-27_17h30m_1474990249//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2345_XrayQualification_2016-09-27_17h30m_1474990249//005_HRData_150//dacParameters35_C15.dat
[15:48:02.085] <TB2> INFO: readTbmDacs: /usr/local/data/M2345_XrayQualification_2016-09-27_17h30m_1474990249//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2345_XrayQualification_2016-09-27_17h30m_1474990249//005_HRData_150//tbmParameters_C0b.dat
[15:48:02.086] <TB2> INFO: readMaskFile: /usr/local/data/M2345_XrayQualification_2016-09-27_17h30m_1474990249//005_HRData_150//defaultMaskFile.dat
[15:48:02.086] <TB2> INFO: readTrimFile: /usr/local/data/M2345_XrayQualification_2016-09-27_17h30m_1474990249//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2345_XrayQualification_2016-09-27_17h30m_1474990249//005_HRData_150//trimParameters35_C15.dat
[15:48:02.168] <TB2> INFO: clk: 4
[15:48:02.168] <TB2> INFO: ctr: 4
[15:48:02.168] <TB2> INFO: sda: 19
[15:48:02.168] <TB2> INFO: tin: 9
[15:48:02.168] <TB2> INFO: level: 15
[15:48:02.168] <TB2> INFO: triggerdelay: 0
[15:48:02.168] <TB2> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[15:48:02.168] <TB2> INFO: Log level: INFO
[15:48:02.181] <TB2> INFO: Found DTB DTB_WXENWR
[15:48:02.192] <TB2> QUIET: Connection to board DTB_WXENWR opened.
[15:48:02.194] <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:
------------------------------------------------------
[15:48:02.196] <TB2> INFO: RPC call hashes of host and DTB match: 486171790
[15:48:03.733] <TB2> INFO: DUT info:
[15:48:03.733] <TB2> INFO: The DUT currently contains the following objects:
[15:48:03.733] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:48:03.733] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:48:03.733] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:48:03.733] <TB2> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:48:03.733] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:03.733] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:48:04.134] <TB2> INFO: enter 'restricted' command line mode
[15:48:04.134] <TB2> INFO: enter test to run
[15:48:04.134] <TB2> INFO: test: delay setting parameters: ->5<-
[15:48:04.134] <TB2> INFO: delay test by 5 seconds...
[15:48:09.134] <TB2> INFO: enter test to run
[15:48:09.134] <TB2> INFO: test: Xray no parameter change
[15:48:09.134] <TB2> INFO: running: xray
[15:48:09.134] <TB2> INFO: readGainPedestalParameters /usr/local/data/M2345_XrayQualification_2016-09-27_17h30m_1474990249//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2345_XrayQualification_2016-09-27_17h30m_1474990249//005_HRData_150//phCalibrationFitErr35_C15.dat
[15:48:09.290] <TB2> INFO: ######################################################################
[15:48:09.290] <TB2> INFO: PixTestXray::doTest()
[15:48:09.290] <TB2> INFO: ######################################################################
[15:48:09.290] <TB2> INFO: ----------------------------------------------------------------------
[15:48:09.290] <TB2> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:48:09.290] <TB2> INFO: ----------------------------------------------------------------------
[15:48:10.013] <TB2> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:48:13.837] <TB2> INFO: run duration 3 seconds, buffer almost full (81%), pausing triggers.
[15:48:39.651] <TB2> INFO: Resuming triggers.
[15:48:43.482] <TB2> INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[15:49:09.689] <TB2> INFO: Resuming triggers.
[15:49:13.522] <TB2> INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:49:40.342] <TB2> INFO: Resuming triggers.
[15:49:44.176] <TB2> INFO: run duration 15 seconds, buffer almost full (81%), pausing triggers.
[15:50:10.085] <TB2> INFO: Resuming triggers.
[15:50:13.917] <TB2> INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:50:39.858] <TB2> INFO: Resuming triggers.
[15:50:43.691] <TB2> INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:51:09.625] <TB2> INFO: Resuming triggers.
[15:51:13.456] <TB2> INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:51:39.361] <TB2> INFO: Resuming triggers.
[15:51:43.191] <TB2> INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[15:52:08.866] <TB2> INFO: Resuming triggers.
[15:52:12.696] <TB2> INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:52:39.594] <TB2> INFO: Resuming triggers.
[15:52:43.422] <TB2> INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[15:52:43.852] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 2 Number of ROCs (5) != Token Chain Length (4)
[15:52:43.852] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[15:52:43.852] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2c3 8041 4700 8 2049 4700 318 2a2f 552 2845 550 2a4d 4700 412 2a29 552 2680 4700 680 2427 e000 c000
[15:52:43.852] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2bd 80c1 4700 80 2a45 108 2469 248 2082 288 2065 65c 2a27 4700 9b 2268 30b 244e 482 2440 4702 615 2a61 6d8 2a45 712 2267 822 2869 81a 2041 819 2646 4700 201 2242 240 2461 748 2a27 e000 c000
[15:52:43.852] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2be 8001 4700 34d 2644 49b 2a4d 4702 1c 284b 115 2465 115 2665 562 206c 641 2248 4701 250 286d 649 2847 851 224e 4702 24d 2062 40d 206b 705 2847 719 2665 e000 c000
[15:52:43.852] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2bf 8041 4702 603 288c 608 264f 608 2a6c 718 2644 800 244a 4701 492 2a47 844 2a2d 4700 52 284d 111 226d 21a 286d 4701 211 208a 205 208d 711 2449 e000 c000
[15:52:43.853] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2c0 80b1 4701 14d 224d 4701 ec6 212a 6c8 2482 4700 200 2440 308 264b 860 2a4f 4701 6d1 2449 4700 60 2a6c 14c 2069 e000 c000
[15:52:43.853] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2c1 80c1 4700 2cc 2868 6d0 2a43 4700 89 2467 28b 2a66 495 2865 700 242c 4700 21b 206a 288 2a61 289 2a4d 2c9 2861 402 2041 4d8 2649 60a 2468 69d 2668 4701 253 286d 29d 244d 2d0 2a4f 640 2640 848 2a47 e000 c000
[15:52:43.853] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2c2 8001 4700 31c 204d 49d 2466 488 2841 612 2269 618 2a68 713 2045 4701 14 2a61 712 2a45 4700 71b 226e 800 2664 4701 60c 2049 850 262d e000 c000
[15:53:10.944] <TB2> INFO: Resuming triggers.
[15:53:14.777] <TB2> INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[15:53:41.630] <TB2> INFO: Resuming triggers.
[15:53:45.458] <TB2> INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:53:56.665] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 0 Number of ROCs (5) != Token Chain Length (4)
[15:53:56.665] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[15:53:56.665] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a008 80b1 4300 4c8 2224 61d 224f 4300 4300 d5 242c 745 2647 4700 20b 244d 355 286d 841 2483 e000 c000
[15:53:56.665] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a002 8001 4300 409 282f 69a 264f 4700 4701 62 244f 4701 800 242d 844 224f e000 c000
[15:53:56.665] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a003 8041 4300 15d 2644 454 2828 70c 2821 4301 2c4 264c 561 2a80 4700 55c 222f 61d 2049 691 2a64 705 244f 4301 2c8 2645 48d 264d e000 c000
[15:53:56.665] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a004 80b1 4300 15a 2448 15a 264c 4300 362 2469 849 2647 4300 643 2a4c 65b 224a 815 2267 840 2845 84b 224d 4700 811 224d e000 c000
[15:53:56.665] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a005 80c1 4300 619 286b 709 2247 755 242c 762 2242 4301 4300 298 2065 75a 2865 4300 748 2a0f 85d 2247 4300 483 2248 500 2445 e000 c000
[15:53:56.666] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a006 8001 4300 4300 810 262f 4300 4301 e000 c000
[15:53:56.666] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a007 8041 4300 4300 4300 2c0 2627 4301 e000 c000
[15:54:13.436] <TB2> INFO: Resuming triggers.
[15:54:17.264] <TB2> INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[15:54:43.928] <TB2> INFO: Resuming triggers.
[15:54:47.757] <TB2> INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:54:52.843] <TB2> WARNING: Channel 1 ROC 2: Readback start marker after 5 readouts!
[15:54:52.843] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 1 Number of ROCs (5) != Token Chain Length (4)
[15:54:52.843] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[15:54:52.843] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a187 8040 4200 6d0 2461 821 2247 4300 68d 2449 4300 70a 2640 741 2649 4300 59 2a4c 15b 2262 643 204b e000 c000
[15:54:52.843] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a181 80c0 4301 462 2844 45d 266f 4301 84c 2244 4701 4b 204f 2cd 264b 4301 444 202d 45b 2261 e000 c000
[15:54:52.843] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a182 8000 4300 4300 59 2269 298 2849 302 2a80 40c 2640 415 2a49 54b 2066 4301 4301 c9 206f 105 2667 245 2a6f e000 c000
[15:54:52.843] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a183 8040 4300 44a 2080 654 2a2f 4301 244 2645 2db 2861 2d4 262d 4700 90 2a65 68b 2829 6e0 2685 75a 2841 4701 9d 2261 143 284d 14b 2a69 501 2a61 60a 2445 e000 c000
[15:54:52.843] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a184 80b0 4300 1 2664 29a 204f 651 2a8f 654 2241 4300 4702 5ee 2060 4300 4300 558 244e 554 2a49 e000 c000
[15:54:52.843] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a185 80c0 4300 100 2a64 21c 2047 4300 5a 2046 20c 2065 205 2860 258 2845 298 2448 31d 286c 443 2a69 553 2a8a 704 264c 861 2a6f 4300 a 2449 a 202d 101 2867 54b 224d 4300 662 244f e000 c000
[15:54:52.843] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a186 8000 4300 1d 2444 a2 2a4d 4c1 2222 4300 12 2462 4 2069 14c 2862 409 2a45 842 244f 84b 2a44 4700 44c 202f 549 2469 558 2a6e 619 242d 619 2049 60b 226c 6ca 2468 4700 280 244b 412 204d 44d 2a44 601 2425 80c 282d 80c 2469 e000 c000
[15:55:14.675] <TB2> INFO: Resuming triggers.
[15:55:18.501] <TB2> INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:55:45.768] <TB2> INFO: Resuming triggers.
[15:55:49.593] <TB2> INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[15:56:16.259] <TB2> INFO: Resuming triggers.
[15:56:20.085] <TB2> INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[15:56:47.954] <TB2> INFO: Resuming triggers.
[15:56:51.779] <TB2> INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:57:18.129] <TB2> INFO: Resuming triggers.
[15:57:21.953] <TB2> INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:57:49.379] <TB2> INFO: Resuming triggers.
[15:57:53.201] <TB2> INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[15:58:19.469] <TB2> INFO: Resuming triggers.
[15:58:23.292] <TB2> INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:58:49.980] <TB2> INFO: Resuming triggers.
[15:58:53.805] <TB2> INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[15:59:18.916] <TB2> INFO: Resuming triggers.
[15:59:22.741] <TB2> INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[15:59:47.633] <TB2> INFO: Resuming triggers.
[15:59:51.456] <TB2> INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[16:00:15.593] <TB2> INFO: Resuming triggers.
[16:00:19.420] <TB2> INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[16:00:43.601] <TB2> INFO: Resuming triggers.
[16:00:47.424] <TB2> INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[16:01:09.375] <TB2> INFO: Resuming triggers.
[16:01:09.943] <TB2> INFO: data taking finished, elapsed time: 100 seconds.
[16:01:13.569] <TB2> INFO: PixTest:: pg_setup set to default.
[16:01:13.570] <TB2> INFO: PixTestXray::doPhRun() done
[16:01:13.570] <TB2> INFO: PixTestXray::doTest() done
[16:01:13.750] <TB2> INFO: enter test to run
[16:01:13.750] <TB2> INFO: test: no parameter change
[16:01:14.063] <TB2> QUIET: Connection to board 162 closed.
[16:01:14.145] <TB2> INFO: pXar: this is the end, my friend