Improve TLS WebSocket and network failure diagnostics
This commit is contained in:
@@ -168,6 +168,7 @@ static void key_thread_entry(void *parameter)
|
||||
!mic_pdp ? "blocked_no_pdp" : (mic_mqtt != 1 ? "blocked_mqtt_offline" : "start_voice"));
|
||||
if(mic_pdp && mic_mqtt == 1){
|
||||
if(tts_play_interrupt_func()==-2){
|
||||
printf("[NET-GATE] mic tip=network_check reason=voice_connect_failed pdp=%d mqtt=%d\r\n", mic_pdp, mic_mqtt);
|
||||
app_play_tips_file(2);
|
||||
}
|
||||
}else{
|
||||
@@ -213,7 +214,14 @@ static void key_thread_entry(void *parameter)
|
||||
build_alarm();
|
||||
}
|
||||
else if(ql_rtos_get_systicks() - key_press_alarm_time > KEY_WAIT_TIME){
|
||||
if(!vad_audio_is_recording()&&key_start_leave==0&&get_mqtt_connect_status()==1){
|
||||
int leave_recording = vad_audio_is_recording();
|
||||
int leave_mqtt = get_mqtt_connect_status();
|
||||
printf("[NET-GATE] leave recording=%d pending=%d mqtt=%d action=%s\r\n",
|
||||
leave_recording, key_start_leave, leave_mqtt,
|
||||
leave_recording ? "blocked_recording" :
|
||||
(key_start_leave ? "blocked_pending" :
|
||||
(leave_mqtt != 1 ? "blocked_mqtt_offline" : "request_leave")));
|
||||
if(!leave_recording&&key_start_leave==0&&leave_mqtt==1){
|
||||
key_start_leave = 1;
|
||||
build_leave_to_parent();
|
||||
}else{
|
||||
|
||||
@@ -340,8 +340,13 @@ rws_bool rws_socket_recv(_rws_socket *s)
|
||||
break;
|
||||
}
|
||||
if (len <= 0) {
|
||||
LOG_E("WSS TLS peer closed or read failed: %d\n", len);
|
||||
s->error = rws_error_new_code_descr(rws_error_code_read_write_socket, "TLS peer closed or read failed");
|
||||
const char *reason = len == 0 ? "tls_eof" :
|
||||
(len == MBEDTLS_ERR_SSL_PEER_CLOSE_NOTIFY ? "peer_close_notify" :
|
||||
(len == MBEDTLS_ERR_SSL_TIMEOUT ? "tls_read_timeout" : "tls_read_error"));
|
||||
printf("[WSS-DIAG] stage=tls_read reason=%s ret=%d hex=-0x%04x command=%d rx_bytes=%u buffered=%u\n",
|
||||
reason, len, (unsigned int)-len, s->command,
|
||||
s->diag_rx_bytes, (unsigned int)s->received_len);
|
||||
s->error = rws_error_new_code_descr(rws_error_code_read_write_socket, reason);
|
||||
s->command = COMMAND_INFORM_DISCONNECTED;
|
||||
result = rws_false;
|
||||
goto _exit;
|
||||
@@ -1032,10 +1037,14 @@ void rws_socket_idle_send(_rws_socket *s)
|
||||
|
||||
void rws_socket_wait_handshake_responce(_rws_socket *s)
|
||||
{
|
||||
unsigned int started = ql_rtos_get_systicks();
|
||||
unsigned int started = ql_rtos_get_systicks(), polls = 0;
|
||||
unsigned int rx_before = s->diag_rx_bytes;
|
||||
size_t header_length = 0;
|
||||
int status = 0, result = 0;
|
||||
const char *reason;
|
||||
printf("[WSS-DIAG] stage=ws_upgrade event=begin timeout_ms=10000\n");
|
||||
while (result == 0) {
|
||||
++polls;
|
||||
rws_socket_recv(s);
|
||||
if (s->error) break;
|
||||
result = rws_check_handshake((const char *)s->received, s->received_len,
|
||||
@@ -1045,6 +1054,9 @@ void rws_socket_wait_handshake_responce(_rws_socket *s)
|
||||
rws_thread_sleep(10);
|
||||
}
|
||||
if (result == 1 && !s->error) {
|
||||
printf("[WSS-DIAG] stage=ws_upgrade result=ok http=101 elapsed_ms=%u rx_bytes=%u header_bytes=%u polls=%u\n",
|
||||
(unsigned int)(ql_rtos_get_systicks() - started) * 5,
|
||||
s->diag_rx_bytes - rx_before, (unsigned int)header_length, polls);
|
||||
s->received_len -= header_length;
|
||||
if (s->received_len)
|
||||
memmove(s->received, (char *)s->received + header_length, s->received_len);
|
||||
@@ -1052,10 +1064,15 @@ void rws_socket_wait_handshake_responce(_rws_socket *s)
|
||||
s->command = COMMAND_INFORM_CONNECTED;
|
||||
LOG_I("WebSocket upgrade verified: HTTP 101\n");
|
||||
} else {
|
||||
LOG_E("WebSocket upgrade failed: HTTP %d (0 means incomplete/invalid headers)\n", status);
|
||||
reason = s->error ? "transport_error" :
|
||||
(result == 0 ? (s->received_len ? "incomplete_headers_timeout" : "no_response_timeout") :
|
||||
(status && status != 101 ? "http_rejected" : "invalid_upgrade_response"));
|
||||
printf("[WSS-DIAG] stage=ws_upgrade result=failed reason=%s http=%d elapsed_ms=%u timeout_ms=10000 rx_bytes=%u buffered=%u header_bytes=%u parser=%d polls=%u\n",
|
||||
reason, status, (unsigned int)(ql_rtos_get_systicks() - started) * 5,
|
||||
s->diag_rx_bytes - rx_before, (unsigned int)s->received_len,
|
||||
(unsigned int)header_length, result, polls);
|
||||
if (!s->error)
|
||||
s->error = rws_error_new_code_descr(rws_error_code_parse_handshake,
|
||||
"Invalid or timed out WebSocket upgrade");
|
||||
s->error = rws_error_new_code_descr(rws_error_code_parse_handshake, reason);
|
||||
rws_socket_close(s);
|
||||
s->command = COMMAND_INFORM_DISCONNECTED;
|
||||
}
|
||||
@@ -1905,6 +1922,19 @@ static const char *rws_tls_phase_name(int state)
|
||||
case MBEDTLS_SSL_SERVER_KEY_EXCHANGE: return "server key exchange";
|
||||
case MBEDTLS_SSL_CLIENT_KEY_EXCHANGE: return "client key exchange";
|
||||
case MBEDTLS_SSL_SERVER_FINISHED: return "server finished";
|
||||
case MBEDTLS_SSL_HELLO_REQUEST: return "hello request";
|
||||
case MBEDTLS_SSL_CERTIFICATE_REQUEST: return "certificate request";
|
||||
case MBEDTLS_SSL_SERVER_HELLO_DONE: return "server hello done";
|
||||
case MBEDTLS_SSL_CLIENT_CERTIFICATE: return "client certificate";
|
||||
case MBEDTLS_SSL_CERTIFICATE_VERIFY: return "certificate verify";
|
||||
case MBEDTLS_SSL_CLIENT_CHANGE_CIPHER_SPEC: return "client change cipher spec";
|
||||
case MBEDTLS_SSL_CLIENT_FINISHED: return "client finished";
|
||||
case MBEDTLS_SSL_SERVER_CHANGE_CIPHER_SPEC: return "server change cipher spec";
|
||||
case MBEDTLS_SSL_FLUSH_BUFFERS: return "flush buffers";
|
||||
case MBEDTLS_SSL_HANDSHAKE_WRAPUP: return "handshake wrapup";
|
||||
case MBEDTLS_SSL_HANDSHAKE_OVER: return "handshake over";
|
||||
case MBEDTLS_SSL_SERVER_NEW_SESSION_TICKET: return "server new session ticket";
|
||||
case MBEDTLS_SSL_SERVER_HELLO_VERIFY_REQUEST_SENT: return "server hello verify request sent";
|
||||
default: return "other";
|
||||
}
|
||||
}
|
||||
@@ -1913,10 +1943,14 @@ static int rws_tls_handshake_timed(mbedtls_ssl_context *ctx)
|
||||
{
|
||||
unsigned int started = ql_rtos_get_systicks();
|
||||
unsigned int phase_started = started, call_ticks = 0, retries = 0;
|
||||
int state = ctx->state, ret = 0;
|
||||
int state = ctx->state, ret = 0, last_step_ret = 0;
|
||||
unsigned int want_read = 0, want_write = 0;
|
||||
while (ctx->state != MBEDTLS_SSL_HANDSHAKE_OVER) {
|
||||
unsigned int before = ql_rtos_get_systicks();
|
||||
ret = mbedtls_ssl_handshake_step(ctx);
|
||||
last_step_ret = ret;
|
||||
if (ret == MBEDTLS_ERR_SSL_WANT_READ) ++want_read;
|
||||
if (ret == MBEDTLS_ERR_SSL_WANT_WRITE) ++want_write;
|
||||
call_ticks += (unsigned int)(ql_rtos_get_systicks() - before);
|
||||
if (ret != 0 && ret != MBEDTLS_ERR_SSL_WANT_READ && ret != MBEDTLS_ERR_SSL_WANT_WRITE)
|
||||
break;
|
||||
@@ -1946,6 +1980,12 @@ static int rws_tls_handshake_timed(mbedtls_ssl_context *ctx)
|
||||
}
|
||||
LOG_I("WSS TLS handshake total=%u ms, state=%d, ret=%d\n",
|
||||
(unsigned int)(ql_rtos_get_systicks() - started) * 5, ctx->state, ret);
|
||||
LOG_I("[WSS-DIAG] stage=tls_handshake result=%s phase=%s state=%d elapsed_ms=%u timeout_ms=20000 ret=%d hex=-0x%04x last_step=%d want_read=%u want_write=%u phase_ms=%u calls_ms=%u\n",
|
||||
ret == 0 ? "ok" : (ret == MBEDTLS_ERR_SSL_TIMEOUT ? "timeout" : "failed"),
|
||||
rws_tls_phase_name(ctx->state), ctx->state,
|
||||
(unsigned int)(ql_rtos_get_systicks() - started) * 5, ret, (unsigned int)-ret,
|
||||
last_step_ret, want_read, want_write,
|
||||
(unsigned int)(ql_rtos_get_systicks() - phase_started) * 5, call_ticks * 5);
|
||||
return ret;
|
||||
}
|
||||
|
||||
@@ -2037,7 +2077,13 @@ int rws_ssl_conn(_rws_socket *s)
|
||||
exit:
|
||||
LOG_E("WSS TLS connection failed at %s: %d (-0x%04x)\n", stage, ret, (unsigned int)-ret);
|
||||
rws_error_delete_clean(&s->error);
|
||||
s->error = rws_error_new_code_descr(rws_error_code_connect_to_host, "TLS connection or certificate verification failed");
|
||||
if (s->ssl)
|
||||
LOG_E("[WSS-DIAG] stage=tls_connect failed_at=%s ret=%d verify_flags=0x%08lx\n",
|
||||
stage, ret, (unsigned long)mbedtls_ssl_get_verify_result(&s->ssl->ssl_ctx));
|
||||
s->error = rws_error_new_code_descr(rws_error_code_connect_to_host,
|
||||
ret == MBEDTLS_ERR_SSL_TIMEOUT ? "TLS handshake timeout" :
|
||||
(ret == MBEDTLS_ERR_X509_CERT_VERIFY_FAILED ? "TLS certificate verification failed" :
|
||||
"TLS connection setup or handshake failed"));
|
||||
if (s->ssl) {
|
||||
/* Do not send close_notify for an incomplete handshake. */
|
||||
mbedtls_net_free(&s->ssl->net_ctx);
|
||||
|
||||
@@ -17,7 +17,8 @@
|
||||
#include <stdio.h>
|
||||
#include <stdlib.h>
|
||||
#include <string.h>
|
||||
#include <ctype.h>
|
||||
#include <ctype.h>
|
||||
#include <errno.h>
|
||||
#include <webclient.h>
|
||||
#include <stdarg.h>
|
||||
|
||||
@@ -131,12 +132,14 @@ static int webclient_read_line(struct webclient_session *session, char *buffer,
|
||||
FD_SET(session->socket, &read_fds);
|
||||
|
||||
ret = select(session->socket + 1, &read_fds, NULL, NULL, &t);
|
||||
int select_errno = ret < 0 ? errno : 0;
|
||||
|
||||
// printf("select ret: %d\r\n", ret);
|
||||
|
||||
if(ret <= 0)
|
||||
{
|
||||
printf("*** select timeout or error ***\r\n");
|
||||
printf("[HTTP-DIAG] stage=response_header reason=%s select_ret=%d errno_snapshot=%d timeout_ms=2000\r\n",
|
||||
ret == 0 ? "timeout" : "select_error", ret, select_errno);
|
||||
return -WEBCLIENT_ERROR;
|
||||
}
|
||||
|
||||
@@ -561,12 +564,14 @@ static int webclient_connect(struct webclient_session *session, const char *URI)
|
||||
FD_SET(socket_handle, &write_fds);
|
||||
|
||||
rc= select(socket_handle + 1, &read_fds, &write_fds, NULL, &t);
|
||||
int select_errno = rc < 0 ? errno : 0;
|
||||
|
||||
printf("select ret: %d\r\n", rc);
|
||||
|
||||
if(rc <= 0)
|
||||
{
|
||||
printf("*** select timeout or error ***\r\n");
|
||||
printf("[HTTP-DIAG] stage=tcp_connect reason=%s select_ret=%d errno_snapshot=%d timeout_ms=2000\r\n",
|
||||
rc == 0 ? "timeout" : "select_error", rc, select_errno);
|
||||
rc = -WEBCLIENT_CONNECT_FAILED;
|
||||
goto __exit;
|
||||
}
|
||||
@@ -1376,12 +1381,14 @@ int webclient_read(struct webclient_session *session, void *buffer, size_t lengt
|
||||
FD_SET(session->socket, &read_fds);
|
||||
|
||||
ret = select(session->socket + 1, &read_fds, NULL, NULL, &t);
|
||||
int select_errno = ret < 0 ? errno : 0;
|
||||
|
||||
// printf("select ret: %d\r\n", ret);
|
||||
|
||||
if(ret <= 0)
|
||||
{
|
||||
printf("*** select timeout or error ***\r\n");
|
||||
printf("[HTTP-DIAG] stage=response_body reason=%s select_ret=%d errno_snapshot=%d timeout_ms=2000\r\n",
|
||||
ret == 0 ? "timeout" : "select_error", ret, select_errno);
|
||||
return -WEBCLIENT_ERROR;
|
||||
}
|
||||
|
||||
|
||||
@@ -821,6 +821,7 @@ int app_mqtt_connect()
|
||||
MQTT_CONN_UNLOCK();
|
||||
|
||||
// [ADD] 连接成功提示音
|
||||
printf("[NET-GATE] tip=network_ok reason=mqtt_connected voice_service=not_checked\r\n");
|
||||
app_play_tips_file(11);
|
||||
|
||||
if(ret!=0){
|
||||
|
||||
Reference in New Issue
Block a user