modify sofia debug code to print file, line numbers and function name

This commit is contained in:
Anthony Minessale 2012-10-26 14:15:14 -05:00
parent 28aa2ad291
commit 63e2044a7e
17 changed files with 96 additions and 62 deletions

View File

@ -1 +1 @@
Tue Oct 23 13:13:35 EDT 2012
Fri Oct 26 14:14:41 CDT 2012

View File

@ -744,7 +744,7 @@ void auth_check_digest(auth_mod_t *am,
auth_challenge_digest(am, as, ach);
as->as_blacklist = am->am_blacklist;
}
SU_DEBUG_5(("auth_method_digest: response did not match\n"));
SU_DEBUG_5(("auth_method_digest: response did not match\n" VA_NONE));
return;
}
@ -761,7 +761,7 @@ void auth_check_digest(auth_mod_t *am,
if (am->am_challenge)
auth_challenge_digest(am, as, ach);
SU_DEBUG_7(("auth_method_digest: successful authentication\n"));
SU_DEBUG_7(("auth_method_digest: successful authentication\n" VA_NONE));
as->as_status = 0; /* Successful authentication! */
as->as_phrase = "";
@ -1412,11 +1412,11 @@ int auth_validate_digest_nonce(auth_mod_t *am,
/* Check nonce */
if (!ar->ar_nonce) {
SU_DEBUG_5(("auth_method_digest: no nonce\n"));
SU_DEBUG_5(("auth_method_digest: no nonce\n" VA_NONE));
return -1;
}
if (base64_d((void*)nonce, (sizeof nonce), ar->ar_nonce) != (sizeof nonce)) {
SU_DEBUG_5(("auth_method_digest: too short nonce\n"));
SU_DEBUG_5(("auth_method_digest: too short nonce\n" VA_NONE));
return -1;
}
@ -1426,7 +1426,7 @@ int auth_validate_digest_nonce(auth_mod_t *am,
auth_md5_hmac_digest(am, md5, hmac, sizeof hmac);
if (memcmp(nonce->digest, hmac, sizeof nonce->digest)) {
SU_DEBUG_5(("auth_method_digest: bad nonce\n"));
SU_DEBUG_5(("auth_method_digest: bad nonce\n" VA_NONE));
return -1;
}

View File

@ -424,12 +424,12 @@ nea_server_t *nea_server_create(nta_agent_t *agent,
throttle = min_throttle;
if (!url) {
SU_DEBUG_5(("nea_server_create(): invalid url\n"));
SU_DEBUG_5(("nea_server_create(): invalid url\n" VA_NONE));
return NULL;
}
if (min_expires > expires || expires > max_expires) {
SU_DEBUG_5(("nea_server_create(): invalid expiration range\n"));
SU_DEBUG_5(("nea_server_create(): invalid expiration range\n" VA_NONE));
return NULL;
}

View File

@ -1276,7 +1276,7 @@ void agent_timer(su_root_magic_t *rm, su_timer_t *timer, nta_agent_t *agent)
if (next == latest) {
/* Do not set timer? */
SU_DEBUG_9(("nta: timer not set\n"));
SU_DEBUG_9(("nta: timer not set\n" VA_NONE));
assert(!agent->sa_out.completed->q_head);
assert(!agent->sa_out.trying->q_head);
assert(!agent->sa_out.inv_calling->q_head);
@ -2162,7 +2162,7 @@ int nta_agent_add_tport(nta_agent_t *self,
if (url_string_p(uri))
SU_DEBUG_1(("nta: %s: invalid bind URL\n", uri->us_str));
else
SU_DEBUG_1(("nta: invalid bind URL\n"));
SU_DEBUG_1(("nta: invalid bind URL\n" VA_NONE));
su_seterrno(EINVAL);
return -1;
}
@ -2249,19 +2249,19 @@ int nta_agent_add_tport(nta_agent_t *self,
/* XXX - when to use maddr? */
if ((agent_init_via(self, tport_primaries(self->sa_tports), 0)) < 0) {
error = su_errno();
SU_DEBUG_1(("nta: cannot create Via headers\n"));
SU_DEBUG_1(("nta: cannot create Via headers\n" VA_NONE));
goto error;
}
else
SU_DEBUG_9(("nta: Via fields initialized\n"));
SU_DEBUG_9(("nta: Via fields initialized\n" VA_NONE));
if ((agent_init_contact(self)) < 0) {
error = su_errno();
SU_DEBUG_1(("nta: cannot create Contact header\n"));
SU_DEBUG_1(("nta: cannot create Contact header\n" VA_NONE));
goto error;
}
else
SU_DEBUG_9(("nta: Contact header created\n"));
SU_DEBUG_9(("nta: Contact header created\n" VA_NONE));
su_free(self->sa_home, url);
ta_end(ta);
@ -2286,7 +2286,7 @@ int agent_create_master_transport(nta_agent_t *self, tagi_t *tags)
if (!self->sa_tports)
return -1;
SU_DEBUG_9(("nta: master transport created\n"));
SU_DEBUG_9(("nta: master transport created\n" VA_NONE));
return 0;
}
@ -7713,7 +7713,7 @@ nta_outgoing_t *outgoing_create(nta_agent_t *agent,
home = msg_home(msg);
if (!sip->sip_request || sip_complete_message(msg) < 0) {
SU_DEBUG_3(("nta: outgoing_create: incomplete request\n"));
SU_DEBUG_3(("nta: outgoing_create: incomplete request\n" VA_NONE));
return NULL;
}
@ -7900,7 +7900,7 @@ nta_outgoing_t *outgoing_create(nta_agent_t *agent,
}
}
else {
SU_DEBUG_1(("outgoing_create: ACK without INVITE\n"));
SU_DEBUG_1(("outgoing_create: ACK without INVITE\n" VA_NONE));
assert(!"INVITE found for ACK");
}
}
@ -7987,11 +7987,11 @@ outgoing_prepare_send(nta_outgoing_t *orq)
outgoing_send_via(orq, tp);
}
else if (orq->orq_sips) {
SU_DEBUG_3(("nta outgoing create: no secure transport\n"));
SU_DEBUG_3(("nta outgoing create: no secure transport\n" VA_NONE));
outgoing_reply(orq, SIP_416_UNSUPPORTED_URI, 1);
}
else {
SU_DEBUG_3(("nta outgoing create: no transport protocol\n"));
SU_DEBUG_3(("nta outgoing create: no transport protocol\n" VA_NONE));
outgoing_reply(orq, 503, "No transport", 1);
}
}
@ -8013,7 +8013,7 @@ outgoing_send_via(nta_outgoing_t *orq, tport_t *tp)
if (old_tp) tport_unref(old_tp);
if (outgoing_insert_via(orq, agent_tport_via(tp)) < 0) {
SU_DEBUG_3(("nta outgoing create: cannot insert Via line\n"));
SU_DEBUG_3(("nta outgoing create: cannot insert Via line\n" VA_NONE));
outgoing_reply(orq, 503, "Cannot insert Via", 1);
return;
}
@ -9211,7 +9211,7 @@ int outgoing_recv(nta_outgoing_t *_orq,
if (orq->orq_destroyed && 200 <= status && status < 300) {
if (orq->orq_uas && su_strcasecmp(sip->sip_to->a_tag, orq->orq_tag) != 0) {
/* Orphan 200 Ok to INVITE. ACK and BYE it */
SU_DEBUG_5(("nta: Orphan 200 Ok send ACK&BYE\n"));
SU_DEBUG_5(("nta: Orphan 200 Ok send ACK&BYE\n" VA_NONE));
return nta_msg_ackbye(sa, msg);
}
return -1; /* Proxy statelessly (RFC3261 section 16.11) */
@ -9273,7 +9273,7 @@ int outgoing_recv(nta_outgoing_t *_orq,
return outgoing_duplicate(orq, msg, sip);
/* Orphan 200 Ok to INVITE. ACK and BYE it */
SU_DEBUG_5(("nta: Orphan 200 Ok send ACK&BYE"));
SU_DEBUG_5(("nta: Orphan 200 Ok send ACK&BYE" VA_NONE));
return nta_msg_ackbye(sa, msg);
}
}

View File

@ -911,7 +911,7 @@ int hc_resolve_and_send(nth_client_t * hc)
if (msg_serialize(msg, http) < 0) {
assert(hc->hc_tport);
SU_DEBUG_3(("nth client create: invalid message"));
SU_DEBUG_3(("nth client create: invalid message" VA_NONE));
return -1;
}

View File

@ -312,20 +312,20 @@ nth_site_t *nth_site_create(nth_site_t *parent,
is_path = url->url_path != NULL;
if (is_host && is_path) {
SU_DEBUG_3(("nth_site_create(): virtual host and path simultanously\n"));
SU_DEBUG_3(("nth_site_create(): virtual host and path simultanously\n" VA_NONE));
errno = EINVAL;
goto error;
}
if (!parent && !is_host) {
SU_DEBUG_3(("nth_site_create(): host is required\n"));
SU_DEBUG_3(("nth_site_create(): host is required\n" VA_NONE));
errno = EINVAL;
goto error;
}
if (parent) {
if (!parent->site_isdir) {
SU_DEBUG_3(("nth_site_create(): invalid parent resource \n"));
SU_DEBUG_3(("nth_site_create(): invalid parent resource \n" VA_NONE));
errno = EINVAL;
goto error;
}
@ -995,7 +995,7 @@ static void server_reply(server_t *srv, tport_t *tport,
if (tport_tqsend(tport, response, NULL,
TPTAG_CLOSE_AFTER(close),
TAG_END()) == -1) {
SU_DEBUG_3(("server_reply(): cannot queue response\n"));
SU_DEBUG_3(("server_reply(): cannot queue response\n" VA_NONE));
tport_shutdown(tport, 2);
}

View File

@ -967,7 +967,7 @@ static int nua_register_client_response(nua_client_request_t *cr,
if (tport && tport != nr->nr_tport) {
if (nr->nr_error_report_id) {
if (tport_release(nr->nr_tport, nr->nr_error_report_id, NULL, NULL, nr, 0) < 0)
SU_DEBUG_1(("nua_register: tport_release() failed\n"));
SU_DEBUG_1(("nua_register: tport_release() failed\n" VA_NONE));
nr->nr_error_report_id = 0;
}
tport_unref(nr->nr_tport);
@ -996,7 +996,7 @@ static int nua_register_client_response(nua_client_request_t *cr,
if (nr->nr_tport) {
if (nr->nr_error_report_id) {
if (tport_release(nr->nr_tport, nr->nr_error_report_id, NULL, NULL, nr, 0) < 0)
SU_DEBUG_1(("nua_register: tport_release() failed\n"));
SU_DEBUG_1(("nua_register: tport_release() failed\n" VA_NONE));
nr->nr_error_report_id = 0;
}
@ -1028,7 +1028,7 @@ void nua_register_connection_closed(tp_stack_t *sip_stack,
pending = nr->nr_error_report_id;
if (tport_release(tport, pending, NULL, NULL, nr, 0) < 0)
SU_DEBUG_1(("nua_register: tport_release() failed\n"));
SU_DEBUG_1(("nua_register: tport_release() failed\n" VA_NONE));
nr->nr_error_report_id = 0;
tpn = tport_name(nr->nr_tport);

View File

@ -3039,11 +3039,11 @@ nh_referral_check(nua_handle_t *nh, tagi_t const *tags)
ref->ref_event = sip_event_dup(nh->nh_home, event);
if (!nh_validate(nh->nh_nua, ref_handle)) {
SU_DEBUG_3(("nua: invalid NOTIFY_REFER handle\n"));
SU_DEBUG_3(("nua: invalid NOTIFY_REFER handle\n" VA_NONE));
return -1;
}
else if (!ref->ref_event) {
SU_DEBUG_3(("nua: NOTIFY event missing\n"));
SU_DEBUG_3(("nua: NOTIFY event missing\n" VA_NONE));
return -1;
}

View File

@ -192,7 +192,7 @@ int nua_stack_init(su_root_t *root, nua_t *nua)
dnh->nh_ds->ds_leg == NULL ||
nta_agent_set_params(nua->nua_nta, NTATAG_UA(1), TAG_END()) < 0 ||
nua_stack_init_transport(nua, nua->nua_args) < 0) {
SU_DEBUG_1(("nua: initializing SIP stack failed\n"));
SU_DEBUG_1(("nua: initializing SIP stack failed\n" VA_NONE));
return -1;
}

View File

@ -3596,7 +3596,7 @@ sres_decode_msg(sres_resolver_t *res,
m->m_offset = sizeof(m->m_packet.mp_header);
if (m->m_size < m->m_offset) {
SU_DEBUG_5(("sres_decode_msg: truncated message\n"));
SU_DEBUG_5(("sres_decode_msg: truncated message\n" VA_NONE));
return -1;
}

View File

@ -132,13 +132,13 @@ sres_resolver_create(su_root_t *root,
srs->srs_timer = t;
if (!srs->srs_timer)
SU_DEBUG_3(("sres: cannot create timer\n"));
SU_DEBUG_3(("sres: cannot create timer\n" VA_NONE));
#if nomore
else if (su_timer_set_for_ever(t, sres_sofia_timer, srs) < 0)
SU_DEBUG_3(("sres: cannot set timer\n"));
SU_DEBUG_3(("sres: cannot set timer\n" VA_NONE));
#else
else if (sres_resolver_set_timer_cb(res, sres_sofia_set_timer, srs) < 0)
SU_DEBUG_3(("sres: cannot set timer cb\n"));
SU_DEBUG_3(("sres: cannot set timer cb\n" VA_NONE));
#endif
else
return res; /* Success! */

View File

@ -73,13 +73,17 @@ SOFIA_BEGIN_DECLS
SOFIAPUBVAR su_log_t SU_LOG[];
#endif
#define VA_NONE "%s",""
#define SU_DEBUG_DEF(level) \
su_inline void su_debug_##level(char const *fmt, ...) \
__attribute__ ((__format__ (printf, 1, 2))); \
su_inline void su_debug_##level(char const *fmt, ...) \
{ va_list ap; va_start(ap, fmt); su_vllog(SU_LOG, level, fmt, ap); va_end(ap); }
{ va_list ap; va_start(ap, fmt); su_vllog(SU_LOG, level, fmt, ap); va_end(ap); }
//SU_DEBUG_DEF(0)
#define su_debug_0(_f, ...) su_llog(SU_LOG, 0, _f, __VA_ARGS__)
SU_DEBUG_DEF(0)
/** Log messages at level 0.
*
* Fatal errors and panic messages should be logged at level 0.
@ -100,7 +104,10 @@ SU_DEBUG_DEF(0)
#endif
#if SU_DEBUG_MAX >= 1
SU_DEBUG_DEF(1)
//SU_DEBUG_DEF(1)
#define su_debug_1(_f, ...) su_llog(SU_LOG, 1, _f, __VA_ARGS__)
/**Log messages at level 1.
*
* Critical errors and minimal progress at subsystem level should be logged
@ -114,7 +121,8 @@ SU_DEBUG_DEF(1)
#endif
#if SU_DEBUG_MAX >= 2
SU_DEBUG_DEF(2)
//SU_DEBUG_DEF(2)
#define su_debug_2(_f, ...) su_llog(SU_LOG, 2, _f, __VA_ARGS__)
/**Log messages at level 2.
*
* Non-critical errors should be logged at level 2.
@ -127,7 +135,8 @@ SU_DEBUG_DEF(2)
#endif
#if SU_DEBUG_MAX >= 3
SU_DEBUG_DEF(3)
//SU_DEBUG_DEF(3)
#define su_debug_3(_f, ...) su_llog(SU_LOG, 3, _f, __VA_ARGS__)
/** Log messages at level 3.
*
* Warnings and progress messages should be logged at level 3.
@ -140,7 +149,8 @@ SU_DEBUG_DEF(3)
#endif
#if SU_DEBUG_MAX >= 4
SU_DEBUG_DEF(4)
//SU_DEBUG_DEF(4)
#define su_debug_4(_f, ...) su_llog(SU_LOG, 4, _f, __VA_ARGS__)
/** Log messages at level 4. */
#define SU_DEBUG_4(x) (SU_LOG_LEVEL >= 4 ? (su_debug_4 x) : (void)0)
#else
@ -148,7 +158,8 @@ SU_DEBUG_DEF(4)
#endif
#if SU_DEBUG_MAX >= 5
SU_DEBUG_DEF(5)
//SU_DEBUG_DEF(5)
#define su_debug_5(_f, ...) su_llog(SU_LOG, 5, _f, __VA_ARGS__)
/** Log messages at level 5.
*
* Signaling protocol actions (incoming packets, etc.) should be logged
@ -162,7 +173,8 @@ SU_DEBUG_DEF(5)
#endif
#if SU_DEBUG_MAX >= 6
SU_DEBUG_DEF(6)
//SU_DEBUG_DEF(6)
#define su_debug_6(_f, ...) su_llog(SU_LOG, 6, _f, __VA_ARGS__)
/** Log messages at level 6. */
#define SU_DEBUG_6(x) (SU_LOG_LEVEL >= 6 ? (su_debug_6 x) : (void)0)
#else
@ -170,7 +182,8 @@ SU_DEBUG_DEF(6)
#endif
#if SU_DEBUG_MAX >= 7
SU_DEBUG_DEF(7)
//SU_DEBUG_DEF(7)
#define su_debug_7(_f, ...) su_llog(SU_LOG, 7, _f, __VA_ARGS__)
/** Log messages at level 7.
*
* Media protocol actions (incoming packets, etc) should be logged at level 7.
@ -183,7 +196,8 @@ SU_DEBUG_DEF(7)
#endif
#if SU_DEBUG_MAX >= 8
SU_DEBUG_DEF(8)
//SU_DEBUG_DEF(8)
#define su_debug_8(_f, ...) su_llog(SU_LOG, 8, _f, __VA_ARGS__)
/** Log messages at level 8. */
#define SU_DEBUG_8(x) (SU_LOG_LEVEL >= 8 ? (su_debug_8 x) : (void)0)
#else
@ -191,7 +205,8 @@ SU_DEBUG_DEF(8)
#endif
#if SU_DEBUG_MAX >= 9
SU_DEBUG_DEF(9)
//SU_DEBUG_DEF(9)
#define su_debug_9(_f, ...) su_llog(SU_LOG, 9, _f, __VA_ARGS__)
/** Log messages at level 9.
*
* Entering/exiting functions, very verbatim progress should be logged at

View File

@ -52,6 +52,15 @@ typedef struct su_log_s su_log_t;
SOFIA_BEGIN_DECLS
#ifdef _MSC_VER
#define __SOFIA_FUNC__ __FUNCTION__
#else
#define __SOFIA_FUNC__ (const char *)__func__
#endif
/** Prototype for logging function */
typedef void (su_logger_f)(void *stream, char const *fmt, va_list ap);
@ -77,9 +86,9 @@ enum { SU_LOG_MAX = 9 };
SOFIAPUBFUN void su_log(char const *fmt, ...)
__attribute__ ((__format__ (printf, 1, 2)));
SOFIAPUBFUN void su_llog(su_log_t *log, unsigned level, char const *fmt, ...)
__attribute__ ((__format__ (printf, 3, 4)));
SOFIAPUBFUN void su_vllog(su_log_t *log, unsigned level,
SOFIAPUBFUN void _su_llog(su_log_t *log, unsigned level, const char *file, const char *func, int line, char const *fmt, ...)
__attribute__ ((__format__ (printf, 6, 7)));
SOFIAPUBFUN void _su_vllog(su_log_t *log, unsigned level, const char *file, const char *func, int line,
char const *fmt, va_list ap);
SOFIAPUBFUN void su_log_redirect(su_log_t *log, su_logger_f *f, void *stream);
SOFIAPUBFUN void su_log_set_level(su_log_t *log, unsigned level);
@ -92,6 +101,9 @@ SOFIAPUBVAR su_log_t su_log_global[];
/** Log the latest su error message */
SOFIAPUBFUN void su_perror(char const *s);
#define su_llog(_l, _ll, _f, ...) _su_llog(_l, _ll, __FILE__, __SOFIA_FUNC__, __LINE__, _f, __VA_ARGS__)
#define su_vllog(_l, _ll, _f, ...) _su_vllog(_l, _ll, __FILE__, __SOFIA_FUNC__, __LINE__, _f, __VA_ARGS__)
/** Log the su error message. */
SOFIAPUBFUN void su_perror2(char const *s, int errcode);

View File

@ -1260,7 +1260,7 @@ int bsd_localinfo(su_localinfo_t const hints[1],
flags |= LI_NUMERIC;
if (!(li = calloc(1, sizeof(*li) + sulen + ifnamelen))) {
SU_DEBUG_1(("su_getlocalinfo: memory exhausted\n"));
SU_DEBUG_1(("su_getlocalinfo: memory exhausted\n" VA_NONE));
error = ELI_MEMORY;
break;
}
@ -1629,7 +1629,7 @@ int li_name(su_localinfo_t const *hints,
if (error) {
if ((flags & LI_NAMEREQD) == LI_NAMEREQD)
return 1;
SU_DEBUG_7(("li_name: getnameinfo() failed\n"));
SU_DEBUG_7(("li_name: getnameinfo() failed\n" VA_NONE));
if (!su_inet_ntop(su->su_family, SU_ADDR(su), name, sizeof name))
return ELI_RESOLVER;
}

View File

@ -100,17 +100,23 @@ void su_log(char const *fmt, ...)
*
* @note This function is used mainly by SU_DEBUG_n() macros.
*/
void su_llog(su_log_t *log, unsigned level, char const *fmt, ...)
void _su_llog(su_log_t *log, unsigned level, const char *file, const char *func, int line,
char const *fmt, ...)
{
va_list ap;
char buf[512];
va_start(ap, fmt);
su_vllog(log, level, fmt, ap);
snprintf(buf, sizeof(buf), "%s:%d %s() %s", file, line, func, fmt);
_su_vllog(log, level, file, func, line, buf, ap);
va_end(ap);
}
/** Log a message with level (stdarg version). */
void su_vllog(su_log_t *log, unsigned level, char const *fmt, va_list ap)
void _su_vllog(su_log_t *log, unsigned level, const char *file, const char *func, int line,
char const *fmt, va_list ap)
{
su_logger_f *logger;
void *stream;
@ -133,8 +139,9 @@ void su_vllog(su_log_t *log, unsigned level, char const *fmt, va_list ap)
stream = su_log_default->log_stream;
}
if (logger)
logger(stream, fmt, ap);
if (logger) {
logger(stream, fmt, ap);
}
}
static char const not_initialized[1];

View File

@ -3350,7 +3350,7 @@ tport_t *tport_tsend(tport_t *self,
if (!self) {
msg_set_errno(msg, su_errno());
SU_DEBUG_9(("tport_socket failed in tsend\n"));
SU_DEBUG_9(("tport_socket failed in tsend\n" VA_NONE));
return NULL;
}
@ -3406,7 +3406,7 @@ int tport_prepare_and_send(tport_t *self, msg_t *msg,
/* ...or we are connecting */
(self->tp_events & (SU_WAIT_CONNECT | SU_WAIT_OUT))) {
if (tport_queue(self, msg) < 0) {
SU_DEBUG_9(("tport_queue failed in tsend\n"));
SU_DEBUG_9(("tport_queue failed in tsend\n" VA_NONE));
return -1;
}
return 0;

View File

@ -201,7 +201,7 @@ static tport_t *tport_http_connect(tport_primary_t *pri, su_addrinfo_t *ai,
msg_set_next(response, thci->thci_stackmsg = tport_msg_alloc(tport, 512));
if (tport_send_msg(tport, msg, tpn, NULL) < 0) {
SU_DEBUG_9(("tport_send_msg failed in tpot_http_connect\n"));
SU_DEBUG_9(("tport_send_msg failed in tpot_http_connect\n" VA_NONE));
msg_destroy(msg);
tport_zap_secondary(tport);
return NULL;