Bug 819821, adds more logging for STUN, r=jesup
authorDan Mosedale <dmose@mozilla.org>
Thu, 13 Dec 2012 07:14:21 -0800
changeset 125057 0ba4220f82ff42b773bbb1d4527d7fa59cf359a8
parent 125056 d468da47eef0f7f8065710788df3e9203e71ed3f
child 125058 4b218334f0e3939aabf0cff5a143638e2455bef3
push id2151
push userlsblakk@mozilla.com
push dateTue, 19 Feb 2013 18:06:57 +0000
treeherdermozilla-beta@4952e88741ec [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersjesup
bugs819821
milestone20.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 819821, adds more logging for STUN, r=jesup
media/mtransport/third_party/nICEr/src/ice/ice_candidate.c
media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c
media/mtransport/third_party/nICEr/src/stun/stun_codec.c
--- a/media/mtransport/third_party/nICEr/src/ice/ice_candidate.c
+++ b/media/mtransport/third_party/nICEr/src/ice/ice_candidate.c
@@ -469,16 +469,18 @@ static int nr_ice_start_relay_turn(nr_ic
   }
 #endif /* USE_TURN */
 
 static void nr_ice_srvrflx_stun_finished_cb(NR_SOCKET sock, int how, void *cb_arg)
   {
     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);
       cand->u.srvrflx.stun_handle=0;
     }
 
     switch(cand->u.srvrflx.stun->state){
       /* OK, we should have a mapped address */
--- a/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c
+++ b/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c
@@ -473,21 +473,28 @@ int nr_stun_client_process_response(nr_s
          * be a different transaction, so don't perform the check in that
          * case */
     }
 #endif /* USE_TURN */
 
     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
  * TODO: !nn! usage (ctx->mode?) */
     if (password) {
         if (nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_NONCE, 0)) {
             if ((r=nr_stun_receive_response_long_term_auth(ctx->response, ctx)))
                 ABORT(r);
@@ -507,16 +514,18 @@ int nr_stun_client_process_response(nr_s
             ABORT(r);
         }
         else {
             /* drop the error on the floor */
             ABORT(R_FAILED);
         }
     }
 
+    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:
     case NR_STUN_CLIENT_MODE_BINDING_REQUEST_SHORT_TERM_AUTH:
         if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, 0))
             ABORT(R_BAD_DATA);
         if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0))
             ABORT(R_BAD_DATA);
--- a/media/mtransport/third_party/nICEr/src/stun/stun_codec.c
+++ b/media/mtransport/third_party/nICEr/src/stun/stun_codec.c
@@ -1196,16 +1196,18 @@ nr_stun_fix_attribute_ordering(nr_stun_m
 
 #ifdef SANITY_CHECKS
 static void sanity_check_encoding_stuff(nr_stun_message *msg)
 {
     nr_stun_message_attribute *attr = 0;
     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;
         if ((attr->length % 4) != 0) {
             padding_bytes = 4 - (attr->length % 4);
         }
         assert(attr->length == (attr->encoding_length - (4 + padding_bytes)));
         assert(((void*)attr->encoding) == (msg->buffer + 20 + l));
@@ -1357,16 +1359,18 @@ nr_stun_decode_message(nr_stun_message *
     if ((size % 4) != 0) {
        r_log(NR_LOG_STUN, LOG_WARNING, "Illegal message size: %d", msg->header.length);
        ABORT(R_FAILED);
     }
 
     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);
         }
 
         if ((r=nr_stun_message_attribute_create(msg, &attr)))
             ABORT(R_NO_MEMORY);
 
@@ -1425,20 +1429,24 @@ nr_stun_decode_message(nr_stun_message *
                 }
 
                 attr->invalid = 1;
             }
             else {
                 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 */
             }
         }
 
         offset += attr->encoding_length;
         size -= attr->encoding_length;
     }