res_pjsip_outbound_registration: Add debugging messages.
When problems occur regarding outbound registrations, it currently is difficult to debug. Most off-nominal paths had warning messages, but sometimes we want to know what's going on before hitting the off-nominal path. This patch adds lots of debugging output that should give a clearer picture of what is happening with regards to outbound registrations. ASTERISK-25020 Reported by Mark Michelson Change-Id: I577bde7860be0a6c872b5bcb4d5047340bf45d45
This commit is contained in:
parent
d7f4788341
commit
f47fed2e12
|
@ -479,10 +479,18 @@ static int handle_client_registration(void *data)
|
||||||
static void sip_outbound_registration_timer_cb(pj_timer_heap_t *timer_heap, struct pj_timer_entry *entry)
|
static void sip_outbound_registration_timer_cb(pj_timer_heap_t *timer_heap, struct pj_timer_entry *entry)
|
||||||
{
|
{
|
||||||
struct sip_outbound_registration_client_state *client_state = entry->user_data;
|
struct sip_outbound_registration_client_state *client_state = entry->user_data;
|
||||||
|
pjsip_regc_info info;
|
||||||
|
|
||||||
|
pjsip_regc_get_info(client_state->client, &info);
|
||||||
|
ast_debug(1, "Attempting scheduled outbound registration attempt to server '%.*s' from client '%.*s'\n",
|
||||||
|
(int) info.server_uri.slen, info.server_uri.ptr,
|
||||||
|
(int) info.client_uri.slen, info.client_uri.ptr);
|
||||||
|
|
||||||
ao2_ref(client_state, +1);
|
ao2_ref(client_state, +1);
|
||||||
if (ast_sip_push_task(client_state->serializer, handle_client_registration, client_state)) {
|
if (ast_sip_push_task(client_state->serializer, handle_client_registration, client_state)) {
|
||||||
ast_log(LOG_WARNING, "Failed to pass outbound registration to threadpool\n");
|
ast_log(LOG_WARNING, "Scheduled outbound registration to server '%.*s' from client '%.*s' could not be executed\n",
|
||||||
|
(int) info.server_uri.slen, info.server_uri.ptr,
|
||||||
|
(int) info.client_uri.slen, info.client_uri.ptr);
|
||||||
ao2_ref(client_state, -1);
|
ao2_ref(client_state, -1);
|
||||||
}
|
}
|
||||||
ao2_ref(client_state, -1);
|
ao2_ref(client_state, -1);
|
||||||
|
@ -494,12 +502,21 @@ static void sip_outbound_registration_timer_cb(pj_timer_heap_t *timer_heap, stru
|
||||||
static void schedule_registration(struct sip_outbound_registration_client_state *client_state, unsigned int seconds)
|
static void schedule_registration(struct sip_outbound_registration_client_state *client_state, unsigned int seconds)
|
||||||
{
|
{
|
||||||
pj_time_val delay = { .sec = seconds, };
|
pj_time_val delay = { .sec = seconds, };
|
||||||
|
pjsip_regc_info info;
|
||||||
|
|
||||||
cancel_registration(client_state);
|
cancel_registration(client_state);
|
||||||
|
|
||||||
|
pjsip_regc_get_info(client_state->client, &info);
|
||||||
|
ast_debug(1, "Scheduling outbound registration to server '%.*s' from client '%.*s' in %d seconds\n",
|
||||||
|
(int) info.server_uri.slen, info.server_uri.ptr,
|
||||||
|
(int) info.client_uri.slen, info.client_uri.ptr,
|
||||||
|
seconds);
|
||||||
|
|
||||||
ao2_ref(client_state, +1);
|
ao2_ref(client_state, +1);
|
||||||
if (pjsip_endpt_schedule_timer(ast_sip_get_pjsip_endpoint(), &client_state->timer, &delay) != PJ_SUCCESS) {
|
if (pjsip_endpt_schedule_timer(ast_sip_get_pjsip_endpoint(), &client_state->timer, &delay) != PJ_SUCCESS) {
|
||||||
ast_log(LOG_WARNING, "Failed to pass timed registration to scheduler\n");
|
ast_log(LOG_WARNING, "Failed to schedule registration to server '%.*s' from client '%.*s'\n",
|
||||||
|
(int) info.server_uri.slen, info.server_uri.ptr,
|
||||||
|
(int) info.client_uri.slen, info.client_uri.ptr);
|
||||||
ao2_ref(client_state, -1);
|
ao2_ref(client_state, -1);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
@ -611,14 +628,19 @@ static int handle_registration_response(void *data)
|
||||||
pjsip_regc_info info;
|
pjsip_regc_info info;
|
||||||
char server_uri[PJSIP_MAX_URL_SIZE], client_uri[PJSIP_MAX_URL_SIZE];
|
char server_uri[PJSIP_MAX_URL_SIZE], client_uri[PJSIP_MAX_URL_SIZE];
|
||||||
|
|
||||||
if (response->client_state->status == SIP_REGISTRATION_STOPPED) {
|
|
||||||
return 0;
|
|
||||||
}
|
|
||||||
|
|
||||||
pjsip_regc_get_info(response->client_state->client, &info);
|
pjsip_regc_get_info(response->client_state->client, &info);
|
||||||
ast_copy_pj_str(server_uri, &info.server_uri, sizeof(server_uri));
|
ast_copy_pj_str(server_uri, &info.server_uri, sizeof(server_uri));
|
||||||
ast_copy_pj_str(client_uri, &info.client_uri, sizeof(client_uri));
|
ast_copy_pj_str(client_uri, &info.client_uri, sizeof(client_uri));
|
||||||
|
|
||||||
|
if (response->client_state->status == SIP_REGISTRATION_STOPPED) {
|
||||||
|
ast_debug(1, "Not handling registration response from '%s' (transaction %s). Registration already stopped\n",
|
||||||
|
server_uri, response->tsx ? response->tsx->obj_name : "<none>");
|
||||||
|
return 0;
|
||||||
|
}
|
||||||
|
|
||||||
|
ast_debug(1, "Processing REGISTER response %d from '%s' (transaction %s)\n",
|
||||||
|
response->code, server_uri, response->tsx ? response->tsx->obj_name : "<none>");
|
||||||
|
|
||||||
if (!response->client_state->auth_attempted &&
|
if (!response->client_state->auth_attempted &&
|
||||||
(response->code == 401 || response->code == 407)) {
|
(response->code == 401 || response->code == 407)) {
|
||||||
pjsip_tx_data *tdata;
|
pjsip_tx_data *tdata;
|
||||||
|
@ -626,11 +648,16 @@ static int handle_registration_response(void *data)
|
||||||
response->rdata, response->tsx, &tdata)) {
|
response->rdata, response->tsx, &tdata)) {
|
||||||
ao2_ref(response->client_state, +1);
|
ao2_ref(response->client_state, +1);
|
||||||
response->client_state->auth_attempted = 1;
|
response->client_state->auth_attempted = 1;
|
||||||
|
ast_debug(1, "Sending authenticated REGISTER to server '%s' from client '%s'\n",
|
||||||
|
server_uri, client_uri);
|
||||||
if (pjsip_regc_send(response->client_state->client, tdata) != PJ_SUCCESS) {
|
if (pjsip_regc_send(response->client_state->client, tdata) != PJ_SUCCESS) {
|
||||||
response->client_state->auth_attempted = 0;
|
response->client_state->auth_attempted = 0;
|
||||||
ao2_cleanup(response->client_state);
|
ao2_cleanup(response->client_state);
|
||||||
}
|
}
|
||||||
return 0;
|
return 0;
|
||||||
|
} else {
|
||||||
|
ast_log(LOG_WARNING, "Failed to create authenticated REGISTER request to server '%s' from client '%s'\n",
|
||||||
|
server_uri, client_uri);
|
||||||
}
|
}
|
||||||
/* Otherwise, fall through so the failure is processed appropriately */
|
/* Otherwise, fall through so the failure is processed appropriately */
|
||||||
}
|
}
|
||||||
|
@ -700,6 +727,7 @@ static void sip_outbound_registration_response_cb(struct pjsip_regc_cbparam *par
|
||||||
{
|
{
|
||||||
RAII_VAR(struct sip_outbound_registration_client_state *, client_state, param->token, ao2_cleanup);
|
RAII_VAR(struct sip_outbound_registration_client_state *, client_state, param->token, ao2_cleanup);
|
||||||
struct registration_response *response;
|
struct registration_response *response;
|
||||||
|
pjsip_regc_info info;
|
||||||
|
|
||||||
ast_assert(client_state != NULL);
|
ast_assert(client_state != NULL);
|
||||||
|
|
||||||
|
@ -712,6 +740,12 @@ static void sip_outbound_registration_response_cb(struct pjsip_regc_cbparam *par
|
||||||
response->client_state = client_state;
|
response->client_state = client_state;
|
||||||
ao2_ref(response->client_state, +1);
|
ao2_ref(response->client_state, +1);
|
||||||
|
|
||||||
|
pjsip_regc_get_info(client_state->client, &info);
|
||||||
|
ast_debug(1, "Received REGISTER response %d(%.*s) from server '%.*s' for client '%.*s\n",
|
||||||
|
param->code, (int) param->reason.slen, param->reason.ptr,
|
||||||
|
(int) info.server_uri.slen, info.server_uri.ptr,
|
||||||
|
(int) info.client_uri.slen, info.client_uri.ptr);
|
||||||
|
|
||||||
if (param->rdata) {
|
if (param->rdata) {
|
||||||
struct pjsip_retry_after_hdr *retry_after = pjsip_msg_find_hdr(param->rdata->msg_info.msg, PJSIP_H_RETRY_AFTER, NULL);
|
struct pjsip_retry_after_hdr *retry_after = pjsip_msg_find_hdr(param->rdata->msg_info.msg, PJSIP_H_RETRY_AFTER, NULL);
|
||||||
|
|
||||||
|
@ -731,6 +765,9 @@ static void sip_outbound_registration_state_destroy(void *obj)
|
||||||
{
|
{
|
||||||
struct sip_outbound_registration_state *state = obj;
|
struct sip_outbound_registration_state *state = obj;
|
||||||
|
|
||||||
|
ast_debug(3, "Destroying registration state for registration to server '%s' from client '%s'\n",
|
||||||
|
state->registration->server_uri, state->registration->client_uri);
|
||||||
|
|
||||||
ao2_cleanup(state->registration);
|
ao2_cleanup(state->registration);
|
||||||
|
|
||||||
if (!state->client_state) {
|
if (!state->client_state) {
|
||||||
|
@ -1146,6 +1183,11 @@ static int unregister_task(void *obj)
|
||||||
RAII_VAR(struct sip_outbound_registration_state*, state, obj, ao2_cleanup);
|
RAII_VAR(struct sip_outbound_registration_state*, state, obj, ao2_cleanup);
|
||||||
struct pjsip_regc *client = state->client_state->client;
|
struct pjsip_regc *client = state->client_state->client;
|
||||||
pjsip_tx_data *tdata;
|
pjsip_tx_data *tdata;
|
||||||
|
pjsip_regc_info info;
|
||||||
|
|
||||||
|
pjsip_regc_get_info(client, &info);
|
||||||
|
ast_debug(1, "Unregistering contacts with server '%s' from client '%s'\n",
|
||||||
|
state->registration->server_uri, state->registration->client_uri);
|
||||||
|
|
||||||
cancel_registration(state->client_state);
|
cancel_registration(state->client_state);
|
||||||
|
|
||||||
|
|
Loading…
Reference in New Issue