diff --git a/daemon/call.c b/daemon/call.c index f386c47fa..8701dcf2b 100644 --- a/daemon/call.c +++ b/daemon/call.c @@ -2978,8 +2978,7 @@ static void __call_free(void *p) { static struct call *call_create(const str *callid, struct callmaster *m) { struct call *c; - ilog(LOG_NOTICE, "["STR_FORMAT"] Creating new call", - STR_FMT(callid)); + ilog(LOG_NOTICE, "Creating new call"); c = obj_alloc0("call", sizeof(*c), __call_free); c->callmaster = m; mutex_init(&c->buffer_lock); @@ -3231,7 +3230,7 @@ int call_delete_branch(struct callmaster *m, const str *callid, const str *branc c = call_get(callid, m); if (!c) { - ilog(LOG_INFO, "["STR_FORMAT"] Call-ID to delete not found", STR_FMT(callid)); + ilog(LOG_INFO, "Call-ID to delete not found"); goto err; } diff --git a/daemon/control_ng.c b/daemon/control_ng.c index dcee3c4f5..ed5fcf8b0 100644 --- a/daemon/control_ng.c +++ b/daemon/control_ng.c @@ -76,7 +76,7 @@ static void control_ng_incoming(struct obj *obj, str *buf, struct sockaddr_in6 * struct control_ng *c = (void *) obj; bencode_buffer_t bencbuf; bencode_item_t *dict, *resp; - str cmd, cookie, data, reply, *to_send; + str cmd, cookie, data, reply, *to_send, callid; const char *errstr; struct msghdr mh; struct iovec iov[3]; @@ -119,11 +119,18 @@ static void control_ng_incoming(struct obj *obj, str *buf, struct sockaddr_in6 * if (!cmd.s) goto err_send; - log_str = g_string_sized_new(256); - g_string_append_printf(log_str, "Got valid command from %s: %.*s - ", addr, STR_FMT(&cmd)); - pretty_print(dict, log_str); - ilog(LOG_INFO, "%.*s", (int) log_str->len, log_str->str); - g_string_free(log_str, TRUE); + bencode_dictionary_get_str(dict, "call-id", &callid); + log_info_str(&callid); + + ilog(LOG_INFO, "Received command '"STR_FORMAT"' from %s", STR_FMT(&cmd), addr); + + if (get_log_level() >= LOG_DEBUG) { + log_str = g_string_sized_new(256); + g_string_append_printf(log_str, "Dump for '"STR_FORMAT"' from %s: ", STR_FMT(&cmd), addr); + pretty_print(dict, log_str); + ilog(LOG_DEBUG, "%.*s", (int) log_str->len, log_str->str); + g_string_free(log_str, TRUE); + } errstr = NULL; if (!str_cmp(&cmd, "ping")) { @@ -165,15 +172,29 @@ err_send: bencode_dictionary_add_string(resp, "result", "error"); bencode_dictionary_add_string(resp, "error-reason", errstr); g_atomic_int_inc(&cur->errors); - goto send_resp; + cmd = STR_NULL; send_resp: bencode_collapse_str(resp, &reply); to_send = &reply; -send_only: - ilog(LOG_INFO, "Returning to SIP proxy: "STR_FORMAT, STR_FMT(to_send)); + if (cmd.s) { + ilog(LOG_INFO, "Replying to '"STR_FORMAT"' from %s", STR_FMT(&cmd), addr); + + if (get_log_level() >= LOG_DEBUG) { + dict = bencode_decode_expect_str(&bencbuf, to_send, BENCODE_DICTIONARY); + if (dict) { + log_str = g_string_sized_new(256); + g_string_append_printf(log_str, "Response dump for '"STR_FORMAT"' to %s: ", + STR_FMT(&cmd), addr); + pretty_print(dict, log_str); + ilog(LOG_DEBUG, "%.*s", (int) log_str->len, log_str->str); + g_string_free(log_str, TRUE); + } + } + } +send_only: ZERO(mh); mh.msg_name = sin; mh.msg_namelen = sizeof(*sin); diff --git a/daemon/control_tcp.c b/daemon/control_tcp.c index 1a707aacb..06ff565dd 100644 --- a/daemon/control_tcp.c +++ b/daemon/control_tcp.c @@ -115,6 +115,12 @@ static int control_stream_parse(struct control_stream *s, char *line) { pcre_get_substring_list(line, ovec, ret, (const char ***) &out); + if (out[RE_TCP_RL_CALLID]) + log_info_c_string(out[RE_TCP_RL_CALLID]); + else if (out[RE_TCP_D_CALLID]) + log_info_c_string(out[RE_TCP_D_CALLID]); + + if (!strcmp(out[RE_TCP_RL_CMD], "request")) output = call_request_tcp(out, c->callmaster); else if (!strcmp(out[RE_TCP_RL_CMD], "lookup")) diff --git a/daemon/control_udp.c b/daemon/control_udp.c index 1e4f3b214..0fcf218ed 100644 --- a/daemon/control_udp.c +++ b/daemon/control_udp.c @@ -82,6 +82,11 @@ static void control_udp_incoming(struct obj *obj, str *buf, struct sockaddr_in6 goto out; } + if (out[RE_UDP_UL_CALLID]) + log_info_c_string(out[RE_UDP_UL_CALLID]); + else if (out[RE_UDP_DQ_CALLID]) + log_info_c_string(out[RE_UDP_DQ_CALLID]); + if (chrtoupper(out[RE_UDP_UL_CMD][0]) == 'U') reply = call_update_udp(out, u->callmaster, addr, sin); else if (chrtoupper(out[RE_UDP_UL_CMD][0]) == 'L') diff --git a/daemon/log.c b/daemon/log.c index f8e4b6854..adfdcf750 100644 --- a/daemon/log.c +++ b/daemon/log.c @@ -116,6 +116,13 @@ void __ilog(int prio, const char *fmt, ...) { STR_FMT(&log_info.u.stream_fd->call->callid), log_info.u.stream_fd->fd.localport); break; + case LOG_INFO_STR: + snprintf(prefix, sizeof(prefix), "["STR_FORMAT"] ", + STR_FMT(log_info.u.str)); + break; + case LOG_INFO_C_STRING: + snprintf(prefix, sizeof(prefix), "[%s] ", log_info.u.cstr); + break; } va_start(ap, fmt); @@ -127,6 +134,9 @@ void __ilog(int prio, const char *fmt, ...) { return; } + while (ret > 0 && msg[ret-1] == '\n') + ret--; + if ((prio & LOG_FLAG_LIMIT)) { time_t when; struct log_limiter_entry lle, *llep; @@ -168,7 +178,7 @@ void __ilog(int prio, const char *fmt, ...) { infix = "... "; } - write_log(xprio, "%s%s%s", prefix, infix, piece); + write_log(xprio, "%s%s%.*s", prefix, infix, ret, piece); out: free(msg); diff --git a/daemon/log.h b/daemon/log.h index 73d49ec23..8ee9e9081 100644 --- a/daemon/log.h +++ b/daemon/log.h @@ -5,18 +5,24 @@ #include #include #include "compat.h" +#include "str.h" struct log_info { union { - struct call *call; - struct stream_fd *stream_fd; + const struct call *call; + const struct stream_fd *stream_fd; + const str *str; + const char *cstr; + const void *ptr; } u; enum { LOG_INFO_NONE = 0, LOG_INFO_CALL, LOG_INFO_STREAM_FD, + LOG_INFO_STR, + LOG_INFO_C_STRING, } e; }; @@ -75,23 +81,41 @@ INLINE void log_info_clear() { case LOG_INFO_STREAM_FD: __obj_put((void *) log_info.u.stream_fd); break; + case LOG_INFO_STR: + case LOG_INFO_C_STRING: + break; } log_info.e = LOG_INFO_NONE; + log_info.u.ptr = NULL; } -INLINE void log_info_call(struct call *c) { +INLINE void log_info_call(const struct call *c) { log_info_clear(); if (!c) return; log_info.e = LOG_INFO_CALL; log_info.u.call = __obj_get((void *) c); } -INLINE void log_info_stream_fd(struct stream_fd *sfd) { +INLINE void log_info_stream_fd(const struct stream_fd *sfd) { log_info_clear(); if (!sfd) return; log_info.e = LOG_INFO_STREAM_FD; log_info.u.stream_fd = __obj_get((void *) sfd); } +INLINE void log_info_str(const str *s) { + log_info_clear(); + if (!s || !s->s) + return; + log_info.e = LOG_INFO_STR; + log_info.u.str = s; +} +INLINE void log_info_c_string(const char *s) { + log_info_clear(); + if (!s) + return; + log_info.e = LOG_INFO_C_STRING; + log_info.u.cstr = s; +} INLINE int get_log_level(void) { return g_atomic_int_get(&log_level); }