[09:32:49.812] <TB2> INFO: *** Welcome to pxar ***
[09:32:49.812] <TB2> INFO: *** Today: 2016/08/10
[09:32:49.881] <TB2> INFO: *** Version: f5d3-dirty
[09:32:49.881] <TB2> INFO: readRocDacs: /usr/local/data/M2289_XrayQualification_2016-08-10_11h12m_1470820366//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2289_XrayQualification_2016-08-10_11h12m_1470820366//005_HRData_150//dacParameters35_C15.dat
[09:32:49.882] <TB2> INFO: readTbmDacs: /usr/local/data/M2289_XrayQualification_2016-08-10_11h12m_1470820366//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2289_XrayQualification_2016-08-10_11h12m_1470820366//005_HRData_150//tbmParameters_C0b.dat
[09:32:49.882] <TB2> INFO: readMaskFile: /usr/local/data/M2289_XrayQualification_2016-08-10_11h12m_1470820366//005_HRData_150//defaultMaskFile.dat
[09:32:49.882] <TB2> INFO: readTrimFile: /usr/local/data/M2289_XrayQualification_2016-08-10_11h12m_1470820366//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2289_XrayQualification_2016-08-10_11h12m_1470820366//005_HRData_150//trimParameters35_C15.dat
[09:32:49.986] <TB2> INFO: clk: 4
[09:32:49.986] <TB2> INFO: ctr: 4
[09:32:49.986] <TB2> INFO: sda: 19
[09:32:49.986] <TB2> INFO: tin: 9
[09:32:49.986] <TB2> INFO: level: 15
[09:32:49.986] <TB2> INFO: triggerdelay: 0
[09:32:49.986] <TB2> QUIET: Instanciating API for pxar v2.7.5+30~g833b08f
[09:32:49.986] <TB2> INFO: Log level: INFO
[09:32:50.000] <TB2> INFO: Found DTB DTB_WXENWR
[09:32:50.011] <TB2> QUIET: Connection to board DTB_WXENWR opened.
[09:32:50.013] <TB2> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 162
HW version: DTB1.2
FW version: 4.4
SW version: 4.6
Options:
USB id: DTB_WXENWR
MAC address: 40D8551180A2
Hostname: pixelDTB162
Comment:
------------------------------------------------------
[09:32:50.015] <TB2> INFO: RPC call hashes of host and DTB match: 484264910
[09:32:51.596] <TB2> INFO: DUT info:
[09:32:51.596] <TB2> INFO: The DUT currently contains the following objects:
[09:32:51.596] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[09:32:51.596] <TB2> INFO: TBM Core alpha (0): 7 registers set
[09:32:51.596] <TB2> INFO: TBM Core beta (1): 7 registers set
[09:32:51.596] <TB2> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:32:51.596] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.596] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:51.997] <TB2> INFO: enter 'restricted' command line mode
[09:32:51.997] <TB2> INFO: enter test to run
[09:32:51.997] <TB2> INFO: test: delay setting parameters: ->5<-
[09:32:51.997] <TB2> INFO: delay test by 5 seconds...
[09:32:56.997] <TB2> INFO: enter test to run
[09:32:56.997] <TB2> INFO: test: Xray no parameter change
[09:32:56.997] <TB2> INFO: running: xray
[09:32:56.998] <TB2> INFO: readGainPedestalParameters /usr/local/data/M2289_XrayQualification_2016-08-10_11h12m_1470820366//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2289_XrayQualification_2016-08-10_11h12m_1470820366//005_HRData_150//phCalibrationFitErr35_C15.dat
[09:32:57.163] <TB2> INFO: ######################################################################
[09:32:57.163] <TB2> INFO: PixTestXray::doTest()
[09:32:57.163] <TB2> INFO: ######################################################################
[09:32:57.163] <TB2> INFO: ----------------------------------------------------------------------
[09:32:57.163] <TB2> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:32:57.163] <TB2> INFO: ----------------------------------------------------------------------
[09:32:57.887] <TB2> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:33:01.144] <TB2> INFO: run duration 3 seconds, buffer almost full (81%), pausing triggers.
[09:33:30.531] <TB2> INFO: Resuming triggers.
[09:33:33.795] <TB2> INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:34:03.416] <TB2> INFO: Resuming triggers.
[09:34:06.678] <TB2> INFO: run duration 9 seconds, buffer almost full (81%), pausing triggers.
[09:34:36.260] <TB2> INFO: Resuming triggers.
[09:34:39.525] <TB2> INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[09:35:09.322] <TB2> INFO: Resuming triggers.
[09:35:12.584] <TB2> INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[09:35:43.044] <TB2> INFO: Resuming triggers.
[09:35:46.307] <TB2> INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[09:36:15.232] <TB2> INFO: Resuming triggers.
[09:36:18.495] <TB2> INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[09:36:48.140] <TB2> INFO: Resuming triggers.
[09:36:51.402] <TB2> INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[09:37:21.220] <TB2> INFO: Resuming triggers.
[09:37:24.483] <TB2> INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[09:37:54.955] <TB2> INFO: Resuming triggers.
[09:37:58.217] <TB2> INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[09:38:27.563] <TB2> INFO: Resuming triggers.
[09:38:30.825] <TB2> INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[09:39:00.761] <TB2> INFO: Resuming triggers.
[09:39:04.024] <TB2> INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[09:39:33.428] <TB2> INFO: Resuming triggers.
[09:39:36.694] <TB2> INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[09:40:07.589] <TB2> INFO: Resuming triggers.
[09:40:10.851] <TB2> INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[09:40:40.715] <TB2> INFO: Resuming triggers.
[09:40:43.979] <TB2> INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[09:41:14.757] <TB2> INFO: Resuming triggers.
[09:41:18.019] <TB2> INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[09:41:47.988] <TB2> INFO: Resuming triggers.
[09:41:51.246] <TB2> INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[09:42:09.836] <TB2> WARNING: Detected DESER400 trailer error bits: "IDLE DATA"
[09:42:09.836] <TB2> ERROR: <datapipe.cc/CheckEventID:L469> Channel 2 Event ID mismatch: local ID (227) != TBM ID (228)
[09:42:09.836] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[09:42:09.836] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e7 8040 40c0 360 2860 4cb 2082 4c4 2868 844 2a46 40c0 855 246f 40c0 10c 2262 118 2a6a 14c 2a2c 341 244a 4c8 2040 6cc 2a27 6d2 2644 40c0 2d1 2a64 819 2227 e000 c000
[09:42:09.836] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e1 80c0 40c0 142 2066 28b 24ae 30d 2884 715 26a0 40c0 4dd 2a6b 40c0 50b 2462 85b 2445 40c1 fff 2fff fff 2fff e000 c000
[09:42:09.836] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e2 8000 40c0 a 2a4c 40c0 d 2882 2c9 268d 350 2069 51c 226e 643 204d 859 2888 41c0 61d 2685 40c1 e000 c000
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e3 8040 40c0 9 2865 549 284e 543 2680 543 2a6f 761 2881 80b 288e 40c0 19 226d 48c 2662 4cc 2460 4dc 224b 40c0 13 2465 5 246d 109 2266 349 2864 349 2448 47f 2cf1 a60 2b27 aa5 2a27 b41 2332 bfc 2031 236 2871 340 2962 945 2285 222 2325 117 2329 334 2388 111 2bff 0 207f fff 2fff f2ff d2ff
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e4 80b0 40c0 35c 2a44 40c0 115 204f 2da 2645 40c0 40c0 145 224f 4d5 2865 841 2483 e000 c000
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e5 80c0 40c0 15d 2880 159 208d 518 2062 505 286a 6d5 2669 813 22a2 40c0 5c 206b 600 242f 40c0 5 284a 604 2a69 614 2641 652 2a82 40c0 9a 228a 249 226d 600 2885 e000 c000
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2e6 8000 40c0 8a 2265 140 264f 61d 2a68 751 2086 753 2282 819 2485 40c0 e2 2262 103 266d 551 2a4f 842 2083 40c0 c 226f 40c0 489 2285 e000 c000
[09:42:09.837] <TB2> WARNING: Channel 2 ROC 1: Readback start marker after 15 readouts!
[09:42:09.837] <TB2> WARNING: Channel 2 ROC 2: Readback start marker after 15 readouts!
[09:42:09.837] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[09:42:09.837] <TB2> WARNING: Channel 2 ROC 0: Readback start marker after 15 readouts!
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2f2 8000 40c0 161 286a 299 228c 543 2648 640 266f 849 284b 40c0 412 2068 510 286f 40c0 213 2867 4d9 204f 560 2884 40c1 4 2447 851 2263 e000 c000
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2ec 80b0 40c0 213 2a65 619 2a67 6da 2647 40c0 10c 244c 50c 286d 60d 244f 811 206f 844 2666 40c0 111 2a4f 243 20a2 549 2288 561 2688 758 2842 40c0 54 204f 14a 224e 205 2640 251 2080 24d 22a8 2d0 244f 542 2469 e000 c000
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2ed 80c0 40c0 289 266e 293 22aa 2cb 2085 814 2663 41c0 5b 206a 142 266d 40c2 504 2a28 853 2445 40c0 85c 2463 e000 c000
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2ee 8000 40c0 d 2662 11b 206f 111 2465 308 2465 845 2681 40c1 4b 2a4e 84c 2a4f 40c1 10 264a c2 2281 2c2 206a 40c2 18 264a 450 2883 e000 c000
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2ef 8040 40c2 349 224e 4c5 226b 40c0 2cb 284f 492 2482 709 204a 40c0 358 2661 40c1 1b 2289 10b 2664 249 2a8d e000 c000
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2f0 80b0 40c1 2cb 206a 35b 2466 40c 2260 6d9 246b 854 2a43 40c0 43 284e 213 2a6d 2c0 2a4b 35d 208b 508 244d 40c1 35c 2848 40c0 144 2a40 450 2249 819 262d e000 c000
[09:42:09.837] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a2f1 80c0 40c0 40c0 143 2a6a 40c0 310 2068 303 286f 302 2a88 34d 2460 859 2a6f 40c1 319 2a62 69d 2085 e000 c000
[09:42:21.898] <TB2> INFO: Resuming triggers.
[09:42:25.157] <TB2> INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[09:42:55.104] <TB2> INFO: Resuming triggers.
[09:42:58.364] <TB2> INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[09:43:28.953] <TB2> INFO: Resuming triggers.
[09:43:32.214] <TB2> INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[09:44:02.369] <TB2> INFO: Resuming triggers.
[09:44:05.633] <TB2> INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[09:44:36.125] <TB2> INFO: Resuming triggers.
[09:44:39.385] <TB2> INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[09:45:10.497] <TB2> INFO: Resuming triggers.
[09:45:13.754] <TB2> INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[09:45:43.824] <TB2> INFO: Resuming triggers.
[09:45:47.080] <TB2> INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[09:46:17.761] <TB2> INFO: Resuming triggers.
[09:46:21.018] <TB2> INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[09:46:51.318] <TB2> INFO: Resuming triggers.
[09:46:54.572] <TB2> INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[09:47:23.505] <TB2> INFO: Resuming triggers.
[09:47:26.760] <TB2> INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[09:47:56.302] <TB2> INFO: Resuming triggers.
[09:47:59.559] <TB2> INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[09:48:28.789] <TB2> INFO: Resuming triggers.
[09:48:32.042] <TB2> INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[09:49:01.842] <TB2> INFO: Resuming triggers.
[09:49:05.095] <TB2> INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[09:49:34.285] <TB2> INFO: Resuming triggers.
[09:49:36.576] <TB2> INFO: data taking finished, elapsed time: 100 seconds.
[09:49:58.215] <TB2> INFO: PixTest:: pg_setup set to default.
[09:49:58.216] <TB2> INFO: PixTestXray::doPhRun() done
[09:49:58.216] <TB2> INFO: PixTestXray::doTest() done
[09:49:58.398] <TB2> INFO: enter test to run
[09:49:58.398] <TB2> INFO: test: no parameter change
[09:49:58.653] <TB2> QUIET: Connection to board 162 closed.
[09:49:58.733] <TB2> INFO: pXar: this is the end, my friend