[07:57:31.497] <TB2> INFO: *** Welcome to pxar ***
[07:57:31.497] <TB2> INFO: *** Today: 2016/08/23
[07:57:31.571] <TB2> INFO: *** Version: f5d3-dirty
[07:57:31.571] <TB2> INFO: readRocDacs: /usr/local/data/M2296_XrayQualification_2016-08-23_09h37m_1471937855//005_HRData_150//dacParameters35_C0.dat .. /usr/local/data/M2296_XrayQualification_2016-08-23_09h37m_1471937855//005_HRData_150//dacParameters35_C15.dat
[07:57:31.572] <TB2> INFO: readTbmDacs: /usr/local/data/M2296_XrayQualification_2016-08-23_09h37m_1471937855//005_HRData_150//tbmParameters_C0a.dat .. /usr/local/data/M2296_XrayQualification_2016-08-23_09h37m_1471937855//005_HRData_150//tbmParameters_C0b.dat
[07:57:31.573] <TB2> INFO: readMaskFile: /usr/local/data/M2296_XrayQualification_2016-08-23_09h37m_1471937855//005_HRData_150//defaultMaskFile.dat
[07:57:31.573] <TB2> INFO: readTrimFile: /usr/local/data/M2296_XrayQualification_2016-08-23_09h37m_1471937855//005_HRData_150//trimParameters35_C0.dat .. /usr/local/data/M2296_XrayQualification_2016-08-23_09h37m_1471937855//005_HRData_150//trimParameters35_C15.dat
[07:57:31.664] <TB2> INFO: clk: 4
[07:57:31.664] <TB2> INFO: ctr: 4
[07:57:31.664] <TB2> INFO: sda: 19
[07:57:31.664] <TB2> INFO: tin: 9
[07:57:31.664] <TB2> INFO: level: 15
[07:57:31.664] <TB2> INFO: triggerdelay: 0
[07:57:31.664] <TB2> QUIET: Instanciating API for pxar v2.7.5+30~g833b08f
[07:57:31.664] <TB2> INFO: Log level: INFO
[07:57:31.680] <TB2> INFO: Found DTB DTB_WXENWR
[07:57:31.693] <TB2> QUIET: Connection to board DTB_WXENWR opened.
[07:57:31.695] <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:
------------------------------------------------------
[07:57:31.697] <TB2> INFO: RPC call hashes of host and DTB match: 484264910
[07:57:33.253] <TB2> INFO: DUT info:
[07:57:33.253] <TB2> INFO: The DUT currently contains the following objects:
[07:57:33.253] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[07:57:33.253] <TB2> INFO: TBM Core alpha (0): 7 registers set
[07:57:33.253] <TB2> INFO: TBM Core beta (1): 7 registers set
[07:57:33.253] <TB2> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[07:57:33.253] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.253] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.253] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.253] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.253] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.253] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.253] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.253] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.254] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.254] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.254] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.254] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.254] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.254] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.254] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.254] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[07:57:33.654] <TB2> INFO: enter 'restricted' command line mode
[07:57:33.654] <TB2> INFO: enter test to run
[07:57:33.654] <TB2> INFO: test: delay setting parameters: ->5<-
[07:57:33.654] <TB2> INFO: delay test by 5 seconds...
[07:57:38.655] <TB2> INFO: enter test to run
[07:57:38.655] <TB2> INFO: test: Xray no parameter change
[07:57:38.655] <TB2> INFO: running: xray
[07:57:38.655] <TB2> INFO: readGainPedestalParameters /usr/local/data/M2296_XrayQualification_2016-08-23_09h37m_1471937855//005_HRData_150//phCalibrationFitErr35_C0.dat .. /usr/local/data/M2296_XrayQualification_2016-08-23_09h37m_1471937855//005_HRData_150//phCalibrationFitErr35_C15.dat
[07:57:38.801] <TB2> INFO: ######################################################################
[07:57:38.801] <TB2> INFO: PixTestXray::doTest()
[07:57:38.801] <TB2> INFO: ######################################################################
[07:57:38.801] <TB2> INFO: ----------------------------------------------------------------------
[07:57:38.801] <TB2> INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[07:57:38.801] <TB2> INFO: ----------------------------------------------------------------------
[07:57:39.523] <TB2> INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[07:57:42.776] <TB2> INFO: run duration 3 seconds, buffer almost full (81%), pausing triggers.
[07:58:11.437] <TB2> INFO: Resuming triggers.
[07:58:14.698] <TB2> INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[07:58:44.155] <TB2> INFO: Resuming triggers.
[07:58:47.421] <TB2> INFO: run duration 9 seconds, buffer almost full (81%), pausing triggers.
[07:59:16.563] <TB2> INFO: Resuming triggers.
[07:59:19.826] <TB2> INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[07:59:49.118] <TB2> INFO: Resuming triggers.
[07:59:52.377] <TB2> INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[08:00:21.539] <TB2> INFO: Resuming triggers.
[08:00:24.803] <TB2> INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[08:00:54.035] <TB2> INFO: Resuming triggers.
[08:00:57.297] <TB2> INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[08:01:26.500] <TB2> INFO: Resuming triggers.
[08:01:29.762] <TB2> INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[08:01:59.185] <TB2> INFO: Resuming triggers.
[08:02:02.446] <TB2> INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[08:02:32.417] <TB2> INFO: Resuming triggers.
[08:02:35.680] <TB2> INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[08:03:05.705] <TB2> INFO: Resuming triggers.
[08:03:08.967] <TB2> INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[08:03:38.594] <TB2> INFO: Resuming triggers.
[08:03:41.857] <TB2> INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[08:04:11.600] <TB2> INFO: Resuming triggers.
[08:04:14.862] <TB2> INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[08:04:43.782] <TB2> INFO: Resuming triggers.
[08:04:47.043] <TB2> INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[08:05:17.287] <TB2> INFO: Resuming triggers.
[08:05:20.547] <TB2> INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[08:05:49.595] <TB2> INFO: Resuming triggers.
[08:05:52.858] <TB2> INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[08:06:21.940] <TB2> INFO: Resuming triggers.
[08:06:25.200] <TB2> INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[08:06:55.103] <TB2> INFO: Resuming triggers.
[08:06:58.364] <TB2> INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[08:07:27.898] <TB2> INFO: Resuming triggers.
[08:07:31.159] <TB2> INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[08:08:01.054] <TB2> INFO: Resuming triggers.
[08:08:04.315] <TB2> INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[08:08:34.947] <TB2> INFO: Resuming triggers.
[08:08:38.206] <TB2> INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[08:09:08.450] <TB2> INFO: Resuming triggers.
[08:09:11.712] <TB2> INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[08:09:41.913] <TB2> INFO: Resuming triggers.
[08:09:45.171] <TB2> INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[08:10:15.214] <TB2> INFO: Resuming triggers.
[08:10:18.471] <TB2> INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[08:10:48.594] <TB2> INFO: Resuming triggers.
[08:10:51.850] <TB2> INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[08:11:21.814] <TB2> INFO: Resuming triggers.
[08:11:25.070] <TB2> INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[08:11:54.353] <TB2> INFO: Resuming triggers.
[08:11:57.612] <TB2> INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[08:12:26.468] <TB2> INFO: Resuming triggers.
[08:12:29.724] <TB2> INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[08:12:58.644] <TB2> INFO: Resuming triggers.
[08:13:01.900] <TB2> INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[08:13:32.103] <TB2> INFO: Resuming triggers.
[08:13:35.359] <TB2> INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[08:13:54.595] <TB2> WARNING: Detected DESER400 trailer error bits: "IDLE DATA"
[08:13:54.596] <TB2> ERROR: <datapipe.cc/CheckEventID:L469> Channel 3 Event ID mismatch: local ID (147) != TBM ID (148)
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a397 8040 4180 501 224f 554 2265 4180 4180 4180 5d 2a2d 748 2023 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a391 80c0 4181 20 264f 4181 261 206e 4181 cb 2a83 34b 206f 4181 cd 2042 253 2047 85a 266d fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a392 8000 4180 244 2824 244 2441 695 2064 4180 690 200d 4181 4cc 2065 4cb 2882 4181 fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a393 8040 4180 21a 2880 2e2 286f 44c 2a47 4181 22 2067 5 282a 515 2487 4180 289 2844 47f 2cf7 bfc 210d 416 296a b27 2bff 0 207f fff 2fff f2ff d2ff
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a394 80b0 4180 140 2448 453 2089 65b 2a69 4180 2c4 242f 684 2625 4180 441 2245 642 2665 4181 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a395 80c0 4180 653 2064 4180 4180 492 206d 48d 2289 4180 94 2268 6dc 2047 fff 2fff e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a396 8000 4180 209 224a 462 2a65 841 2065 84c 2241 4180 a0 2248 4180 50d 2247 4180 4c 202d 542 2465 81c 240f e000 c000
[08:13:54.596] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[08:13:54.596] <TB2> WARNING: Channel 3 ROC 0: Readback start marker after 15 readouts!
[08:13:54.596] <TB2> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[08:13:54.596] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a3a2 8000 4180 315 2268 65a 2245 68a 2848 4180 855 2066 4181 49c 2a4f 4181 e1 2244 544 2445 71a 262c 71a 2a45 e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a39c 80b0 4180 2d1 2065 549 204c 4180 4180 4180 d0 2841 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a39d 80c0 4180 751 2a46 801 2467 4180 dd 224d 69b 204f 4180 74b 2247 4180 51 2227 209 2421 2d1 2249 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a39e 8000 4180 88 2848 d5 2861 6d2 2860 4180 4180 59 2446 244 2a89 4d0 266c 4182 5 204f 35d 2063 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a39f 8040 4182 53 2685 54b 2667 862 248b 4182 8b 2845 718 2a41 4182 212 2644 414 262f 4181 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a3a0 80b0 4181 54a 2248 4181 c 262d 41c1 41c1 11a 2446 400 2629 fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff e000 c000
[08:13:54.596] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a3a1 80c0 4181 48 246d 559 2286 610 2245 69b 266a 4181 699 2227 4181 743 2440 743 2042 4181 13 224c 55 2269 861 2667 fff 2fff fff 2fff e000 c000
[08:14:05.579] <TB2> INFO: Resuming triggers.
[08:14:07.864] <TB2> INFO: data taking finished, elapsed time: 100 seconds.
[08:14:27.778] <TB2> INFO: PixTest:: pg_setup set to default.
[08:14:27.779] <TB2> INFO: PixTestXray::doPhRun() done
[08:14:27.779] <TB2> INFO: PixTestXray::doTest() done
[08:14:28.015] <TB2> INFO: enter test to run
[08:14:28.015] <TB2> INFO: test: no parameter change
[08:14:28.289] <TB2> QUIET: Connection to board 162 closed.
[08:14:28.369] <TB2> INFO: pXar: this is the end, my friend