From 663351b2ebd734715635f0d8f2beefe21e1bbb21 Mon Sep 17 00:00:00 2001 From: "Byron Campen [:bwc]" Date: Tue, 17 Sep 2019 18:15:06 +0000 Subject: [PATCH] Bug 1569183: Add some much-needed logging to this function. r=mjf Differential Revision: https://phabricator.services.mozilla.com/D45096 --HG-- extra : moz-landing-system : lando --- .../nICEr/src/stun/stun_client_ctx.c | 109 +++++++++++++----- 1 file changed, 80 insertions(+), 29 deletions(-) diff --git a/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c b/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c index db6c6e3f1d0d..6461d2820ffe 100644 --- a/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c +++ b/media/mtransport/third_party/nICEr/src/stun/stun_client_ctx.c @@ -583,18 +583,24 @@ int nr_stun_client_process_response(nr_stun_client_ctx *ctx, UCHAR *msg, int len * 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))) + if ((r=nr_stun_receive_response_long_term_auth(ctx->response, ctx))) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): long term auth failed",ctx->label); ABORT(r); + } } else { - if ((r=nr_stun_receive_response_short_term_auth(ctx->response))) + if ((r=nr_stun_receive_response_short_term_auth(ctx->response))) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): short term auth failed",ctx->label); ABORT(r); + } } } if (NR_STUN_GET_TYPE_CLASS(ctx->response->header.type) == NR_CLASS_RESPONSE) { - if ((r=nr_stun_process_success_response(ctx->response))) + if ((r=nr_stun_process_success_response(ctx->response))) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): nr_stun_process_success_response failed",ctx->label); ABORT(r); + } } else { if (fail_on_error) { @@ -606,11 +612,13 @@ int nr_stun_client_process_response(nr_stun_client_ctx *ctx, UCHAR *msg, int len the error code, and just keep going. */ if ((r=nr_stun_process_error_response(ctx->response, &ctx->error_code))) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): nr_stun_process_error_response failed",ctx->label); ABORT(r); } else { ctx->error_code = 0xffff; /* drop the error on the floor */ + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): processed error response",ctx->label); ABORT(R_FAILED); } } @@ -621,10 +629,14 @@ int nr_stun_client_process_response(nr_stun_client_ctx *ctx, UCHAR *msg, int len 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)) + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No XOR-MAPPED-ADDRESS",ctx->label); ABORT(R_BAD_DATA); - if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) + } + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No MESSAGE-INTEGRITY",ctx->label); ABORT(R_BAD_DATA); + } mapped_addr = &ctx->results.stun_binding_response.mapped_addr; break; @@ -636,6 +648,7 @@ int nr_stun_client_process_response(nr_stun_client_ctx *ctx, UCHAR *msg, int len r_log(NR_LOG_STUN,LOG_INFO,"STUN-CLIENT(%s): No XOR-MAPPED-ADDRESS but MAPPED-ADDRESS. Falling back (though server is wrong).", ctx->label); } else { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No XOR-MAPPED-ADDRESS or MAPPED-ADDRESS",ctx->label); ABORT(R_BAD_DATA); } } @@ -644,26 +657,36 @@ int nr_stun_client_process_response(nr_stun_client_ctx *ctx, UCHAR *msg, int len break; case NR_STUN_CLIENT_MODE_BINDING_REQUEST_STUND_0_96: - if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MAPPED_ADDRESS, 0) && ! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, 0)) + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MAPPED_ADDRESS, 0) && ! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No MAPPED-ADDRESS",ctx->label); ABORT(R_BAD_DATA); + } mapped_addr = &ctx->results.stun_binding_response_stund_0_96.mapped_addr; break; #ifdef USE_ICE case NR_ICE_CLIENT_MODE_BINDING_REQUEST: - if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, 0)) + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No XOR-MAPPED-ADDRESS",ctx->label); ABORT(R_BAD_DATA); - if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) + } + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No MESSAGE-INTEGRITY",ctx->label); ABORT(R_BAD_DATA); + } mapped_addr = &ctx->results.stun_binding_response.mapped_addr; break; case NR_ICE_CLIENT_MODE_USE_CANDIDATE: - if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, 0)) + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No XOR-MAPPED-ADDRESS",ctx->label); ABORT(R_BAD_DATA); - if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) + } + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No MESSAGE-INTEGRITY",ctx->label); ABORT(R_BAD_DATA); + } mapped_addr = &ctx->results.stun_binding_response.mapped_addr; break; @@ -671,25 +694,37 @@ int nr_stun_client_process_response(nr_stun_client_ctx *ctx, UCHAR *msg, int len #ifdef USE_TURN case NR_TURN_CLIENT_MODE_ALLOCATE_REQUEST: - if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, 0)) + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No XOR-MAPPED-ADDRESS",ctx->label); ABORT(R_BAD_DATA); - if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) + } + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No MESSAGE-INTEGRITY",ctx->label); ABORT(R_BAD_DATA); + } - if (!nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_RELAY_ADDRESS, &attr)) - ABORT(R_BAD_DATA); + if (!nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_RELAY_ADDRESS, &attr)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No XOR-RELAYED-ADDRESS",ctx->label); + ABORT(R_BAD_DATA); + } if ((r=nr_stun_transport_addr_check(&attr->u.relay_address.unmasked, - ctx->mapped_addr_check_mask))) - ABORT(r); + ctx->mapped_addr_check_mask))) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): nr_stun_transport_addr_check failed",ctx->label); + ABORT(r); + } if ((r=nr_transport_addr_copy( &ctx->results.allocate_response.relay_addr, - &attr->u.relay_address.unmasked))) - ABORT(r); + &attr->u.relay_address.unmasked))) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): nr_transport_addr_copy failed",ctx->label); + ABORT(r); + } - if (!nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_LIFETIME, &attr)) - ABORT(R_BAD_DATA); + if (!nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_LIFETIME, &attr)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No LIFETIME",ctx->label); + ABORT(R_BAD_DATA); + } ctx->results.allocate_response.lifetime_secs=attr->u.lifetime_secs; r_log(NR_LOG_STUN,LOG_DEBUG,"STUN-CLIENT(%s): Received relay address: %s", ctx->label, ctx->results.allocate_response.relay_addr.as_string); @@ -698,15 +733,21 @@ int nr_stun_client_process_response(nr_stun_client_ctx *ctx, UCHAR *msg, int len break; case NR_TURN_CLIENT_MODE_REFRESH_REQUEST: - if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No MESSAGE-INTEGRITY",ctx->label); ABORT(R_BAD_DATA); - if (!nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_LIFETIME, &attr)) - ABORT(R_BAD_DATA); + } + if (!nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_LIFETIME, &attr)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No LIFETIME",ctx->label); + ABORT(R_BAD_DATA); + } ctx->results.refresh_response.lifetime_secs=attr->u.lifetime_secs; break; case NR_TURN_CLIENT_MODE_PERMISSION_REQUEST: - if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) + if (! nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MESSAGE_INTEGRITY, 0)) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No MESSAGE-INTEGRITY",ctx->label); ABORT(R_BAD_DATA); + } break; #endif /* USE_TURN */ @@ -725,22 +766,32 @@ int nr_stun_client_process_response(nr_stun_client_ctx *ctx, UCHAR *msg, int len if (mapped_addr) { if (nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_XOR_MAPPED_ADDRESS, &attr)) { if ((r=nr_stun_transport_addr_check(&attr->u.xor_mapped_address.unmasked, - ctx->mapped_addr_check_mask))) + ctx->mapped_addr_check_mask))) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): XOR-MAPPED-ADDRESS is bogus",ctx->label); ABORT(r); + } - if ((r=nr_transport_addr_copy(mapped_addr, &attr->u.xor_mapped_address.unmasked))) + if ((r=nr_transport_addr_copy(mapped_addr, &attr->u.xor_mapped_address.unmasked))) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): nr_transport_addr_copy failed",ctx->label); ABORT(r); + } } else if (nr_stun_message_has_attribute(ctx->response, NR_STUN_ATTR_MAPPED_ADDRESS, &attr)) { if ((r=nr_stun_transport_addr_check(&attr->u.mapped_address, - ctx->mapped_addr_check_mask))) + ctx->mapped_addr_check_mask))) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): MAPPED-ADDRESS is bogus",ctx->label); ABORT(r); + } - if ((r=nr_transport_addr_copy(mapped_addr, &attr->u.mapped_address))) + if ((r=nr_transport_addr_copy(mapped_addr, &attr->u.mapped_address))) { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): nr_transport_addr_copy failed",ctx->label); ABORT(r); + } } - else + else { + r_log(NR_LOG_STUN,LOG_WARNING,"STUN-CLIENT(%s): No mapped address!",ctx->label); ABORT(R_BAD_DATA); + } // STUN doesn't distinguish protocol in mapped address, therefore // assign used protocol from peer_addr