Bug 819821, adds more logging for STUN, r=jesup

media/mtransport/third_party/nICEr/src/ice/ice_candidate.c

@@ -474,6 +474,8 @@ static void nr_ice_srvrflx_stun_finished_cb(NR_SOCKET sock, int how, void *cb_ar
     int _status;
     nr_ice_candidate *cand=cb_arg;
 
+    r_log(LOG_ICE,LOG_DEBUG,"ICE(%s): %s for %s",cand->ctx->label,__FUNCTION__,cand->label);
+
     /* Deregister to suppress duplicates */
     if(cand->u.srvrflx.stun_handle){ /* This test because we might have failed before CB registered */
       nr_ice_socket_deregister(cand->isock,cand->u.srvrflx.stun_handle);

media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c

@@ -478,11 +478,18 @@ int nr_stun_client_process_response(nr_stun_client_ctx *ctx, UCHAR *msg, int len
     if ((r=nr_stun_message_create2(&ctx->response, msg, len)))
         ABORT(r);
 
-    if ((r=nr_stun_decode_message(ctx->response, nr_stun_client_get_password, password)))
+    if ((r=nr_stun_decode_message(ctx->response, nr_stun_client_get_password, password))) {
+        r_log(NR_LOG_STUN,LOG_DEBUG,"STUN-CLIENT(%s): error decoding message",ctx->label);
         ABORT(r);
+    }
 
-    if ((r=nr_stun_receive_message(ctx->request, ctx->response)))
+    if ((r=nr_stun_receive_message(ctx->request, ctx->response))) {
+        r_log(NR_LOG_STUN,LOG_DEBUG,"STUN-CLIENT(%s): error receiving message",ctx->label);
         ABORT(r);
+    }
+
+    r_log(NR_LOG_STUN,LOG_DEBUG,
+          "STUN-CLIENT(%s): successfully received message; processing",ctx->label);
 
 /* TODO: !nn! currently using password!=0 to mean that auth is required,
  * TODO: !nn! but we should probably pass that in explicitly via the
@@ -512,6 +519,8 @@ int nr_stun_client_process_response(nr_stun_client_ctx *ctx, UCHAR *msg, int len
         }
     }
 
+    r_log(NR_LOG_STUN,LOG_DEBUG,"STUN-CLIENT(%s): Successfully parsed mode=%d",ctx->label,ctx->mode);
+
 /* TODO: !nn! this should be moved to individual message receive/processing sections */
     switch (ctx->mode) {
     case NR_STUN_CLIENT_MODE_BINDING_REQUEST_LONG_TERM_AUTH:

media/mtransport/third_party/nICEr/src/stun/stun_codec.c

@@ -1201,6 +1201,8 @@ static void sanity_check_encoding_stuff(nr_stun_message *msg)
     int padding_bytes;
     int l;
 
+    r_log(NR_LOG_STUN, LOG_DEBUG, "Starting to sanity check encoding");
+
     l = 0;
     TAILQ_FOREACH(attr, &msg->attributes, entry) {
         padding_bytes = 0;
@@ -1362,6 +1364,8 @@ nr_stun_decode_message(nr_stun_message *msg, int (*get_password)(void *arg, nr_s
     offset = sizeof(msg->header);
 
     while (size > 0) {
+        r_log(NR_LOG_STUN, LOG_DEBUG, "size = %d", size);
+
         if (size < 4) {
            r_log(NR_LOG_STUN, LOG_WARNING, "Illegal message length: %d", size);
            ABORT(R_FAILED);
@@ -1430,10 +1434,14 @@ nr_stun_decode_message(nr_stun_message *msg, int (*get_password)(void *arg, nr_s
                 attr_info->codec->print(attr_info, "Parsed", &attr->u);
 
 #ifdef USE_STUN_PEDANTIC
+                r_log(NR_LOG_STUN, LOG_DEBUG, "Before pedantic attr_info checks");
                 if (attr_info->illegal) {
-                    if ((r=attr_info->illegal(attr_info, attr->length, &attr->u)))
+    		    if ((r=attr_info->illegal(attr_info, attr->length, &attr->u))) {
+                        r_log(NR_LOG_STUN, LOG_DEBUG, "Failed pedantic attr_info checks");
                         ABORT(r);
+		    }
                 }
+                r_log(NR_LOG_STUN, LOG_DEBUG, "After pedantic attr_info checks");
 #endif /* USE_STUN_PEDANTIC */
             }
         }