[Asterisk-code-review] res pjsip outbound registration: Add debugging messages. (asterisk[master])

[Mark Michelson]

Mark Michelson has uploaded a new change for review.

  https://gerrit.asterisk.org/263

Change subject: res_pjsip_outbound_registration: Add debugging messages.
......................................................................

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
---
M res/res_pjsip_outbound_registration.c
1 file changed, 39 insertions(+), 6 deletions(-)


  git pull ssh://gerrit.asterisk.org:29418/asterisk refs/changes/63/263/1

diff --git a/res/res_pjsip_outbound_registration.c b/res/res_pjsip_outbound_registration.c
index e30a32e..14cdc3c 100644
--- a/res/res_pjsip_outbound_registration.c
+++ b/res/res_pjsip_outbound_registration.c
@@ -479,10 +479,16 @@
 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;
+	pjsip_regc_info info;
+
+	pjsip_regc_get_info(client_state->client, &info);
+	ast_debug(1, "Attempting scheduled outbound registration attempt to %.*s\n",
+			(int) info.server_uri.slen, info.server_uri.ptr);
 
 	ao2_ref(client_state, +1);
 	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 %.*s could not be executed\n",
+				(int) info.server_uri.slen, info.server_uri.ptr);
 		ao2_ref(client_state, -1);
 	}
 	ao2_ref(client_state, -1);
@@ -494,12 +500,18 @@
 static void schedule_registration(struct sip_outbound_registration_client_state *client_state, unsigned int seconds)
 {
 	pj_time_val delay = { .sec = seconds, };
+	pjsip_regc_info info;
 
 	cancel_registration(client_state);
 
+	pjsip_regc_get_info(client_state->client, &info);
+	ast_debug(1, "Scheduling outbound registration to %.*s in %d seconds\n", (int) info.server_uri.slen,
+			info.server_uri.ptr, seconds);
+
 	ao2_ref(client_state, +1);
 	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 %.*s\n",
+				(int) info.server_uri.slen, info.server_uri.ptr);
 		ao2_ref(client_state, -1);
 	}
 }
@@ -611,13 +623,18 @@
 	pjsip_regc_info info;
 	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);
 	ast_copy_pj_str(server_uri, &info.server_uri, sizeof(server_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 &&
 			(response->code == 401 || response->code == 407)) {
@@ -626,11 +643,14 @@
 				response->rdata, response->tsx, &tdata)) {
 			ao2_ref(response->client_state, +1);
 			response->client_state->auth_attempted = 1;
+			ast_debug(1, "Sending authenticated REGISTER to '%s'\n", server_uri);
 			if (pjsip_regc_send(response->client_state->client, tdata) != PJ_SUCCESS) {
 				response->client_state->auth_attempted = 0;
 				ao2_cleanup(response->client_state);
 			}
 			return 0;
+		} else {
+			ast_log(LOG_WARNING, "Failed to create authenticated REGISTER request to '%s'\n", server_uri);
 		}
 		/* Otherwise, fall through so the failure is processed appropriately */
 	}
@@ -700,6 +720,7 @@
 {
 	RAII_VAR(struct sip_outbound_registration_client_state *, client_state, param->token, ao2_cleanup);
 	struct registration_response *response;
+	pjsip_regc_info info;
 
 	ast_assert(client_state != NULL);
 
@@ -711,6 +732,11 @@
 	response->expiration = param->expiration;
 	response->client_state = client_state;
 	ao2_ref(response->client_state, +1);
+
+	pjsip_regc_get_info(client_state->client, &info);
+	ast_debug(1, "Received REGISTER response %d(%.*s) from '%.*s'\n",
+			param->code, (int) param->reason.slen, param->reason.ptr,
+			(int) info.server_uri.slen, info.server_uri.ptr);
 
 	if (param->rdata) {
 		struct pjsip_retry_after_hdr *retry_after = pjsip_msg_find_hdr(param->rdata->msg_info.msg, PJSIP_H_RETRY_AFTER, NULL);
@@ -730,6 +756,9 @@
 static void sip_outbound_registration_state_destroy(void *obj)
 {
 	struct sip_outbound_registration_state *state = obj;
+
+	ast_debug(3, "Destroying registration state for registration to '%s\n",
+			state->registration->server_uri);
 
 	ao2_cleanup(state->registration);
 
@@ -1146,6 +1175,10 @@
 	RAII_VAR(struct sip_outbound_registration_state*, state, obj, ao2_cleanup);
 	struct pjsip_regc *client = state->client_state->client;
 	pjsip_tx_data *tdata;
+	pjsip_regc_info info;
+
+	pjsip_regc_get_info(client, &info);
+	ast_debug(1, "Unregistering contacts with '%s'\n", state->registration->server_uri);
 
 	cancel_registration(state->client_state);
 

-- 
To view, visit https://gerrit.asterisk.org/263
To unsubscribe, visit https://gerrit.asterisk.org/settings

Gerrit-MessageType: newchange
Gerrit-Change-Id: I577bde7860be0a6c872b5bcb4d5047340bf45d45
Gerrit-PatchSet: 1
Gerrit-Project: asterisk
Gerrit-Branch: master
Gerrit-Owner: Mark Michelson <mmichelson at digium.com>