diff --git a/applications/VK_Client.c b/applications/VK_Client.c index a3e83cd..d20deda 100644 --- a/applications/VK_Client.c +++ b/applications/VK_Client.c @@ -35,9 +35,63 @@ static uint8_t socket_tx_buffer[LTE_SOCKET_TX_CHUNK_SIZE]; static uint8_t socket_rx_buffer[LTE_SOCKET_RX_CHUNK_SIZE]; static rt_size_t socket_tx_pending = 0; static rt_tick_t last_ack_query_tick = 0; +static rt_tick_t socket_tx_retry_tick = 0; +static rt_uint8_t socket_tx_retry_count = 0; + +typedef struct { + rt_tick_t tick; + rt_uint32_t fmu_rx_bytes; + rt_uint32_t socket_tx_bytes; + rt_uint32_t send_ok; + rt_uint32_t send_fail; + rt_uint32_t acked_bytes; + rt_uint32_t queue_drops; + rt_uint32_t prompt_timeouts; +} tx_stat_baseline_t; + +static tx_stat_baseline_t tx_stat_baseline; static void lte_diag_finish_disconnect(void); +static void tx_stat_reset(void) { + tx_stat_baseline.tick = rt_tick_get(); + tx_stat_baseline.fmu_rx_bytes = lte_diag.fmu_rx_bytes; + tx_stat_baseline.socket_tx_bytes = lte_diag.socket_tx_bytes; + tx_stat_baseline.send_ok = lte_diag.socket_send_ok; + tx_stat_baseline.send_fail = lte_diag.socket_send_fail; + tx_stat_baseline.acked_bytes = lte_diag.socket_acked_bytes; + tx_stat_baseline.queue_drops = lte_diag.tx_queue_drops; + tx_stat_baseline.prompt_timeouts = lte_diag.socket_prompt_timeouts; +} + +static rt_uint32_t tx_stat_rate(rt_uint32_t delta, rt_tick_t elapsed) { + return elapsed == 0 ? 0 : delta * RT_TICK_PER_SECOND / elapsed; +} + +static void tx_stat_log(void) { + rt_tick_t now = rt_tick_get(); + rt_tick_t elapsed = now - tx_stat_baseline.tick; + rt_uint32_t fmu_delta; + rt_uint32_t socket_delta; + + if (elapsed < RT_TICK_PER_SECOND * 5) return; + + fmu_delta = lte_diag.fmu_rx_bytes - tx_stat_baseline.fmu_rx_bytes; + socket_delta = lte_diag.socket_tx_bytes - tx_stat_baseline.socket_tx_bytes; + LOG_I("[TXSTAT] in=%uB/s out=%uB/s q=%u/%u pending=%u drops=%u", + tx_stat_rate(fmu_delta, elapsed), tx_stat_rate(socket_delta, elapsed), + fmu_net_queue_data_len(), fmu_net_queue_capacity(), socket_tx_pending, + lte_diag.tx_queue_drops - tx_stat_baseline.queue_drops); + LOG_I("[TXSTAT] ok=%u fail=%u retry=%u ack_delta=%u unacked=%u prompt_to=%u", + lte_diag.socket_send_ok - tx_stat_baseline.send_ok, + lte_diag.socket_send_fail - tx_stat_baseline.send_fail, + socket_tx_retry_count, + lte_diag.socket_acked_bytes - tx_stat_baseline.acked_bytes, + lte_diag.socket_unacked_bytes, + lte_diag.socket_prompt_timeouts - tx_stat_baseline.prompt_timeouts); + tx_stat_reset(); +} + no_carrier_match_t _no_carrier_t = {0}; /*关闭TCP连接*/ @@ -53,6 +107,8 @@ void client_tcp_close(Cclient_t *client) { BSP_LTE_ClearSocketEvents(); fmu_net_queue_reset(); socket_tx_pending = 0; + socket_tx_retry_tick = 0; + socket_tx_retry_count = 0; rt_snprintf(close_cmd, sizeof(close_cmd), AT_QICLOSE, client->connect_ID); BSP_LTE_SendCmd(close_cmd, DEFAULT_EXPECT, DEFAULT_ERROR, LTE_CMD_WAIT_QICLOSE); @@ -412,8 +468,11 @@ int16_t client_tcp_connect(Cclient_t *client) { BSP_LTE_ClearSocketEvents(); fmu_net_queue_reset(); socket_tx_pending = 0; + socket_tx_retry_tick = 0; + socket_tx_retry_count = 0; BSP_LTE_SetDataTxPaused(false); lte_diag_connect_success(); + tx_stat_reset(); last_ack_query_tick = lte_diag.connect_tick; client->error_cnt = 0; lte_dev.reset_flag = DTU_CF_NO_NEED_RESET; @@ -593,28 +652,44 @@ void client_yield(CLte_dev_t *pLte_dev) { socket_tx_pending = fmu_net_queue_get(socket_tx_buffer, sizeof(socket_tx_buffer)); } - if (socket_tx_pending > 0) { + if (socket_tx_pending > 0 && + (socket_tx_retry_tick == 0 || + (rt_int32_t)(rt_tick_get() - socket_tx_retry_tick) >= 0)) { socket_result = BSP_LTE_SendSocketData( pLte_dev->client1->connect_ID, socket_tx_buffer, (uint16_t)socket_tx_pending); if (socket_result == 0) { socket_tx_pending = 0; + socket_tx_retry_tick = 0; + socket_tx_retry_count = 0; } else if (socket_result < 0) { lte_diag_disconnect(LTE_DISC_SOCKET_SEND); client_tcp_close(pLte_dev->client1); continue; } else { - rt_thread_mdelay(50); + rt_uint32_t retry_delay_ms; + + if (socket_tx_retry_count < 255) socket_tx_retry_count++; + retry_delay_ms = socket_tx_retry_count <= 2 ? 100 : + socket_tx_retry_count <= 5 ? 250 : 500; + socket_tx_retry_tick = + rt_tick_get() + rt_tick_from_millisecond(retry_delay_ms); + LOG_W("[TX] retry=%u delay_ms=%u pending=%u", socket_tx_retry_count, + retry_delay_ms, socket_tx_pending); } } - if (rt_tick_get() - last_ack_query_tick >= RT_TICK_PER_SECOND * 5) { + if (!pLte_dev->socket_recv_pending && + rt_tick_get() - last_ack_query_tick >= RT_TICK_PER_SECOND * 5) { last_ack_query_tick = rt_tick_get(); BSP_LTE_QuerySocketSendStatus(pLte_dev->client1->connect_ID); } + tx_stat_log(); + #if LTE_SERVER_SILENCE_TIMEOUT_SEC > 0 - if (rt_tick_get() - last_rx_tick > + if (!pLte_dev->socket_recv_pending && + rt_tick_get() - last_rx_tick > RT_TICK_PER_SECOND * LTE_SERVER_SILENCE_TIMEOUT_SEC) { lte_diag.server_silence_timeout_count++; LOG_W("server silence timeout, reconnect\n"); diff --git a/applications/VK_Com.c b/applications/VK_Com.c index 89aa493..cfca3fe 100644 --- a/applications/VK_Com.c +++ b/applications/VK_Com.c @@ -5,6 +5,10 @@ #include "rtthread.h" #include +#define DBG_TAG "LINK_LOG" +#define DBG_LVL DBG_INFO +#include "rtdbg.h" + #define ENABLE_MEMORY_USAGE_LOG 0 #if ENABLE_MEMORY_USAGE_LOG @@ -16,11 +20,14 @@ rt_device_t fmu_com = RT_NULL; rt_sem_t fmu_com_rx_sem = RT_NULL; -#define FMU_NET_QUEUE_SIZE 512 +#define FMU_NET_QUEUE_SIZE 768 static struct rt_ringbuffer fmu_net_queue; static struct rt_mutex fmu_net_queue_lock; static uint8_t fmu_net_queue_pool[FMU_NET_QUEUE_SIZE]; static bool fmu_net_queue_ready = false; +static rt_tick_t tx_queue_drop_log_tick = 0; +static rt_uint32_t tx_queue_drop_log_bytes = 0; +static rt_uint32_t tx_queue_drop_log_events = 0; #if ENABLE_MEMORY_USAGE_LOG static rt_size_t thread_stack_used(rt_thread_t thread) { @@ -96,7 +103,24 @@ rt_size_t fmu_net_queue_put(const uint8_t *data, rt_size_t length) { used = rt_ringbuffer_data_len(&fmu_net_queue); rt_mutex_release(&fmu_net_queue_lock); - if (queued < length) lte_diag.tx_queue_drops += length - queued; + if (queued < length) { + rt_size_t dropped = length - queued; + rt_tick_t now = rt_tick_get(); + + lte_diag.tx_queue_drops += dropped; + tx_queue_drop_log_bytes += dropped; + tx_queue_drop_log_events++; + if (tx_queue_drop_log_tick == 0) tx_queue_drop_log_tick = now; + if (now - tx_queue_drop_log_tick >= RT_TICK_PER_SECOND) { + LOG_W("[TXQ] drops=%u events=%u used=%u/%u window_ms=%u", + tx_queue_drop_log_bytes, tx_queue_drop_log_events, used, + (rt_size_t)FMU_NET_QUEUE_SIZE, + now - tx_queue_drop_log_tick); + tx_queue_drop_log_tick = now; + tx_queue_drop_log_bytes = 0; + tx_queue_drop_log_events = 0; + } + } if (used > lte_diag.tx_queue_high_water) lte_diag.tx_queue_high_water = used; return queued; } @@ -111,6 +135,18 @@ rt_size_t fmu_net_queue_get(uint8_t *data, rt_size_t length) { return read; } +rt_size_t fmu_net_queue_data_len(void) { + rt_size_t used; + + if (!fmu_net_queue_ready) return 0; + rt_mutex_take(&fmu_net_queue_lock, RT_WAITING_FOREVER); + used = rt_ringbuffer_data_len(&fmu_net_queue); + rt_mutex_release(&fmu_net_queue_lock); + return used; +} + +rt_size_t fmu_net_queue_capacity(void) { return FMU_NET_QUEUE_SIZE; } + void fmu_net_queue_reset(void) { if (!fmu_net_queue_ready) return; rt_mutex_take(&fmu_net_queue_lock, RT_WAITING_FOREVER); diff --git a/applications/VK_Com.h b/applications/VK_Com.h index edd12eb..83c8685 100644 --- a/applications/VK_Com.h +++ b/applications/VK_Com.h @@ -17,6 +17,8 @@ rt_device_t fmu_com_get(void); int fmu_com_register(rt_device_t com_dev); rt_size_t fmu_net_queue_put(const uint8_t *data, rt_size_t length); rt_size_t fmu_net_queue_get(uint8_t *data, rt_size_t length); +rt_size_t fmu_net_queue_data_len(void); +rt_size_t fmu_net_queue_capacity(void); void fmu_net_queue_reset(void); #ifdef __cplusplus diff --git a/lib/mavlink b/lib/mavlink index 10ab2c9..901131d 160000 --- a/lib/mavlink +++ b/lib/mavlink @@ -1 +1 @@ -Subproject commit 10ab2c9cf0b57b58a136412beeea2b0d459073a6 +Subproject commit 901131d3504631175255966012664c450500f259