Willy Tarreau | 4151c75 | 2019-08-08 18:21:26 +0200 | [diff] [blame] | 1 | /* |
| 2 | * Runtime tracing API |
| 3 | * |
| 4 | * Copyright (C) 2000-2019 Willy Tarreau - w@1wt.eu |
| 5 | * |
| 6 | * This library is free software; you can redistribute it and/or |
| 7 | * modify it under the terms of the GNU Lesser General Public |
| 8 | * License as published by the Free Software Foundation, version 2.1 |
| 9 | * exclusively. |
| 10 | * |
| 11 | * This library is distributed in the hope that it will be useful, |
| 12 | * but WITHOUT ANY WARRANTY; without even the implied warranty of |
| 13 | * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU |
| 14 | * Lesser General Public License for more details. |
| 15 | * |
| 16 | * You should have received a copy of the GNU Lesser General Public |
| 17 | * License along with this library; if not, write to the Free Software |
| 18 | * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA |
| 19 | */ |
| 20 | |
Willy Tarreau | eb6f701 | 2020-05-27 16:21:26 +0200 | [diff] [blame] | 21 | #include <import/ist.h> |
Willy Tarreau | 2741c8c | 2020-06-02 11:28:02 +0200 | [diff] [blame] | 22 | #include <haproxy/api.h> |
| 23 | #include <haproxy/buf.h> |
| 24 | #include <haproxy/istbuf.h> |
Willy Tarreau | 853b297 | 2020-05-27 18:01:47 +0200 | [diff] [blame] | 25 | #include <haproxy/list.h> |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 26 | #include <proto/cli.h> |
Willy Tarreau | 4151c75 | 2019-08-08 18:21:26 +0200 | [diff] [blame] | 27 | #include <proto/log.h> |
Willy Tarreau | ba2f73d | 2020-06-03 20:02:28 +0200 | [diff] [blame^] | 28 | #include <haproxy/sink.h> |
Willy Tarreau | 4151c75 | 2019-08-08 18:21:26 +0200 | [diff] [blame] | 29 | #include <proto/trace.h> |
| 30 | |
| 31 | struct list trace_sources = LIST_HEAD_INIT(trace_sources); |
Willy Tarreau | 88ebd40 | 2019-08-19 15:55:34 +0200 | [diff] [blame] | 32 | THREAD_LOCAL struct buffer trace_buf = { }; |
| 33 | |
| 34 | /* allocates the trace buffers. Returns 0 in case of failure. It is safe to |
| 35 | * call to call this function multiple times if the size changes. |
| 36 | */ |
| 37 | static int alloc_trace_buffers_per_thread() |
| 38 | { |
| 39 | chunk_init(&trace_buf, my_realloc2(trace_buf.area, global.tune.bufsize), global.tune.bufsize); |
Willy Tarreau | 2e7fdfc | 2019-11-25 19:43:31 +0100 | [diff] [blame] | 40 | return !!trace_buf.area; |
Willy Tarreau | 88ebd40 | 2019-08-19 15:55:34 +0200 | [diff] [blame] | 41 | } |
| 42 | |
| 43 | static void free_trace_buffers_per_thread() |
| 44 | { |
| 45 | chunk_destroy(&trace_buf); |
| 46 | } |
Willy Tarreau | 4151c75 | 2019-08-08 18:21:26 +0200 | [diff] [blame] | 47 | |
Willy Tarreau | 88ebd40 | 2019-08-19 15:55:34 +0200 | [diff] [blame] | 48 | REGISTER_PER_THREAD_ALLOC(alloc_trace_buffers_per_thread); |
| 49 | REGISTER_PER_THREAD_FREE(free_trace_buffers_per_thread); |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 50 | |
Willy Tarreau | d8b99ed | 2019-08-21 17:05:46 +0200 | [diff] [blame] | 51 | /* pick the lowest non-null argument with a non-null arg_def mask */ |
| 52 | static inline const void *trace_pick_arg(uint32_t arg_def, const void *a1, const void *a2, const void *a3, const void *a4) |
| 53 | { |
| 54 | if (arg_def & 0x0000FFFF) { |
| 55 | if ((arg_def & 0x000000FF) && a1) |
| 56 | return a1; |
| 57 | if ((arg_def & 0x0000FF00) && a2) |
| 58 | return a2; |
| 59 | } |
| 60 | |
| 61 | if (arg_def & 0xFFFF0000) { |
| 62 | if ((arg_def & 0x00FF0000) && a3) |
| 63 | return a3; |
| 64 | if ((arg_def & 0xFF000000) && a4) |
| 65 | return a4; |
| 66 | } |
| 67 | |
| 68 | return NULL; |
| 69 | } |
| 70 | |
Willy Tarreau | 4c2ae48 | 2019-08-12 15:51:58 +0200 | [diff] [blame] | 71 | /* write a message for the given trace source */ |
Willy Tarreau | 09fb0df | 2019-08-29 08:40:59 +0200 | [diff] [blame] | 72 | void __trace(enum trace_level level, uint64_t mask, struct trace_source *src, |
| 73 | const struct ist where, const char *func, |
Willy Tarreau | bfd14fc | 2019-08-19 16:28:07 +0200 | [diff] [blame] | 74 | const void *a1, const void *a2, const void *a3, const void *a4, |
Willy Tarreau | 09fb0df | 2019-08-29 08:40:59 +0200 | [diff] [blame] | 75 | void (*cb)(enum trace_level level, uint64_t mask, const struct trace_source *src, |
| 76 | const struct ist where, const struct ist func, |
Willy Tarreau | bfd14fc | 2019-08-19 16:28:07 +0200 | [diff] [blame] | 77 | const void *a1, const void *a2, const void *a3, const void *a4), |
| 78 | const struct ist msg) |
Willy Tarreau | 4c2ae48 | 2019-08-12 15:51:58 +0200 | [diff] [blame] | 79 | { |
Willy Tarreau | d8b99ed | 2019-08-21 17:05:46 +0200 | [diff] [blame] | 80 | const struct listener *li = NULL; |
| 81 | const struct proxy *fe = NULL; |
| 82 | const struct proxy *be = NULL; |
| 83 | const struct server *srv = NULL; |
| 84 | const struct session *sess = NULL; |
| 85 | const struct stream *strm = NULL; |
| 86 | const struct connection *conn = NULL; |
| 87 | const void *lockon_ptr = NULL; |
Willy Tarreau | 09fb0df | 2019-08-29 08:40:59 +0200 | [diff] [blame] | 88 | struct ist ist_func = ist(func); |
Willy Tarreau | a9f5b96 | 2019-08-28 10:08:58 +0200 | [diff] [blame] | 89 | char tnum[4]; |
Willy Tarreau | 052ad36 | 2019-08-29 09:08:36 +0200 | [diff] [blame] | 90 | struct ist line[12]; |
Willy Tarreau | 09fb0df | 2019-08-29 08:40:59 +0200 | [diff] [blame] | 91 | int words = 0; |
Willy Tarreau | 419bd49 | 2019-08-12 17:27:09 +0200 | [diff] [blame] | 92 | |
Willy Tarreau | 4c2ae48 | 2019-08-12 15:51:58 +0200 | [diff] [blame] | 93 | if (likely(src->state == TRACE_STATE_STOPPED)) |
| 94 | return; |
| 95 | |
| 96 | /* check that at least one action is interested by this event */ |
| 97 | if (((src->report_events | src->start_events | src->pause_events | src->stop_events) & mask) == 0) |
| 98 | return; |
| 99 | |
Willy Tarreau | d8b99ed | 2019-08-21 17:05:46 +0200 | [diff] [blame] | 100 | /* retrieve available information from the caller's arguments */ |
| 101 | if (src->arg_def & TRC_ARGS_CONN) |
| 102 | conn = trace_pick_arg(src->arg_def & TRC_ARGS_CONN, a1, a2, a3, a4); |
| 103 | |
| 104 | if (src->arg_def & TRC_ARGS_SESS) |
| 105 | sess = trace_pick_arg(src->arg_def & TRC_ARGS_SESS, a1, a2, a3, a4); |
| 106 | |
| 107 | if (src->arg_def & TRC_ARGS_STRM) |
| 108 | strm = trace_pick_arg(src->arg_def & TRC_ARGS_STRM, a1, a2, a3, a4); |
| 109 | |
| 110 | if (!sess && strm) |
| 111 | sess = strm->sess; |
| 112 | else if (!sess && conn) |
| 113 | sess = conn->owner; |
| 114 | |
| 115 | if (sess) { |
| 116 | fe = sess->fe; |
| 117 | li = sess->listener; |
| 118 | } |
| 119 | |
| 120 | if (!li && conn) |
| 121 | li = objt_listener(conn->target); |
| 122 | |
| 123 | if (li && !fe) |
| 124 | fe = li->bind_conf->frontend; |
| 125 | |
| 126 | if (strm) { |
| 127 | be = strm->be; |
| 128 | srv = strm->srv_conn; |
| 129 | } |
| 130 | |
| 131 | if (!srv && conn) |
| 132 | srv = objt_server(conn->target); |
| 133 | |
| 134 | if (srv && !be) |
| 135 | be = srv->proxy; |
| 136 | |
| 137 | if (!be && conn) |
| 138 | be = objt_proxy(conn->target); |
| 139 | |
Willy Tarreau | 4c2ae48 | 2019-08-12 15:51:58 +0200 | [diff] [blame] | 140 | /* TODO: add handling of filters here, return if no match (not even update states) */ |
| 141 | |
| 142 | /* check if we need to start the trace now */ |
| 143 | if (src->state == TRACE_STATE_WAITING) { |
| 144 | if ((src->start_events & mask) == 0) |
| 145 | return; |
| 146 | |
| 147 | /* TODO: add update of lockon+lockon_ptr here */ |
| 148 | HA_ATOMIC_STORE(&src->state, TRACE_STATE_RUNNING); |
| 149 | } |
| 150 | |
Willy Tarreau | d8b99ed | 2019-08-21 17:05:46 +0200 | [diff] [blame] | 151 | /* we may want to lock on a particular object */ |
| 152 | if (src->lockon != TRACE_LOCKON_NOTHING) { |
| 153 | switch (src->lockon) { |
| 154 | case TRACE_LOCKON_BACKEND: lockon_ptr = be; break; |
| 155 | case TRACE_LOCKON_CONNECTION: lockon_ptr = conn; break; |
| 156 | case TRACE_LOCKON_FRONTEND: lockon_ptr = fe; break; |
| 157 | case TRACE_LOCKON_LISTENER: lockon_ptr = li; break; |
| 158 | case TRACE_LOCKON_SERVER: lockon_ptr = srv; break; |
| 159 | case TRACE_LOCKON_SESSION: lockon_ptr = sess; break; |
| 160 | case TRACE_LOCKON_STREAM: lockon_ptr = strm; break; |
| 161 | case TRACE_LOCKON_THREAD: lockon_ptr = ti; break; |
| 162 | case TRACE_LOCKON_ARG1: lockon_ptr = a1; break; |
| 163 | case TRACE_LOCKON_ARG2: lockon_ptr = a2; break; |
| 164 | case TRACE_LOCKON_ARG3: lockon_ptr = a3; break; |
| 165 | case TRACE_LOCKON_ARG4: lockon_ptr = a4; break; |
| 166 | default: break; // silence stupid gcc -Wswitch |
| 167 | } |
| 168 | |
| 169 | if (src->lockon_ptr && src->lockon_ptr != lockon_ptr) |
| 170 | return; |
| 171 | |
| 172 | if (!src->lockon_ptr && lockon_ptr && src->state == TRACE_STATE_RUNNING) |
| 173 | HA_ATOMIC_STORE(&src->lockon_ptr, lockon_ptr); |
| 174 | } |
| 175 | |
Willy Tarreau | 4c2ae48 | 2019-08-12 15:51:58 +0200 | [diff] [blame] | 176 | /* here the trace is running and is tracking a desired item */ |
| 177 | |
Willy Tarreau | 5da4088 | 2019-08-12 17:57:57 +0200 | [diff] [blame] | 178 | if ((src->report_events & mask) == 0 || level > src->level) |
Willy Tarreau | 4c2ae48 | 2019-08-12 15:51:58 +0200 | [diff] [blame] | 179 | goto end; |
| 180 | |
Willy Tarreau | 419bd49 | 2019-08-12 17:27:09 +0200 | [diff] [blame] | 181 | /* log the logging location truncated to 10 chars from the right so that |
| 182 | * the line number and the end of the file name are there. |
| 183 | */ |
Willy Tarreau | 09fb0df | 2019-08-29 08:40:59 +0200 | [diff] [blame] | 184 | line[words++] = ist("["); |
Willy Tarreau | a9f5b96 | 2019-08-28 10:08:58 +0200 | [diff] [blame] | 185 | tnum[0] = '0' + tid / 10; |
| 186 | tnum[1] = '0' + tid % 10; |
| 187 | tnum[2] = '|'; |
| 188 | tnum[3] = 0; |
Willy Tarreau | 09fb0df | 2019-08-29 08:40:59 +0200 | [diff] [blame] | 189 | line[words++] = ist(tnum); |
| 190 | line[words++] = src->name; |
| 191 | line[words++] = ist("|"); |
Willy Tarreau | 052ad36 | 2019-08-29 09:08:36 +0200 | [diff] [blame] | 192 | line[words++] = ist2("01234" + level, 1); // "0" to "4" |
| 193 | line[words++] = ist("|"); |
Willy Tarreau | 09fb0df | 2019-08-29 08:40:59 +0200 | [diff] [blame] | 194 | line[words] = where; |
| 195 | if (line[words].len > 13) { |
| 196 | line[words].ptr += (line[words].len - 13); |
| 197 | line[words].len = 13; |
Willy Tarreau | 419bd49 | 2019-08-12 17:27:09 +0200 | [diff] [blame] | 198 | } |
Willy Tarreau | 09fb0df | 2019-08-29 08:40:59 +0200 | [diff] [blame] | 199 | words++; |
| 200 | line[words++] = ist("] "); |
| 201 | |
| 202 | if (ist_func.ptr) { |
| 203 | line[words++] = ist_func; |
| 204 | line[words++] = ist("(): "); |
| 205 | } |
Willy Tarreau | bfd14fc | 2019-08-19 16:28:07 +0200 | [diff] [blame] | 206 | |
Willy Tarreau | 3da0026 | 2019-08-28 07:03:58 +0200 | [diff] [blame] | 207 | if (!cb) |
| 208 | cb = src->default_cb; |
| 209 | |
Willy Tarreau | 370a694 | 2019-08-29 08:24:16 +0200 | [diff] [blame] | 210 | if (cb && src->verbosity) { |
Willy Tarreau | bfd14fc | 2019-08-19 16:28:07 +0200 | [diff] [blame] | 211 | /* decode function passed, we want to pre-fill the |
| 212 | * buffer with the message and let the decode function |
| 213 | * do its job, possibly even overwriting it. |
| 214 | */ |
| 215 | b_reset(&trace_buf); |
| 216 | b_istput(&trace_buf, msg); |
Willy Tarreau | 09fb0df | 2019-08-29 08:40:59 +0200 | [diff] [blame] | 217 | cb(level, mask, src, where, ist_func, a1, a2, a3, a4); |
| 218 | line[words].ptr = trace_buf.area; |
| 219 | line[words].len = trace_buf.data; |
| 220 | words++; |
Willy Tarreau | bfd14fc | 2019-08-19 16:28:07 +0200 | [diff] [blame] | 221 | } |
Willy Tarreau | 370a694 | 2019-08-29 08:24:16 +0200 | [diff] [blame] | 222 | else { |
| 223 | /* Note that here we could decide to print some args whose type |
| 224 | * is known, when verbosity is above the quiet level, and even |
| 225 | * to print the name and values of those which are declared for |
| 226 | * lock-on. |
| 227 | */ |
Willy Tarreau | 09fb0df | 2019-08-29 08:40:59 +0200 | [diff] [blame] | 228 | line[words++] = msg; |
Willy Tarreau | 370a694 | 2019-08-29 08:24:16 +0200 | [diff] [blame] | 229 | } |
Willy Tarreau | 419bd49 | 2019-08-12 17:27:09 +0200 | [diff] [blame] | 230 | |
Willy Tarreau | 4c2ae48 | 2019-08-12 15:51:58 +0200 | [diff] [blame] | 231 | if (src->sink) |
Emeric Brun | bd16381 | 2020-05-06 14:33:46 +0200 | [diff] [blame] | 232 | sink_write(src->sink, line, words, 0, 0, NULL, NULL, NULL); |
Willy Tarreau | 4c2ae48 | 2019-08-12 15:51:58 +0200 | [diff] [blame] | 233 | |
| 234 | end: |
| 235 | /* check if we need to stop the trace now */ |
| 236 | if ((src->stop_events & mask) != 0) { |
Willy Tarreau | beadb5c | 2019-08-20 18:57:48 +0200 | [diff] [blame] | 237 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
Willy Tarreau | 4c2ae48 | 2019-08-12 15:51:58 +0200 | [diff] [blame] | 238 | HA_ATOMIC_STORE(&src->state, TRACE_STATE_STOPPED); |
| 239 | } |
| 240 | else if ((src->pause_events & mask) != 0) { |
Willy Tarreau | beadb5c | 2019-08-20 18:57:48 +0200 | [diff] [blame] | 241 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
Willy Tarreau | 4c2ae48 | 2019-08-12 15:51:58 +0200 | [diff] [blame] | 242 | HA_ATOMIC_STORE(&src->state, TRACE_STATE_WAITING); |
| 243 | } |
| 244 | } |
| 245 | |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 246 | struct trace_source *trace_find_source(const char *name) |
| 247 | { |
| 248 | struct trace_source *src; |
| 249 | const struct ist iname = ist(name); |
| 250 | |
| 251 | list_for_each_entry(src, &trace_sources, source_link) |
| 252 | if (isteq(src->name, iname)) |
| 253 | return src; |
| 254 | return NULL; |
| 255 | } |
| 256 | |
| 257 | const struct trace_event *trace_find_event(const struct trace_event *ev, const char *name) |
| 258 | { |
| 259 | for (; ev && ev->mask; ev++) |
| 260 | if (strcmp(ev->name, name) == 0) |
| 261 | return ev; |
| 262 | return NULL; |
| 263 | } |
| 264 | |
| 265 | /* parse the command, returns 1 if a message is returned, otherwise zero */ |
| 266 | static int cli_parse_trace(char **args, char *payload, struct appctx *appctx, void *private) |
| 267 | { |
| 268 | struct trace_source *src; |
| 269 | uint64_t *ev_ptr = NULL; |
| 270 | |
| 271 | if (!cli_has_level(appctx, ACCESS_LVL_OPER)) |
| 272 | return 1; |
| 273 | |
| 274 | if (!*args[1]) { |
| 275 | /* no arg => report the list of supported sources as a warning */ |
| 276 | chunk_printf(&trash, |
| 277 | "Supported trace sources and states (.=stopped, w=waiting, R=running) :\n" |
| 278 | " [.] 0 : not a source, will immediately stop all traces\n" |
| 279 | ); |
| 280 | |
| 281 | list_for_each_entry(src, &trace_sources, source_link) |
| 282 | chunk_appendf(&trash, " [%c] %-10s : %s\n", trace_state_char(src->state), src->name.ptr, src->desc); |
| 283 | |
| 284 | trash.area[trash.data] = 0; |
| 285 | return cli_msg(appctx, LOG_WARNING, trash.area); |
| 286 | } |
| 287 | |
| 288 | if (strcmp(args[1], "0") == 0) { |
| 289 | /* emergency stop of all traces */ |
| 290 | list_for_each_entry(src, &trace_sources, source_link) |
| 291 | HA_ATOMIC_STORE(&src->state, TRACE_STATE_STOPPED); |
| 292 | return cli_msg(appctx, LOG_NOTICE, "All traces now stopped"); |
| 293 | } |
| 294 | |
| 295 | src = trace_find_source(args[1]); |
| 296 | if (!src) |
| 297 | return cli_err(appctx, "No such trace source"); |
| 298 | |
| 299 | if (!*args[2]) { |
| 300 | return cli_msg(appctx, LOG_WARNING, |
| 301 | "Supported commands:\n" |
Willy Tarreau | 370a694 | 2019-08-29 08:24:16 +0200 | [diff] [blame] | 302 | " event : list/enable/disable source-specific event reporting\n" |
| 303 | //" filter : list/enable/disable generic filters\n" |
| 304 | " level : list/set trace reporting level\n" |
| 305 | " lock : automatic lock on thread/connection/stream/...\n" |
| 306 | " pause : pause and automatically restart after a specific event\n" |
| 307 | " sink : list/set event sinks\n" |
| 308 | " start : start immediately or after a specific event\n" |
| 309 | " stop : stop immediately or after a specific event\n" |
| 310 | " verbosity : list/set trace output verbosity\n" |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 311 | ); |
| 312 | } |
| 313 | else if ((strcmp(args[2], "event") == 0 && (ev_ptr = &src->report_events)) || |
| 314 | (strcmp(args[2], "pause") == 0 && (ev_ptr = &src->pause_events)) || |
| 315 | (strcmp(args[2], "start") == 0 && (ev_ptr = &src->start_events)) || |
| 316 | (strcmp(args[2], "stop") == 0 && (ev_ptr = &src->stop_events))) { |
| 317 | const struct trace_event *ev; |
| 318 | const char *name = args[3]; |
| 319 | int neg = 0; |
| 320 | int i; |
| 321 | |
| 322 | /* skip prefix '!', '-', '+' and remind negation */ |
| 323 | while (*name) { |
| 324 | if (*name == '!' || *name == '-') |
| 325 | neg = 1; |
| 326 | else if (*name == '+') |
| 327 | neg = 0; |
| 328 | else |
| 329 | break; |
| 330 | name++; |
| 331 | } |
| 332 | |
| 333 | if (!*name) { |
| 334 | chunk_printf(&trash, "Supported events for source %s (+=enabled, -=disabled):\n", src->name.ptr); |
| 335 | if (ev_ptr != &src->report_events) |
Willy Tarreau | 99282dd | 2019-08-30 07:37:32 +0200 | [diff] [blame] | 336 | chunk_appendf(&trash, " - now : don't wait for events, immediately change the state\n"); |
| 337 | chunk_appendf(&trash, " - none : disable all event types\n"); |
| 338 | chunk_appendf(&trash, " - any : enable all event types\n"); |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 339 | for (i = 0; src->known_events && src->known_events[i].mask; i++) { |
Willy Tarreau | 99282dd | 2019-08-30 07:37:32 +0200 | [diff] [blame] | 340 | chunk_appendf(&trash, " %c %-12s : %s\n", |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 341 | trace_event_char(*ev_ptr, src->known_events[i].mask), |
| 342 | src->known_events[i].name, src->known_events[i].desc); |
| 343 | } |
| 344 | trash.area[trash.data] = 0; |
| 345 | return cli_msg(appctx, LOG_WARNING, trash.area); |
| 346 | } |
| 347 | |
| 348 | if (strcmp(name, "now") == 0 && ev_ptr != &src->report_events) { |
| 349 | HA_ATOMIC_STORE(ev_ptr, 0); |
Willy Tarreau | beadb5c | 2019-08-20 18:57:48 +0200 | [diff] [blame] | 350 | if (ev_ptr == &src->pause_events) { |
| 351 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 352 | HA_ATOMIC_STORE(&src->state, TRACE_STATE_WAITING); |
Willy Tarreau | beadb5c | 2019-08-20 18:57:48 +0200 | [diff] [blame] | 353 | } |
| 354 | else if (ev_ptr == &src->start_events) { |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 355 | HA_ATOMIC_STORE(&src->state, TRACE_STATE_RUNNING); |
Willy Tarreau | beadb5c | 2019-08-20 18:57:48 +0200 | [diff] [blame] | 356 | } |
| 357 | else if (ev_ptr == &src->stop_events) { |
| 358 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 359 | HA_ATOMIC_STORE(&src->state, TRACE_STATE_STOPPED); |
Willy Tarreau | beadb5c | 2019-08-20 18:57:48 +0200 | [diff] [blame] | 360 | } |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 361 | return 0; |
| 362 | } |
| 363 | |
| 364 | if (strcmp(name, "none") == 0) |
| 365 | HA_ATOMIC_STORE(ev_ptr, 0); |
| 366 | else if (strcmp(name, "any") == 0) |
| 367 | HA_ATOMIC_STORE(ev_ptr, ~0); |
| 368 | else { |
| 369 | ev = trace_find_event(src->known_events, name); |
| 370 | if (!ev) |
| 371 | return cli_err(appctx, "No such trace event"); |
| 372 | |
| 373 | if (!neg) |
| 374 | HA_ATOMIC_OR(ev_ptr, ev->mask); |
| 375 | else |
| 376 | HA_ATOMIC_AND(ev_ptr, ~ev->mask); |
| 377 | } |
| 378 | } |
| 379 | else if (strcmp(args[2], "sink") == 0) { |
| 380 | const char *name = args[3]; |
| 381 | struct sink *sink; |
| 382 | |
| 383 | if (!*name) { |
| 384 | chunk_printf(&trash, "Supported sinks for source %s (*=current):\n", src->name.ptr); |
| 385 | chunk_appendf(&trash, " %c none : no sink\n", src->sink ? ' ' : '*'); |
| 386 | list_for_each_entry(sink, &sink_list, sink_list) { |
| 387 | chunk_appendf(&trash, " %c %-10s : %s\n", |
| 388 | src->sink == sink ? '*' : ' ', |
| 389 | sink->name, sink->desc); |
| 390 | } |
| 391 | trash.area[trash.data] = 0; |
| 392 | return cli_msg(appctx, LOG_WARNING, trash.area); |
| 393 | } |
| 394 | |
| 395 | if (strcmp(name, "none") == 0) |
| 396 | sink = NULL; |
| 397 | else { |
| 398 | sink = sink_find(name); |
| 399 | if (!sink) |
| 400 | return cli_err(appctx, "No such sink"); |
| 401 | } |
| 402 | |
| 403 | HA_ATOMIC_STORE(&src->sink, sink); |
| 404 | } |
Willy Tarreau | aaaf411 | 2019-08-12 17:57:57 +0200 | [diff] [blame] | 405 | else if (strcmp(args[2], "level") == 0) { |
| 406 | const char *name = args[3]; |
| 407 | |
| 408 | if (!*name) { |
Willy Tarreau | 2ea549b | 2019-08-29 08:01:48 +0200 | [diff] [blame] | 409 | chunk_printf(&trash, "Supported trace levels for source %s:\n", src->name.ptr); |
Willy Tarreau | aaaf411 | 2019-08-12 17:57:57 +0200 | [diff] [blame] | 410 | chunk_appendf(&trash, " %c user : information useful to the end user\n", |
| 411 | src->level == TRACE_LEVEL_USER ? '*' : ' '); |
Willy Tarreau | 2ea549b | 2019-08-29 08:01:48 +0200 | [diff] [blame] | 412 | chunk_appendf(&trash, " %c proto : also protocol-level updates\n", |
Willy Tarreau | aaaf411 | 2019-08-12 17:57:57 +0200 | [diff] [blame] | 413 | src->level == TRACE_LEVEL_PROTO ? '*' : ' '); |
Willy Tarreau | 2ea549b | 2019-08-29 08:01:48 +0200 | [diff] [blame] | 414 | chunk_appendf(&trash, " %c state : also report internal state changes\n", |
Willy Tarreau | aaaf411 | 2019-08-12 17:57:57 +0200 | [diff] [blame] | 415 | src->level == TRACE_LEVEL_STATE ? '*' : ' '); |
Willy Tarreau | 2ea549b | 2019-08-29 08:01:48 +0200 | [diff] [blame] | 416 | chunk_appendf(&trash, " %c data : also report data transfers\n", |
| 417 | src->level == TRACE_LEVEL_DATA ? '*' : ' '); |
| 418 | chunk_appendf(&trash, " %c developer : also report information useful only to the developer\n", |
Willy Tarreau | aaaf411 | 2019-08-12 17:57:57 +0200 | [diff] [blame] | 419 | src->level == TRACE_LEVEL_DEVELOPER ? '*' : ' '); |
| 420 | trash.area[trash.data] = 0; |
| 421 | return cli_msg(appctx, LOG_WARNING, trash.area); |
| 422 | } |
| 423 | |
| 424 | if (strcmp(name, "user") == 0) |
| 425 | HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_USER); |
Willy Tarreau | aaaf411 | 2019-08-12 17:57:57 +0200 | [diff] [blame] | 426 | else if (strcmp(name, "proto") == 0) |
| 427 | HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_PROTO); |
| 428 | else if (strcmp(name, "state") == 0) |
| 429 | HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_STATE); |
Willy Tarreau | 2ea549b | 2019-08-29 08:01:48 +0200 | [diff] [blame] | 430 | else if (strcmp(name, "data") == 0) |
| 431 | HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_DATA); |
Willy Tarreau | aaaf411 | 2019-08-12 17:57:57 +0200 | [diff] [blame] | 432 | else if (strcmp(name, "developer") == 0) |
| 433 | HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_DEVELOPER); |
| 434 | else |
| 435 | return cli_err(appctx, "No such trace level"); |
| 436 | } |
Willy Tarreau | 60e4c9f | 2019-08-20 19:24:10 +0200 | [diff] [blame] | 437 | else if (strcmp(args[2], "lock") == 0) { |
| 438 | const char *name = args[3]; |
| 439 | |
| 440 | if (!*name) { |
| 441 | chunk_printf(&trash, "Supported lock-on criteria for source %s:\n", src->name.ptr); |
| 442 | if (src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_STRM)) |
| 443 | chunk_appendf(&trash, " %c backend : lock on the backend that started the trace\n", |
| 444 | src->lockon == TRACE_LOCKON_BACKEND ? '*' : ' '); |
| 445 | |
| 446 | if (src->arg_def & TRC_ARGS_CONN) |
| 447 | chunk_appendf(&trash, " %c connection : lock on the connection that started the trace\n", |
| 448 | src->lockon == TRACE_LOCKON_CONNECTION ? '*' : ' '); |
| 449 | |
| 450 | if (src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM)) |
| 451 | chunk_appendf(&trash, " %c frontend : lock on the frontend that started the trace\n", |
| 452 | src->lockon == TRACE_LOCKON_FRONTEND ? '*' : ' '); |
| 453 | |
| 454 | if (src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM)) |
| 455 | chunk_appendf(&trash, " %c listener : lock on the listener that started the trace\n", |
| 456 | src->lockon == TRACE_LOCKON_LISTENER ? '*' : ' '); |
| 457 | |
| 458 | chunk_appendf(&trash, " %c nothing : do not lock on anything\n", |
| 459 | src->lockon == TRACE_LOCKON_NOTHING ? '*' : ' '); |
| 460 | |
| 461 | if (src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_STRM)) |
| 462 | chunk_appendf(&trash, " %c server : lock on the server that started the trace\n", |
| 463 | src->lockon == TRACE_LOCKON_SERVER ? '*' : ' '); |
| 464 | |
| 465 | if (src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM)) |
| 466 | chunk_appendf(&trash, " %c session : lock on the session that started the trace\n", |
| 467 | src->lockon == TRACE_LOCKON_SESSION ? '*' : ' '); |
| 468 | |
| 469 | if (src->arg_def & TRC_ARGS_STRM) |
| 470 | chunk_appendf(&trash, " %c stream : lock on the stream that started the trace\n", |
| 471 | src->lockon == TRACE_LOCKON_STREAM ? '*' : ' '); |
| 472 | |
| 473 | chunk_appendf(&trash, " %c thread : lock on the thread that started the trace\n", |
| 474 | src->lockon == TRACE_LOCKON_THREAD ? '*' : ' '); |
| 475 | |
| 476 | if (src->lockon_args && src->lockon_args[0].name) |
| 477 | chunk_appendf(&trash, " %c %-10s : %s\n", |
| 478 | src->lockon == TRACE_LOCKON_ARG1 ? '*' : ' ', |
| 479 | src->lockon_args[0].name, src->lockon_args[0].desc); |
| 480 | |
| 481 | if (src->lockon_args && src->lockon_args[1].name) |
| 482 | chunk_appendf(&trash, " %c %-10s : %s\n", |
| 483 | src->lockon == TRACE_LOCKON_ARG2 ? '*' : ' ', |
| 484 | src->lockon_args[1].name, src->lockon_args[1].desc); |
| 485 | |
| 486 | if (src->lockon_args && src->lockon_args[2].name) |
| 487 | chunk_appendf(&trash, " %c %-10s : %s\n", |
| 488 | src->lockon == TRACE_LOCKON_ARG3 ? '*' : ' ', |
| 489 | src->lockon_args[2].name, src->lockon_args[2].desc); |
| 490 | |
| 491 | if (src->lockon_args && src->lockon_args[3].name) |
| 492 | chunk_appendf(&trash, " %c %-10s : %s\n", |
| 493 | src->lockon == TRACE_LOCKON_ARG4 ? '*' : ' ', |
| 494 | src->lockon_args[3].name, src->lockon_args[3].desc); |
| 495 | |
| 496 | trash.area[trash.data] = 0; |
| 497 | return cli_msg(appctx, LOG_WARNING, trash.area); |
| 498 | } |
| 499 | else if ((src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_STRM)) && strcmp(name, "backend") == 0) { |
| 500 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_BACKEND); |
| 501 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 502 | } |
| 503 | else if ((src->arg_def & TRC_ARGS_CONN) && strcmp(name, "connection") == 0) { |
| 504 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_CONNECTION); |
| 505 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 506 | } |
| 507 | else if ((src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM)) && strcmp(name, "frontend") == 0) { |
| 508 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_FRONTEND); |
| 509 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 510 | } |
| 511 | else if ((src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM)) && strcmp(name, "listener") == 0) { |
| 512 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_LISTENER); |
| 513 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 514 | } |
| 515 | else if (strcmp(name, "nothing") == 0) { |
| 516 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_NOTHING); |
| 517 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 518 | } |
| 519 | else if ((src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_STRM)) && strcmp(name, "server") == 0) { |
| 520 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_SERVER); |
| 521 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 522 | } |
| 523 | else if ((src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM)) && strcmp(name, "session") == 0) { |
| 524 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_SESSION); |
| 525 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 526 | } |
| 527 | else if ((src->arg_def & TRC_ARGS_STRM) && strcmp(name, "stream") == 0) { |
| 528 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_STREAM); |
| 529 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 530 | } |
| 531 | else if (strcmp(name, "thread") == 0) { |
| 532 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_THREAD); |
| 533 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 534 | } |
| 535 | else if (src->lockon_args && src->lockon_args[0].name && strcmp(name, src->lockon_args[0].name) == 0) { |
| 536 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_ARG1); |
| 537 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 538 | } |
| 539 | else if (src->lockon_args && src->lockon_args[1].name && strcmp(name, src->lockon_args[1].name) == 0) { |
| 540 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_ARG2); |
| 541 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 542 | } |
| 543 | else if (src->lockon_args && src->lockon_args[2].name && strcmp(name, src->lockon_args[2].name) == 0) { |
| 544 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_ARG3); |
| 545 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 546 | } |
| 547 | else if (src->lockon_args && src->lockon_args[3].name && strcmp(name, src->lockon_args[3].name) == 0) { |
| 548 | HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_ARG4); |
| 549 | HA_ATOMIC_STORE(&src->lockon_ptr, NULL); |
| 550 | } |
| 551 | else |
| 552 | return cli_err(appctx, "Unsupported lock-on criterion"); |
| 553 | } |
Willy Tarreau | 370a694 | 2019-08-29 08:24:16 +0200 | [diff] [blame] | 554 | else if (strcmp(args[2], "verbosity") == 0) { |
| 555 | const char *name = args[3]; |
| 556 | const struct name_desc *nd; |
| 557 | |
| 558 | if (!*name) { |
| 559 | chunk_printf(&trash, "Supported trace verbosities for source %s:\n", src->name.ptr); |
| 560 | chunk_appendf(&trash, " %c quiet : only report basic information with no decoding\n", |
| 561 | src->verbosity == 0 ? '*' : ' '); |
| 562 | if (!src->decoding || !src->decoding[0].name) { |
| 563 | chunk_appendf(&trash, " %c default : report extra information when available\n", |
| 564 | src->verbosity > 0 ? '*' : ' '); |
| 565 | } else { |
| 566 | for (nd = src->decoding; nd->name && nd->desc; nd++) |
| 567 | chunk_appendf(&trash, " %c %-10s : %s\n", |
| 568 | nd == (src->decoding + src->verbosity - 1) ? '*' : ' ', |
| 569 | nd->name, nd->desc); |
| 570 | } |
| 571 | trash.area[trash.data] = 0; |
| 572 | return cli_msg(appctx, LOG_WARNING, trash.area); |
| 573 | } |
| 574 | |
| 575 | if (strcmp(name, "quiet") == 0) |
| 576 | HA_ATOMIC_STORE(&src->verbosity, 0); |
| 577 | else if (!src->decoding || !src->decoding[0].name) { |
| 578 | if (strcmp(name, "default") == 0) |
| 579 | HA_ATOMIC_STORE(&src->verbosity, 1); |
| 580 | else |
| 581 | return cli_err(appctx, "No such verbosity level"); |
| 582 | } else { |
| 583 | for (nd = src->decoding; nd->name && nd->desc; nd++) |
| 584 | if (strcmp(name, nd->name) == 0) |
| 585 | break; |
| 586 | |
| 587 | if (!nd->name || !nd->desc) |
| 588 | return cli_err(appctx, "No such verbosity level"); |
| 589 | |
| 590 | HA_ATOMIC_STORE(&src->verbosity, (nd - src->decoding) + 1); |
| 591 | } |
| 592 | } |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 593 | else |
| 594 | return cli_err(appctx, "Unknown trace keyword"); |
| 595 | |
| 596 | return 0; |
| 597 | } |
| 598 | |
Willy Tarreau | 85b1575 | 2019-08-12 16:44:33 +0200 | [diff] [blame] | 599 | /* parse the command, returns 1 if a message is returned, otherwise zero */ |
| 600 | static int cli_parse_show_trace(char **args, char *payload, struct appctx *appctx, void *private) |
| 601 | { |
| 602 | struct trace_source *src; |
| 603 | const struct sink *sink; |
| 604 | int i; |
| 605 | |
| 606 | args++; // make args[1] the 1st arg |
| 607 | |
| 608 | if (!*args[1]) { |
| 609 | /* no arg => report the list of supported sources */ |
| 610 | chunk_printf(&trash, |
| 611 | "Supported trace sources and states (.=stopped, w=waiting, R=running) :\n" |
| 612 | ); |
| 613 | |
| 614 | list_for_each_entry(src, &trace_sources, source_link) { |
| 615 | sink = src->sink; |
| 616 | chunk_appendf(&trash, " [%c] %-10s -> %s [drp %u] [%s]\n", |
| 617 | trace_state_char(src->state), src->name.ptr, |
| 618 | sink ? sink->name : "none", |
| 619 | sink ? sink->ctx.dropped : 0, |
| 620 | src->desc); |
| 621 | } |
| 622 | |
| 623 | trash.area[trash.data] = 0; |
| 624 | return cli_msg(appctx, LOG_INFO, trash.area); |
| 625 | } |
| 626 | |
| 627 | if (!cli_has_level(appctx, ACCESS_LVL_OPER)) |
| 628 | return 1; |
| 629 | |
| 630 | src = trace_find_source(args[1]); |
| 631 | if (!src) |
| 632 | return cli_err(appctx, "No such trace source"); |
| 633 | |
| 634 | sink = src->sink; |
| 635 | chunk_printf(&trash, "Trace status for %s:\n", src->name.ptr); |
| 636 | chunk_appendf(&trash, " - sink: %s [%u dropped]\n", |
| 637 | sink ? sink->name : "none", sink ? sink->ctx.dropped : 0); |
| 638 | |
Willy Tarreau | 99282dd | 2019-08-30 07:37:32 +0200 | [diff] [blame] | 639 | chunk_appendf(&trash, " - event name : report start stop pause\n"); |
Willy Tarreau | 85b1575 | 2019-08-12 16:44:33 +0200 | [diff] [blame] | 640 | for (i = 0; src->known_events && src->known_events[i].mask; i++) { |
Willy Tarreau | 99282dd | 2019-08-30 07:37:32 +0200 | [diff] [blame] | 641 | chunk_appendf(&trash, " %-12s : %c %c %c %c\n", |
Willy Tarreau | 85b1575 | 2019-08-12 16:44:33 +0200 | [diff] [blame] | 642 | src->known_events[i].name, |
| 643 | trace_event_char(src->report_events, src->known_events[i].mask), |
| 644 | trace_event_char(src->start_events, src->known_events[i].mask), |
| 645 | trace_event_char(src->stop_events, src->known_events[i].mask), |
| 646 | trace_event_char(src->pause_events, src->known_events[i].mask)); |
| 647 | } |
| 648 | |
| 649 | trash.area[trash.data] = 0; |
| 650 | return cli_msg(appctx, LOG_WARNING, trash.area); |
| 651 | } |
| 652 | |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 653 | static struct cli_kw_list cli_kws = {{ },{ |
| 654 | { { "trace", NULL }, "trace <module> [cmd [args...]] : manage live tracing", cli_parse_trace, NULL, NULL }, |
Willy Tarreau | 85b1575 | 2019-08-12 16:44:33 +0200 | [diff] [blame] | 655 | { { "show", "trace", NULL }, "show trace [<module>] : show live tracing state", cli_parse_show_trace, NULL, NULL }, |
Willy Tarreau | 864e880 | 2019-08-08 18:48:12 +0200 | [diff] [blame] | 656 | {{},} |
| 657 | }}; |
| 658 | |
| 659 | INITCALL1(STG_REGISTER, cli_register_kw, &cli_kws); |
| 660 | |
Willy Tarreau | 4151c75 | 2019-08-08 18:21:26 +0200 | [diff] [blame] | 661 | /* |
| 662 | * Local variables: |
| 663 | * c-indent-level: 8 |
| 664 | * c-basic-offset: 8 |
| 665 | * End: |
| 666 | */ |