diff --git a/daemon/call.c b/daemon/call.c index c18c7f795..159383e92 100644 --- a/daemon/call.c +++ b/daemon/call.c @@ -266,7 +266,7 @@ delete: out: rwlock_unlock_r(&rtpe_config.config_lock); rwlock_unlock_r(&c->master_lock); - log_info_clear(); + log_info_pop(); } void xmlrpc_kill_calls(void *p) { @@ -489,7 +489,7 @@ destroy: call_destroy(ca); obj_put(ca); list = g_slist_delete_link(list, list); - log_info_clear(); + log_info_pop(); if (dup_tags) g_hash_table_destroy(dup_tags); diff --git a/daemon/cli.c b/daemon/cli.c index 422043def..c67808958 100644 --- a/daemon/cli.c +++ b/daemon/cli.c @@ -1237,7 +1237,7 @@ static void cli_stream_readable(struct streambuf_stream *s) { free(inbuf); streambuf_stream_shutdown(s); - log_info_clear(); + log_info_reset(); } void cli_handle(str *instr, struct cli_writer *cw) { diff --git a/daemon/codec.c b/daemon/codec.c index 3f2920135..814e6fa5d 100644 --- a/daemon/codec.c +++ b/daemon/codec.c @@ -922,7 +922,7 @@ static void __rtcp_timer_run(struct codec_timer *ct) { } out: - log_info_clear(); + log_info_pop(); } // master lock held in W static void __codec_rtcp_timer(struct call_media *receiver) { @@ -1358,8 +1358,10 @@ static void __mqtt_timer_run(struct codec_timer *ct) { struct mqtt_timer *mqt = (struct mqtt_timer *) ct; struct call *call = mqt->call; - if (call) + if (call) { rwlock_lock_w(&call->master_lock); + log_info_call(call); + } if (!*mqt->self) { if (call) @@ -1375,7 +1377,8 @@ static void __mqtt_timer_run(struct codec_timer *ct) { mqtt_timer_run(call, mqt->media); out: - log_info_clear(); + if (call) + log_info_pop(); } static void __codec_mqtt_timer_schedule(struct mqtt_timer *mqt) { timeval_add_usec(&mqt->ct.next, rtpe_config.mqtt_publish_interval * 1000); @@ -2732,11 +2735,10 @@ out: if (call) { rwlock_unlock_r(&call->master_lock); obj_put(call); + log_info_pop(); } if (dframe) delay_frame_free(dframe); - - log_info_clear(); } @@ -3041,8 +3043,10 @@ static void __dtx_send_later(struct codec_timer *ct) { rwlock_unlock_r(&call->master_lock); out: - if (call) + if (call) { obj_put(call); + log_info_pop(); + } if (ch) obj_put(&ch->h); if (input_ch) @@ -3050,7 +3054,6 @@ out: if (dtxp) dtx_packet_free(dtxp); media_packet_release(&mp_copy); - log_info_clear(); } static void __dtx_shutdown(struct dtx_buffer *dtxb) { if (dtxb->csh) @@ -4768,7 +4771,7 @@ static void __codec_timer_callback_fire(struct codec_timer *ct) { log_info_call(cb->call); cb->func(cb->call, cb->ptr); codec_timer_stop(&ct); - log_info_clear(); + log_info_pop(); } void codec_timer_callback(struct call *c, void (*func)(struct call *, void *), void *p, uint64_t delay) { struct timer_callback *cb = obj_alloc0("codec_timer_callback", sizeof(*cb), __codec_timer_callback_free); diff --git a/daemon/control_ng.c b/daemon/control_ng.c index 9fa31f0ac..6d3c02b2e 100644 --- a/daemon/control_ng.c +++ b/daemon/control_ng.c @@ -398,7 +398,7 @@ send_only: out: ng_buffer_release(ngbuf); - log_info_clear(); + log_info_pop(); return funcret; } diff --git a/daemon/control_tcp.c b/daemon/control_tcp.c index f7513d1eb..9c50bb46e 100644 --- a/daemon/control_tcp.c +++ b/daemon/control_tcp.c @@ -108,7 +108,7 @@ static int control_stream_parse(struct streambuf_stream *s, char *line) { } pcre_free(out); - log_info_clear(); + log_info_pop(); return 1; } diff --git a/daemon/control_udp.c b/daemon/control_udp.c index e4e33c16c..a48fb7fc6 100644 --- a/daemon/control_udp.c +++ b/daemon/control_udp.c @@ -130,7 +130,7 @@ static void control_udp_incoming(struct obj *obj, struct udp_buffer *udp_buf) { out: pcre_free(out); - log_info_clear(); + log_info_pop(); } void control_udp_free(void *p) { diff --git a/daemon/ice.c b/daemon/ice.c index d538ffe4b..5f81efa81 100644 --- a/daemon/ice.c +++ b/daemon/ice.c @@ -1322,7 +1322,7 @@ static void ice_agents_timer_run(void *ptr) { __do_ice_checks(ag); /* finally, release our reference and start over */ - log_info_clear(); + log_info_pop(); rwlock_unlock_r(&call->master_lock); } diff --git a/daemon/log.c b/daemon/log.c index 8e0cac068..9667591d3 100644 --- a/daemon/log.c +++ b/daemon/log.c @@ -14,6 +14,7 @@ __thread struct log_info log_info; +__thread GSList *log_info_stack; int _log_facility_cdr = 0; int _log_facility_rtcp = 0; diff --git a/daemon/log.h b/daemon/log.h index 376d27eb7..5f9d5263a 100644 --- a/daemon/log.h +++ b/daemon/log.h @@ -37,6 +37,7 @@ extern int _log_facility_dtmf; extern __thread struct log_info log_info; +extern __thread GSList *log_info_stack; diff --git a/daemon/log_funcs.h b/daemon/log_funcs.h index cfea369e1..3d8992e28 100644 --- a/daemon/log_funcs.h +++ b/daemon/log_funcs.h @@ -8,58 +8,90 @@ #include "ice.h" #include "log.h" -INLINE void log_info_clear(void) { - switch (log_info.e) { +INLINE void __log_info_release(struct log_info *li) { + switch (li->e) { case LOG_INFO_NONE: return; case LOG_INFO_CALL: - obj_put(log_info.u.call); + obj_put(li->u.call); break; case LOG_INFO_STREAM_FD: - obj_put(log_info.u.stream_fd); + obj_put(li->u.stream_fd); break; case LOG_INFO_ICE_AGENT: - obj_put(&log_info.u.ice_agent->tt_obj); + obj_put(&li->u.ice_agent->tt_obj); 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_push(void) { + struct log_info *copy = g_slice_alloc(sizeof(*copy)); + *copy = log_info; + log_info_stack = g_slist_prepend(log_info_stack, copy); + ZERO(log_info); +} + +// should be paired with any invocation of log_info_X() +INLINE void log_info_pop(void) { + __log_info_release(&log_info); + + if (!log_info_stack) { + ZERO(log_info); + return; + } + + struct log_info *next = log_info_stack->data; + log_info = *next; + g_slice_free1(sizeof(*next), next); + log_info_stack = g_slist_delete_link(log_info_stack, log_info_stack); +} +// clears current log context and entire stack +INLINE void log_info_reset(void) { + __log_info_release(&log_info); + ZERO(log_info); + + while (log_info_stack) { + struct log_info *element = log_info_stack->data; + __log_info_release(element); + g_slice_free1(sizeof(*element), element); + log_info_stack = g_slist_delete_link(log_info_stack, log_info_stack); + } +} + INLINE void log_info_call(struct call *c) { - log_info_clear(); if (!c) return; + __log_info_push(); log_info.e = LOG_INFO_CALL; log_info.u.call = obj_get(c); } INLINE void log_info_stream_fd(struct stream_fd *sfd) { - log_info_clear(); if (!sfd) return; + __log_info_push(); log_info.e = LOG_INFO_STREAM_FD; log_info.u.stream_fd = obj_get(sfd); } INLINE void log_info_str(const str *s) { - log_info_clear(); if (!s || !s->s) return; + __log_info_push(); 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_push(); log_info.e = LOG_INFO_C_STRING; log_info.u.cstr = s; } INLINE void log_info_ice_agent(struct ice_agent *ag) { - log_info_clear(); if (!ag) return; + __log_info_push(); log_info.e = LOG_INFO_ICE_AGENT; log_info.u.ice_agent = obj_get(&ag->tt_obj); } diff --git a/daemon/media_player.c b/daemon/media_player.c index 81b9d5596..251d175bb 100644 --- a/daemon/media_player.c +++ b/daemon/media_player.c @@ -236,7 +236,7 @@ static void send_timer_send_lock(struct send_timer *st, struct codec_packet *cp) __send_timer_send_common(st, cp); rwlock_unlock_r(&call->master_lock); - log_info_clear(); + log_info_pop(); } // st->stream->out_lock (or call->master_lock/W) must be held already @@ -249,7 +249,7 @@ static void send_timer_send_nolock(struct send_timer *st, struct codec_packet *c __send_timer_send_common(st, cp); - log_info_clear(); + log_info_pop(); } @@ -737,7 +737,7 @@ static void media_player_run(void *ptr) { mutex_unlock(&mp->lock); rwlock_unlock_r(&call->master_lock); - log_info_clear(); + log_info_pop(); } #endif diff --git a/daemon/media_socket.c b/daemon/media_socket.c index 4496b231e..edf1e40c3 100644 --- a/daemon/media_socket.c +++ b/daemon/media_socket.c @@ -2622,7 +2622,7 @@ strike: redis_update_onekey(ca, rtpe_redis_write); } done: - log_info_clear(); + log_info_pop(); } diff --git a/daemon/mqtt.c b/daemon/mqtt.c index 0d4c32666..8e310c9b5 100644 --- a/daemon/mqtt.c +++ b/daemon/mqtt.c @@ -458,6 +458,7 @@ void mqtt_timer_run(struct call *call, struct call_media *media) { mqtt_media_stats(media, json); rwlock_unlock_r(&call->master_lock); + log_info_pop(); } json_builder_end_object(json); diff --git a/daemon/poller.c b/daemon/poller.c index 8702e9dd4..c717707fa 100644 --- a/daemon/poller.c +++ b/daemon/poller.c @@ -19,6 +19,7 @@ #include "aux.h" #include "obj.h" +#include "log_funcs.h" @@ -365,6 +366,7 @@ static void poller_timers_run(struct poller *p) { for (l = p->timers; l; l = l->next) { ti = l->data; ti->func(ti->obj_ptr); + log_info_reset(); } mutex_lock(&p->timers_add_del_lock); @@ -443,6 +445,7 @@ int poller_poll(struct poller *p, int timeout) { next: obj_put(it); + log_info_reset(); mutex_lock(&p->lock); } diff --git a/daemon/redis.c b/daemon/redis.c index 96ba95535..77d9aedf5 100644 --- a/daemon/redis.c +++ b/daemon/redis.c @@ -407,13 +407,11 @@ void on_redis_notification(redisAsyncContext *actx, void *reply, void *privdata) } err: - if (c) { - // because of call_get(..) + if (c) // because of call_get(..) obj_put(c); - log_info_clear(); - } mutex_unlock(&r->lock); + log_info_reset(); } void redis_delete_async_context_connect(const redisAsyncContext *redis_delete_async_context, int status) { @@ -2000,7 +1998,7 @@ err1: } if (c) obj_put(c); - log_info_clear(); + log_info_reset(); } struct thread_ctx { diff --git a/daemon/timerthread.c b/daemon/timerthread.c index bc8fc4c4e..28d837383 100644 --- a/daemon/timerthread.c +++ b/daemon/timerthread.c @@ -1,5 +1,6 @@ #include "timerthread.h" #include "aux.h" +#include "log_funcs.h" static int tt_obj_cmp(const void *a, const void *b) { @@ -61,6 +62,8 @@ void timerthread_run(void *p) { tt->func(tt_obj); obj_put(tt_obj); + log_info_reset(); + mutex_lock(&tt->lock); continue; diff --git a/t/log_funcs.h b/t/log_funcs.h index fdb0048b3..5ce34a8a1 100644 --- a/t/log_funcs.h +++ b/t/log_funcs.h @@ -8,7 +8,9 @@ struct call; struct stream_fd; struct ice_agent; -INLINE void log_info_clear(void) { +INLINE void log_info_reset(void) { +} +INLINE void log_info_pop(void) { } INLINE void log_info_call(struct call *c) { }