Project

General

Profile

Bug #957 ยป relayd_traces.txt

Traces of relay daemon in verbose mode - Lakshmi Anusha Mahamkali, 10/20/2015 02:05 AM

 
1
PERROR - 20:17:01.442823 [11252/11257]: open stream path /home/labuser/lttng-traces/oamhost//ts_session0_6171-20151007-201712//ust/uid/0/64-bit/index/ch-1_9.idx: File exists (in utils_create_stream_file() at utils.c:648)
2
DEBUG3 - 20:17:01.442887 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
3
DEBUG3 - 20:17:01.442905 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
4
DEBUG1 - 20:17:01.442920 [11252/11257]: Session find by ID 45 id found (in session_find_by_id() at session.c:89)
5
DEBUG3 - 20:17:01.442935 [11252/11257]: Receiving data of size 68 for stream id 1117 seqnum 0 (in relay_process_data() at main.c:2284)
6
DEBUG3 - 20:17:01.442947 [11252/11257]: Finding index for stream id 1117 and seq_num 0 (in relay_index_find() at index.c:88)
7
DEBUG3 - 20:17:01.442959 [11252/11257]: mkdir() /home/labuser/lttng-traces/oamhost//ts_session0_6171-20151007-201712//ust/uid/0/64-bit/index with mode 504 for uid 1000 and gid 100 (in run_as_mkdir() at runas.c:320)
8
DEBUG1 - 20:17:01.442970 [11252/11257]: Using run_as_clone (in run_as() at runas.c:291)
9
DEBUG3 - 20:17:01.443867 [11252/11257]: open() /home/labuser/lttng-traces/oamhost//ts_session0_6171-20151007-201712//ust/uid/0/64-bit/index/ch-1_17.idx with flags 241 mode 432 for uid 1000 and gid 100 (in run_as_open() at runas.c:336)
10
DEBUG1 - 20:17:01.443892 [11252/11257]: Using run_as_clone (in run_as() at runas.c:291)
11
PERROR - 20:17:01.444732 [11252/11257]: open stream path /home/labuser/lttng-traces/oamhost//ts_session0_6171-20151007-201712//ust/uid/0/64-bit/index/ch-1_17.idx: File exists (in utils_create_stream_file() at utils.c:648)
12
DEBUG3 - 20:17:01.444806 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
13
DEBUG3 - 20:17:01.444826 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
14
DEBUG1 - 20:17:01.444841 [11252/11257]: Session find by ID 45 id found (in session_find_by_id() at session.c:89)
15
DEBUG3 - 20:17:01.444856 [11252/11257]: Receiving data of size 68 for stream id 1107 seqnum 0 (in relay_process_data() at main.c:2284)
16
DEBUG3 - 20:17:01.444870 [11252/11257]: Finding index for stream id 1107 and seq_num 0 (in relay_index_find() at index.c:88)
17
DEBUG3 - 20:17:01.444883 [11252/11257]: mkdir() /home/labuser/lttng-traces/oamhost//ts_session0_6171-20151007-201712//ust/uid/0/64-bit/index with mode 504 for uid 1000 and gid 100 (in run_as_mkdir() at runas.c:320)
18
DEBUG1 - 20:17:01.444894 [11252/11257]: Using run_as_clone (in run_as() at runas.c:291)
19
DEBUG3 - 20:17:01.445754 [11252/11257]: open() /home/labuser/lttng-traces/oamhost//ts_session0_6171-20151007-201712//ust/uid/0/64-bit/index/ch-1_7.idx with flags 241 mode 432 for uid 1000 and gid 100 (in run_as_open() at runas.c:336)
20
DEBUG1 - 20:17:01.445798 [11252/11257]: Using run_as_clone (in run_as() at runas.c:291)
21
PERROR - 20:17:01.446632 [11252/11257]: open stream path /home/labuser/lttng-traces/oamhost//ts_session0_6171-20151007-201712//ust/uid/0/64-bit/index/ch-1_7.idx: File exists (in utils_create_stream_file() at utils.c:648)
22
DEBUG3 - 20:17:01.446706 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
23
DEBUG1 - 20:17:01.464210 [11252/11257]: Relay receiving index (in relay_recv_index() at main.c:1920)
24
DEBUG1 - 20:17:01.464227 [11252/11257]: Received live beacon for stream 1100 (in relay_recv_index() at main.c:1953)
25
DEBUG3 - 20:17:01.464245 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
26
DEBUG3 - 20:17:01.530065 [11252/11257]: open() /home/labuser/lttng-traces/oamhost//ts_session0_6171-20151007-201712//ust/uid/0/64-bit/metadata with flags 241 mode 432 for uid 1000 and gid 100 (in run_as_open() at runas.c:336)
27
DEBUG1 - 20:17:01.530082 [11252/11257]: Using run_as_clone (in run_as() at runas.c:291)
28
PERROR - 20:17:01.530936 [11252/11257]: open stream path /home/labuser/lttng-traces/oamhost//ts_session0_6171-20151007-201712//ust/uid/0/64-bit/metadata: File exists (in utils_create_stream_file() at utils.c:648)
29
DEBUG1 - 20:17:01.530959 [11252/11257]: Tracefile /home/labuser/lttng-traces/oamhost//ts_session0_6171-20151007-201712//ust/uid/0/64-bit/metadata created (in relay_add_stream() at main.c:1244)
30
DEBUG1 - 20:17:01.530980 [11252/11257]: Relay new stream added metadata with ID 1124 (in relay_add_stream() at main.c:1281)
31
DEBUG3 - 20:17:01.531000 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
32
DEBUG1 - 20:17:01.531019 [11252/11257]: Close stream received (in relay_close_stream() at main.c:1326)
33
DEBUG1 - 20:17:01.531031 [11252/11257]: Relay stream 0 not found (in stream_find_by_id() at stream.c:54)
34
DEBUG1 - 20:17:01.531071 [11252/11257]: Closing stream id 1100 (in stream_close() at stream.c:86)
35
PERROR - 20:17:01.531087 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
36
DEBUG1 - 20:17:01.531109 [11252/11257]: Relay viewer stream 1100 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
37
DEBUG1 - 20:17:01.531134 [11252/11257]: Closing stream id 1101 (in stream_close() at stream.c:86)
38
PERROR - 20:17:01.531153 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
39
PERROR - 20:17:01.531164 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
40
DEBUG1 - 20:17:01.531174 [11252/11257]: Relay viewer stream 1101 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
41
DEBUG1 - 20:17:01.531194 [11252/11257]: Closing stream id 1102 (in stream_close() at stream.c:86)
42
PERROR - 20:17:01.531205 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
43
PERROR - 20:17:01.531216 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
44
DEBUG1 - 20:17:01.531225 [11252/11257]: Relay viewer stream 1102 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
45
DEBUG1 - 20:17:01.531244 [11252/11257]: Closing stream id 1103 (in stream_close() at stream.c:86)
46
PERROR - 20:17:01.531258 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
47
PERROR - 20:17:01.531269 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
48
DEBUG1 - 20:17:01.531279 [11252/11257]: Relay viewer stream 1103 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
49
DEBUG1 - 20:17:01.531298 [11252/11257]: Closing stream id 1104 (in stream_close() at stream.c:86)
50
PERROR - 20:17:01.531310 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
51
PERROR - 20:17:01.531320 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
52
DEBUG1 - 20:17:01.531330 [11252/11257]: Relay viewer stream 1104 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
53
DEBUG1 - 20:17:01.531349 [11252/11257]: Closing stream id 1105 (in stream_close() at stream.c:86)
54
PERROR - 20:17:01.531360 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
55
PERROR - 20:17:01.531371 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
56
DEBUG1 - 20:17:01.531381 [11252/11257]: Relay viewer stream 1105 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
57
DEBUG1 - 20:17:01.531400 [11252/11257]: Closing stream id 1106 (in stream_close() at stream.c:86)
58
PERROR - 20:17:01.531411 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
59
PERROR - 20:17:01.531422 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
60
DEBUG1 - 20:17:01.531432 [11252/11257]: Relay viewer stream 1106 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
61
DEBUG1 - 20:17:01.531445 [11252/11257]: Closing stream id 1107 (in stream_close() at stream.c:86)
62
PERROR - 20:17:01.531461 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
63
PERROR - 20:17:01.531473 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
64
DEBUG1 - 20:17:01.531483 [11252/11257]: Relay viewer stream 1107 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
65
DEBUG1 - 20:17:01.531496 [11252/11257]: Closing stream id 1108 (in stream_close() at stream.c:86)
66
PERROR - 20:17:01.531512 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
67
PERROR - 20:17:01.531524 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
68
DEBUG1 - 20:17:01.531533 [11252/11257]: Relay viewer stream 1108 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
69
DEBUG1 - 20:17:01.531548 [11252/11257]: Closing stream id 1109 (in stream_close() at stream.c:86)
70
PERROR - 20:17:01.531559 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
71
PERROR - 20:17:01.531579 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
72
DEBUG1 - 20:17:01.531589 [11252/11257]: Relay viewer stream 1109 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
73
DEBUG1 - 20:17:01.531603 [11252/11257]: Closing stream id 1110 (in stream_close() at stream.c:86)
74
DEBUG1 - 20:17:01.531630 [11252/11257]: Relay viewer stream 1110 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
75
DEBUG1 - 20:17:01.531647 [11252/11257]: Closing stream id 1111 (in stream_close() at stream.c:86)
76
PERROR - 20:17:01.531658 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
77
PERROR - 20:17:01.531669 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
78
DEBUG1 - 20:17:01.531678 [11252/11257]: Relay viewer stream 1111 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
79
DEBUG1 - 20:17:01.531692 [11252/11257]: Closing stream id 1112 (in stream_close() at stream.c:86)
80
PERROR - 20:17:01.531709 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
81
PERROR - 20:17:01.531719 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
82
DEBUG1 - 20:17:01.531729 [11252/11257]: Relay viewer stream 1112 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
83
DEBUG1 - 20:17:01.531743 [11252/11257]: Closing stream id 1113 (in stream_close() at stream.c:86)
84
PERROR - 20:17:01.531753 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
85
PERROR - 20:17:01.531764 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
86
DEBUG1 - 20:17:01.531796 [11252/11257]: Relay viewer stream 1113 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
87
DEBUG1 - 20:17:01.531811 [11252/11257]: Closing stream id 1114 (in stream_close() at stream.c:86)
88
PERROR - 20:17:01.531834 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
89
PERROR - 20:17:01.531848 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
90
DEBUG1 - 20:17:01.531858 [11252/11257]: Relay viewer stream 1114 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
91
DEBUG1 - 20:17:01.531882 [11252/11257]: Closing stream id 1115 (in stream_close() at stream.c:86)
92
PERROR - 20:17:01.531900 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
93
PERROR - 20:17:01.531912 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
94
DEBUG1 - 20:17:01.531921 [11252/11257]: Relay viewer stream 1115 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
95
DEBUG1 - 20:17:01.531935 [11252/11257]: Closing stream id 1116 (in stream_close() at stream.c:86)
96
PERROR - 20:17:01.531946 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
97
PERROR - 20:17:01.531956 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
98
DEBUG1 - 20:17:01.531972 [11252/11257]: Relay viewer stream 1116 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
99
DEBUG1 - 20:17:01.531996 [11252/11257]: Closing stream id 1117 (in stream_close() at stream.c:86)
100
PERROR - 20:17:01.532008 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
101
PERROR - 20:17:01.532018 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
102
DEBUG1 - 20:17:01.532028 [11252/11257]: Relay viewer stream 1117 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
103
DEBUG1 - 20:17:01.532041 [11252/11257]: Closing stream id 1118 (in stream_close() at stream.c:86)
104
PERROR - 20:17:01.532060 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
105
PERROR - 20:17:01.532071 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
106
DEBUG1 - 20:17:01.532080 [11252/11257]: Relay viewer stream 1118 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
107
DEBUG1 - 20:17:01.532100 [11252/11257]: Closing stream id 1119 (in stream_close() at stream.c:86)
108
PERROR - 20:17:01.532125 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
109
PERROR - 20:17:01.532136 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
110
DEBUG1 - 20:17:01.532157 [11252/11257]: Relay viewer stream 1119 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
111
DEBUG1 - 20:17:01.532172 [11252/11257]: Closing stream id 1120 (in stream_close() at stream.c:86)
112
PERROR - 20:17:01.532182 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
113
PERROR - 20:17:01.532198 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
114
DEBUG1 - 20:17:01.532209 [11252/11257]: Relay viewer stream 1120 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
115
DEBUG1 - 20:17:01.532223 [11252/11257]: Closing stream id 1121 (in stream_close() at stream.c:86)
116
PERROR - 20:17:01.532233 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
117
PERROR - 20:17:01.532244 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
118
DEBUG1 - 20:17:01.532253 [11252/11257]: Relay viewer stream 1121 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
119
DEBUG1 - 20:17:01.532269 [11252/11257]: Closing stream id 1122 (in stream_close() at stream.c:86)
120
PERROR - 20:17:01.532281 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
121
PERROR - 20:17:01.532291 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
122
DEBUG1 - 20:17:01.532300 [11252/11257]: Relay viewer stream 1122 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
123
DEBUG1 - 20:17:01.532314 [11252/11257]: Closing stream id 1123 (in stream_close() at stream.c:86)
124
PERROR - 20:17:01.532325 [11252/11257]: close stream: Bad file descriptor (in stream_close() at stream.c:91)
125
PERROR - 20:17:01.532335 [11252/11257]: close stream index_fd: Bad file descriptor (in stream_close() at stream.c:98)
126
DEBUG1 - 20:17:01.532344 [11252/11257]: Relay viewer stream 1123 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
127
DEBUG1 - 20:17:01.532358 [11252/11257]: Closing stream id 1124 (in stream_close() at stream.c:86)
128
DEBUG1 - 20:17:01.532370 [11252/11257]: Relay viewer stream 1124 not found (in viewer_stream_find_by_id() at viewer-stream.c:195)
129
DEBUG1 - 20:17:01.532411 [11252/11257]: Relay destroying session 45 (in session_destroy() at session.c:167)
130
DEBUG1 - 20:17:01.532426 [11252/11257]: Connection closed with 93 (in relay_thread_worker() at main.c:2569)
131
DEBUG3 - 20:17:01.532436 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
132
DEBUG1 - 20:24:29.589714 [11252/11258]: Relay new connection received (in relay_thread_listener() at main.c:829)
133
DEBUG1 - 20:24:29.589761 [11252/11258]: Relay control connection accepted, socket 93 (in relay_thread_listener() at main.c:876)
134
DEBUG1 - 20:24:29.589785 [11252/11258]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:104)
135
DEBUG1 - 20:24:29.589792 [11252/11258]: Listener accepting connections (in relay_thread_listener() at main.c:811)
136
DEBUG1 - 20:24:29.589794 [11252/11256]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:90)
137
DEBUG1 - 20:24:29.589808 [11252/11256]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:75)
138
DEBUG1 - 20:24:29.589815 [11252/11256]: Dispatching request waiting on sock 93 (in relay_thread_dispatcher() at main.c:979)
139
DEBUG1 - 20:24:29.589828 [11252/11256]: Woken up but nothing in the relay command queue (in relay_thread_dispatcher() at main.c:973)
140
DEBUG1 - 20:24:29.589854 [11252/11257]: Connection socket 93 added (in relay_thread_worker() at main.c:2540)
141
DEBUG3 - 20:24:29.589861 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
142
DEBUG1 - 20:24:29.589882 [11252/11257]: Version check done using protocol 2.6 (in relay_send_version() at main.c:1609)
143
DEBUG3 - 20:24:29.589890 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
144
DEBUG3 - 20:24:29.590130 [11252/11257]: Created hashtable size 4 at 0x7f077c04abb0 of type 0 (in lttng_ht_new() at hashtable.c:127)
145
DEBUG1 - 20:24:29.590149 [11252/11257]: Created session 46 (in relay_create_session() at main.c:1124)
146
DEBUG3 - 20:24:29.590161 [11252/11257]: Relayd worker thread polling... (in relay_thread_worker() at main.c:2482)
147
DEBUG1 - 20:24:29.590658 [11252/11258]: Relay new connection received (in relay_thread_listener() at main.c:829)
148
DEBUG1 - 20:24:29.590673 [11252/11258]: Relay data connection accepted, socket 94 (in relay_thread_listener() at main.c:870)
149
DEBUG1 - 20:24:29.590683 [11252/11258]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:104)
150
DEBUG1 - 20:24:29.590702 [11252/11258]: Listener accepting connections (in relay_thread_listener() at main.c:811)
151
DEBUG1 - 20:24:29.590691 [11252/11256]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:90)
152
DEBUG1 - 20:24:29.590717 [11252/11256]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:75)
153
DEBUG1 - 20:24:29.590724 [11252/11256]: Dispatching request waiting on sock 94 (in relay_thread_dispatcher() at main.c:979)
154
DEBUG1 - 20:24:29.590734 [11252/11256]: Woken up but nothing in the relay command queue (in relay_thread_dispatcher() at main.c:973)
155
lttng-relayd: hashtable.c:315: lttng_ht_add_unique_ulong: Assertion `node_ptr == &node->node' failed.
156
^C
157
[1]+  Aborted                 ./T9/usr/bin/lttng-relayd -v
    (1-1/1)