From c53a117368d123bdc6ccdc12c374a645f37433c7 Mon Sep 17 00:00:00 2001 From: chenjintao Date: Mon, 26 Oct 2026 11:55:40 +0800 Subject: [PATCH] diag: trace RTC synchronization and WSS clock state --- docs/time_diag.md | 31 ++++ .../threadx/interface/custom_app/Makefile | 1 + .../threadx/interface/custom_app/custom_app.c | 2 + .../interface/custom_app/inc/time_diag.h | 12 ++ .../lib/librws/src/rws_socketpriv.c | 4 +- .../threadx/interface/custom_app/net_mgt.c | 4 + .../threadx/interface/custom_app/time_diag.c | 84 ++++++++++ ql-config/config/talkingq_time_diag.h | 37 +++++ ql-kernel/threadx/api_map/Makefile | 1 + ql-kernel/threadx/api_map/ql_user_api_map.c | 2 + .../threadx/api_map/talkingq_time_diag.c | 80 ++++++++++ ql-kernel/threadx/quec/gps_channel.c | 26 +++- ql-kernel/threadx/quec_mbedtls/ntp.c | 13 ++ tools/test_time_diag.py | 146 ++++++++++++++++++ 14 files changed, 439 insertions(+), 4 deletions(-) create mode 100644 docs/time_diag.md create mode 100644 ql-application/threadx/interface/custom_app/inc/time_diag.h create mode 100644 ql-application/threadx/interface/custom_app/time_diag.c create mode 100644 ql-config/config/talkingq_time_diag.h create mode 100644 ql-kernel/threadx/api_map/talkingq_time_diag.c create mode 100644 tools/test_time_diag.py diff --git a/docs/time_diag.md b/docs/time_diag.md new file mode 100644 index 0000000..745137a --- /dev/null +++ b/docs/time_diag.md @@ -0,0 +1,31 @@ +# RTC / GNSS / WSS 诊断日志 + +所有新增输出以 `[TIME-DIAG]` 开头，仅采集状态，不主动设置时间、清除 NVM 或修改校时重试策略。 + +## 构建与采集 + +完整诊断需要在支持的 Windows 编译环境依次执行 `build.bat kernel`、`build.bat app`、`build.bat firmware`，并更新匹配的内核和 APP。普通 APP OTA 不代表内核已更新。保留设备原有 RTC/NVM 状态，以免丢失异常现场。 + +APP 兼容旧内核：缺少新增接口时打印 `kernel_diag=unavailable need_matching_diagnostic_kernel=1`，仍可输出 WSS 的 APP 时间，但无法取得内核偏移和跟随标志。 + +采集从上电至 WSS 首次失败、随后恢复的完整串口日志，并记录烧录包版本。启动日志包含 APP 版本、编译信息和固件版本；内核事件日志包含自身编译日期。重点比较异常设备与正常设备的下列阶段： + +- `boot-before-nitz`：启动且尚未开启 NITZ。 +- `nitz-enabled`、`pdp-active`：开启运营商校时、数据连接成功。 +- `gnss_ntp_dns`、`gnss_ntp_trigger`、`ntp_request/result`、`ntp_rtc_written`：GNSS 发起的 NTP 路径。 +- `gnss-time-state`、`ntp-finished`：内核校时状态变化和 NTP 完成。 +- `wss-before-time-read`、`wss-precheck`、`wss-after-time-read`：WSS 读取 APP 时间前后。 + +## 字段 + +`counter` 是原始 RTC 计数，`sys_offset/app_offset` 是两套偏移；`sys_raw/app_raw` 是无符号 32 位相加后的原始秒数，不直接视为 UTC。`follows_sys` 是 APP 跟随 SYS 标志；`app_ever` 表示持久化的 APP RTC 设置标记；`storage` 是 SDK 的偏移存储枚举。 + +`net_tz_min` 单位为分钟，`rtc_tz_hour` 单位为小时；`source` 对应 SDK 的 NITZ=0、NTP=1、APP=2、UNKNOWN=3。`ntp_status` 对应原有状态 0/1/2（初始/成功/失败），日志忠实输出现有状态，不能仅凭这个标志判定实际校时成功。`ntp_type` 是 SDK 的校时类型状态，`ntp_ready` 表示任务和事件句柄已创建；`gnss_rtc` 是 GNSS 网络模块的校时状态，`cid` 为该模块记录的数据上下文。未编入的可选功能字段为 -1。 + +`time_null` 是 WSS 原来使用的 `time(NULL)` 样本，门槛仍为 `1704067200`；返回这个原始样本用于判断。`time_ptr_return/value` 用于对比 `time(&value)` 的返回值和指针写回，未写回时 value 保持哨兵值 1。`app_calendar` 来自额外的 `ql_rtc_get_time`，只在 `rtc_rc` 成功时有意义。 + +内核快照直接读计数、偏移和标记，避开可能开启 APP 跟随行为的 RTC 取时接口。WSS 额外读取发生在原来的首次 `time(NULL)` 之后。多字段采样并非原子快照，允许跨秒或并发校时造成的短暂差异，需结合连续日志判读。 + +## 本机检查 + +`python3 tools/test_time_diag.py` 使用本机 C 编译器及模拟 SDK，编译实际新增模块，验证可选接口缺失、ABI 不匹配、未初始化 RTC、SYS/APP 偏移差异、32 位溢出及 WSS 保留原始门槛样本。它不替代 Windows 目标固件编译、链接或实机复现。 diff --git a/ql-application/threadx/interface/custom_app/Makefile b/ql-application/threadx/interface/custom_app/Makefile index b79cab6..6db6cf1 100644 --- a/ql-application/threadx/interface/custom_app/Makefile +++ b/ql-application/threadx/interface/custom_app/Makefile @@ -82,6 +82,7 @@ SRC_FILES+= \ DP1312EA.c \ mqtt.c \ mqtt_connect_diag.c \ + time_diag.c \ vad_det.c \ sleep_wake.c \ battery.c \ diff --git a/ql-application/threadx/interface/custom_app/custom_app.c b/ql-application/threadx/interface/custom_app/custom_app.c index e045ffd..aaf1e66 100644 --- a/ql-application/threadx/interface/custom_app/custom_app.c +++ b/ql-application/threadx/interface/custom_app/custom_app.c @@ -30,6 +30,7 @@ #include "hal_api.h" #include "nfc.h" #include "ota_baseline.h" +#include "time_diag.h" #define APP_ENABLE_SLEEP @@ -147,6 +148,7 @@ static void custom_app_task(void * argv) hal_os_get_build_time(tempbuf); printf("BUILD TIME:%s\r\n",tempbuf); + talkingq_time_diag_boot(); printf("[OTA-BASELINE] layout=%s profile=%s app_phys=0x%08lX app_xip=0x%08lX app_size=%lu fs_size=%lu slot=single\r\n", BANBAN_OTA_LAYOUT_ID, BANBAN_OTA_BUILD_PROFILE, diff --git a/ql-application/threadx/interface/custom_app/inc/time_diag.h b/ql-application/threadx/interface/custom_app/inc/time_diag.h new file mode 100644 index 0000000..72a9947 --- /dev/null +++ b/ql-application/threadx/interface/custom_app/inc/time_diag.h @@ -0,0 +1,12 @@ +#ifndef TALKINGQ_APP_TIME_DIAG_H +#define TALKINGQ_APP_TIME_DIAG_H + +#include + +void talkingq_time_diag_boot(void); +/* Raw kernel snapshot only: safe to call before the application's first RTC read. */ +void talkingq_time_diag_log(const char *phase); +/* Returns the original time(NULL) sample for the existing WSS threshold check. */ +time_t talkingq_time_diag_wss_time(void); + +#endif diff --git a/ql-application/threadx/interface/custom_app/lib/librws/src/rws_socketpriv.c b/ql-application/threadx/interface/custom_app/lib/librws/src/rws_socketpriv.c index d8bb566..dd420b5 100644 --- a/ql-application/threadx/interface/custom_app/lib/librws/src/rws_socketpriv.c +++ b/ql-application/threadx/interface/custom_app/lib/librws/src/rws_socketpriv.c @@ -28,6 +28,7 @@ #include "sockets.h" #include "ql_rtos.h" #include +#include "time_diag.h" #include "rws_handshake.h" #ifdef LIBRWS_USING_MBED_TLS #include "mbedtls/base64.h" @@ -1945,7 +1946,8 @@ int rws_ssl_conn(_rws_socket *s) LOG_E("WSS requires a trusted root CA\n"); goto exit; } - if (time(NULL) < 1704067200) { + stage = "check RTC time"; + if (talkingq_time_diag_wss_time() < 1704067200) { LOG_E("WSS requires valid network/RTC time before certificate verification\n"); goto exit; } diff --git a/ql-application/threadx/interface/custom_app/net_mgt.c b/ql-application/threadx/interface/custom_app/net_mgt.c index 8987699..16bd39c 100644 --- a/ql-application/threadx/interface/custom_app/net_mgt.c +++ b/ql-application/threadx/interface/custom_app/net_mgt.c @@ -21,6 +21,7 @@ #include "ql_atcmd.h" #include "http_downfile.h" #include "ota_post_update.h" +#include "time_diag.h" //#define NTP_SERVER_DOMAIN "ntp.aliyun.com" @@ -141,6 +142,7 @@ void ql_datacall_demo_thread(void *arvg) if(ret == 0) { + talkingq_time_diag_log("pdp-active"); ql_get_data_call_info(1, 0, &info); printf("info.profile_idx: %d\r\n", info.profile_idx); printf("info.ip_version: %d\r\n", info.ip_version); @@ -197,6 +199,8 @@ int app_net_mgt_init() // ql_rtos_semaphore_create(&g_ql_ntp_sem,0); ql_rtc_set_nitz_mode(1); + printf("[TIME-DIAG] nitz_enabled=1 app_ntp_enabled=0\r\n"); + talkingq_time_diag_log("nitz-enabled"); ql_task_t appTaskRef = NULL; ql_rtos_task_create(&appTaskRef, 1024*4, 100, "app_net_mgt", ql_datacall_demo_thread, NULL); diff --git a/ql-application/threadx/interface/custom_app/time_diag.c b/ql-application/threadx/interface/custom_app/time_diag.c new file mode 100644 index 0000000..c9c0c86 --- /dev/null +++ b/ql-application/threadx/interface/custom_app/time_diag.c @@ -0,0 +1,84 @@ +#include +#include +#include "ql_func.h" +#include "ql_rtc.h" +#include "ql_rtos.h" +#include "ql_dev.h" +#include "build_macro.h" +#include "time_diag.h" +#include "../../../../ql-config/config/talkingq_time_diag.h" + +void talkingq_time_diag_log(const char *phase) +{ + talkingq_time_diag_snapshot_fn snapshot; + talkingq_time_diag_snapshot s; + int ret; + + snapshot = m_get_api_ptr ? (talkingq_time_diag_snapshot_fn) + m_get_api_ptr(TALKINGQ_TIME_DIAG_API_NAME) : NULL; + if (!snapshot) { + printf("[TIME-DIAG] phase=%s ticks=%lu kernel_diag=unavailable " + "need_matching_diagnostic_kernel=1\r\n", phase, + (unsigned long)ql_rtos_get_systicks()); + return; + } + memset(&s, 0, sizeof(s)); + ret = snapshot(&s, sizeof(s)); + if (ret != 0 || s.abi_version != TALKINGQ_TIME_DIAG_ABI_VERSION) { + printf("[TIME-DIAG] phase=%s kernel_diag=abi_mismatch rc=%d abi=%u\r\n", + phase, ret, s.abi_version); + return; + } + printf("[TIME-DIAG] phase=%s ticks=%u abi=%u rtc_init=%u " + "counter=%lu sys_offset=%lu app_offset=%lu " + "sys_raw=%lu app_raw=%lu follows_sys=%u app_ever=%u storage=%d\r\n", + phase, s.sample_ticks, s.abi_version, s.rtc_initialized, + (unsigned long)s.counter, (unsigned long)s.sys_offset, + (unsigned long)s.app_offset, + (unsigned long)(s.counter + s.sys_offset), + (unsigned long)(s.counter + s.app_offset), + s.app_follows_sys, s.app_ever_configured, s.offset_storage); + printf("[TIME-DIAG] phase=%s ticks=%u net_tz_min=%d rtc_tz_hour=%d source=%d " + "ntp_type=%d ntp_status=%d ntp_ready=%d gnss_rtc=%d cid=%d " + "triggers=%d dns_attempted=%d ntp_ip=%.31s\r\n", + phase, s.sample_ticks, s.network_tz_minutes, s.rtc_tz_hours, s.rtc_source, + s.ntp_type, s.ntp_status, s.ntp_ready, s.gnss_rtc_status, s.gnss_cid, + s.ntp_triggers, s.ntp_dns_attempted, s.ntp_server); +} + +void talkingq_time_diag_boot(void) +{ + char firmware[128] = {0}; + int ret = ql_dev_get_firmware_version(firmware, sizeof(firmware)); + firmware[sizeof(firmware) - 1] = '\0'; + printf("[TIME-DIAG] boot app_ver=%s app_build=%s app_rev=%s " + "diag_build=%s %s firmware_rc=%d firmware=%s\r\n", + CUSTOM_APP_BUILD_VER, CUSTOM_APP_BUILD_TIME, CUSTOM_APP_BUILD_REV, + __DATE__, __TIME__, ret, firmware); + talkingq_time_diag_log("boot-before-nitz"); +} + +time_t talkingq_time_diag_wss_time(void) +{ + time_t original; + time_t with_pointer; + time_t pointer_value = 1; + ql_rtc_time_t rtc; + int rtc_ret; + + /* Capture raw flags first. Do not replace or correct the existing gate. */ + talkingq_time_diag_log("wss-before-time-read"); + original = time(NULL); + with_pointer = time(&pointer_value); + memset(&rtc, 0, sizeof(rtc)); + rtc_ret = ql_rtc_get_time(&rtc); + printf("[TIME-DIAG] phase=wss-precheck ticks=%lu time_null=%ld " + "time_ptr_return=%ld time_ptr_value=%ld rtc_rc=%d " + "app_calendar=%04d-%02d-%02dT%02d:%02d:%02d min_epoch=1704067200 valid=%d\r\n", + (unsigned long)ql_rtos_get_systicks(), (long)original, + (long)with_pointer, (long)pointer_value, rtc_ret, + rtc.tm_year, rtc.tm_mon, rtc.tm_mday, rtc.tm_hour, rtc.tm_min, rtc.tm_sec, + original >= 1704067200); + talkingq_time_diag_log("wss-after-time-read"); + return original; +} diff --git a/ql-config/config/talkingq_time_diag.h b/ql-config/config/talkingq_time_diag.h new file mode 100644 index 0000000..51c62fa --- /dev/null +++ b/ql-config/config/talkingq_time_diag.h @@ -0,0 +1,37 @@ +#ifndef TALKINGQ_TIME_DIAG_ABI_H +#define TALKINGQ_TIME_DIAG_ABI_H + +/* Shared by the ARMCC kernel and GCC application. No pointers or enums in ABI. */ +#define TALKINGQ_TIME_DIAG_ABI_VERSION 1U +#define TALKINGQ_TIME_DIAG_API_NAME "talkingq_time_diag_snapshot_v1" +#define TALKINGQ_TIME_DIAG_API_HASH 0x11B09482U + +typedef struct { + unsigned int abi_version; + unsigned int sample_ticks; + unsigned int rtc_initialized; + unsigned int counter; + unsigned int sys_offset; + unsigned int app_offset; + unsigned int app_follows_sys; + unsigned int app_ever_configured; + int offset_storage; + int network_tz_minutes; + int rtc_tz_hours; + int rtc_source; + int ntp_type; + int ntp_status; + int ntp_ready; + int gnss_rtc_status; + int gnss_cid; + int ntp_triggers; + int ntp_dns_attempted; + char ntp_server[32]; +} talkingq_time_diag_snapshot; + +typedef int (*talkingq_time_diag_snapshot_fn)(talkingq_time_diag_snapshot *, unsigned int); + +int talkingq_time_diag_snapshot_v1(talkingq_time_diag_snapshot *out, unsigned int size); +void talkingq_time_diag_trace(const char *phase); + +#endif diff --git a/ql-kernel/threadx/api_map/Makefile b/ql-kernel/threadx/api_map/Makefile index 8f282bc..43a3522 100644 --- a/ql-kernel/threadx/api_map/Makefile +++ b/ql-kernel/threadx/api_map/Makefile @@ -12,6 +12,7 @@ MAKEFILE_PATH :=$(subst $(strip \),/,$(abspath $(lastword $(MAKEFILE_LIST)))) SRC_FILES+= \ quec_kernel_shim_api.c \ ql_user_api_map.c \ + talkingq_time_diag.c \ #------------------------------------------------------------------------------- diff --git a/ql-kernel/threadx/api_map/ql_user_api_map.c b/ql-kernel/threadx/api_map/ql_user_api_map.c index cb8499e..eeea48d 100644 --- a/ql-kernel/threadx/api_map/ql_user_api_map.c +++ b/ql-kernel/threadx/api_map/ql_user_api_map.c @@ -30,6 +30,7 @@ WHEN WHO WHAT, WHERE, WHY #include "ql_keypad.h" #include "ql_rtc.h" #include "ql_time.h" +#include "../../../ql-config/config/talkingq_time_diag.h" #include "ql_power.h" #include "ql_nw.h" #include "ql_platform.h" @@ -103,6 +104,7 @@ ql_open_api_list vUserAPITable[] __attribute__((used, section("DDR_USER_API_TABL { {0x60BCEA5A, (void*)ql_user_api_map_test}, {0xFFFFFFFF, (void*)quec_kernel_api_test}, + {TALKINGQ_TIME_DIAG_API_HASH, (void *)talkingq_time_diag_snapshot_v1}, #ifdef QL_MBEDTLS /************************************************************************************************ diff --git a/ql-kernel/threadx/api_map/talkingq_time_diag.c b/ql-kernel/threadx/api_map/talkingq_time_diag.c new file mode 100644 index 0000000..826b4e5 --- /dev/null +++ b/ql-kernel/threadx/api_map/talkingq_time_diag.c @@ -0,0 +1,80 @@ +#include +#include +#include "ql_type.h" +#include "quec_cust_feature.h" +#include "pmic.h" +#include "pmic_rtc.h" +#include "quec_rtc.h" +#include "ql_rtos.h" +#include "../../../ql-config/config/talkingq_time_diag.h" + +/* SDK globals are linked by name, never by firmware-specific RAM addresses. */ +extern unsigned char m_rtc_app_sys_keeping_synced; +extern PMIC_RTC_OFFSET_STORAGE m_pmic_rtc_offset_storage_type; +#ifdef NTP +extern int get_ntp_time_type(void); +extern int GetNTPStatus(void); +extern int talkingq_ntp_diag_ready(void); +#endif +#ifdef QUEC_GNSS_NTP +extern int quec_get_rtc_status(void); +extern int quec_get_nw_status(void); +extern char *get_ntp_server_ip(void); +extern char ntp_sync_cnt; +extern char ntp_dns_gain; +#endif + +int talkingq_time_diag_snapshot_v1(talkingq_time_diag_snapshot *out, unsigned int size) +{ + if (out == NULL || size != sizeof(*out)) return -1; + memset(out, 0, sizeof(*out)); + out->abi_version = TALKINGQ_TIME_DIAG_ABI_VERSION; + out->sample_ticks = ql_rtos_get_systicks(); + out->ntp_type = out->ntp_status = out->ntp_ready = -1; + out->gnss_rtc_status = out->gnss_cid = -1; + out->ntp_triggers = out->ntp_dns_attempted = -1; + out->rtc_initialized = pmic_rtc_INIT_FLAG_GET() ? 1U : 0U; + if (!out->rtc_initialized) return 0; + + /* Read raw RTC storage, not PMIC_RTC_GetTime_Count(): that getter can + * enable APP-follow-SYS and would disturb the boot state under diagnosis. */ + out->app_follows_sys = m_rtc_app_sys_keeping_synced; + out->app_ever_configured = pmic_userdata_get_app_rtc_ever_configed() ? 1U : 0U; + out->offset_storage = (int)m_pmic_rtc_offset_storage_type; + out->sys_offset = PM812_RTC_GET_32B_SYS_OFFSET(); + out->app_offset = PM812_RTC_GET_32B_APP_OFFSET(); + out->counter = PM812_RTC_GET_32B_COUNTER(); + out->network_tz_minutes = GetTimeZone(); + out->rtc_tz_hours = PMIC_RTC_GetTimezone(); + out->rtc_source = (int)quec_get_rtc_source(); +#ifdef NTP + out->ntp_type = get_ntp_time_type(); + out->ntp_status = GetNTPStatus(); + out->ntp_ready = talkingq_ntp_diag_ready(); +#endif +#ifdef QUEC_GNSS_NTP + out->gnss_rtc_status = quec_get_rtc_status(); + out->gnss_cid = quec_get_nw_status(); + out->ntp_triggers = (unsigned char)ntp_sync_cnt; + out->ntp_dns_attempted = (unsigned char)ntp_dns_gain; + snprintf(out->ntp_server, sizeof(out->ntp_server), "%.31s", get_ntp_server_ip()); +#endif + return 0; +} + +void talkingq_time_diag_trace(const char *phase) +{ + talkingq_time_diag_snapshot s; + if (talkingq_time_diag_snapshot_v1(&s, sizeof(s)) != 0) return; + printf("[TIME-DIAG] kernel phase=%s build=%s %s rtc_init=%u " + "counter=%lu sys_offset=%lu app_offset=%lu follows_sys=%u app_ever=%u " + "storage=%d\r\n", + phase, __DATE__, __TIME__, s.rtc_initialized, + (unsigned long)s.counter, (unsigned long)s.sys_offset, + (unsigned long)s.app_offset, s.app_follows_sys, s.app_ever_configured, + s.offset_storage); + printf("[TIME-DIAG] kernel phase=%s ticks=%u net_tz_min=%d rtc_tz_hour=%d source=%d " + "ntp_type=%d ntp_status=%d ntp_ready=%d gnss_rtc=%d triggers=%d\r\n", + phase, s.sample_ticks, s.network_tz_minutes, s.rtc_tz_hours, s.rtc_source, + s.ntp_type, s.ntp_status, s.ntp_ready, s.gnss_rtc_status, s.ntp_triggers); +} diff --git a/ql-kernel/threadx/quec/gps_channel.c b/ql-kernel/threadx/quec/gps_channel.c index 4344c41..f25d8f9 100644 --- a/ql-kernel/threadx/quec/gps_channel.c +++ b/ql-kernel/threadx/quec/gps_channel.c @@ -17,6 +17,7 @@ #include "quec_sockets.h" #include "gps_app.h" #include "quec_mfpr_api.h" +#include "../../../ql-config/config/talkingq_time_diag.h" #define GPS_VIA_UART @@ -415,6 +416,8 @@ void quec_gps_nw_status_monitor(void * argv) { int cid_num = 0; struct sockaddr sockaddr = {0}; + int last_type = -1, last_status = -1, last_rtc = -1; + int current_type, current_status, dns_ret; while(1) { cid_num = quec_gps_get_cid_act(); @@ -429,13 +432,18 @@ void quec_gps_nw_status_monitor(void * argv) memcpy(&gps_nw_ctx_ptr.gps_ip4_addr, &(((struct sockaddr_in *)&sockaddr)->sin_addr), sizeof(struct in_addr)); quec_rtos_task_sleep_s(2); if(!ntp_dns_gain){ - quec_gps_ntp_set_server(quec_gps_cfg->ntp_url); + dns_ret = quec_gps_ntp_set_server(quec_gps_cfg->ntp_url); + printf("[TIME-DIAG] gnss_ntp_dns cid=%d server=%.31s rc=%d ip=%.31s\r\n", + cid_num, quec_gps_cfg->ntp_url, dns_ret, get_ntp_server_ip()); ntp_dns_gain++; } /*限制成功激活pdp后ntp的同步次数*/ if((gps_nw_ctx_ptr.rtc_status !=1)&&(ntp_sync_cnt < 10)) { - get_ntp_time_internal(); + printf("[TIME-DIAG] gnss_ntp_trigger cid=%d attempt=%u ntp_type=%d ntp_status=%d\r\n", + cid_num, (unsigned int)(unsigned char)ntp_sync_cnt + 1U, + get_ntp_time_type(), GetNTPStatus()); + get_ntp_time_internal(); ntp_sync_cnt++; GPS_LOGD("Ntp sync cnt:%d!!!",ntp_sync_cnt); } @@ -453,6 +461,15 @@ void quec_gps_nw_status_monitor(void * argv) { gps_nw_ctx_ptr.rtc_status = 1; } + current_type = get_ntp_time_type(); + current_status = GetNTPStatus(); + if (current_type != last_type || current_status != last_status || + gps_nw_ctx_ptr.rtc_status != last_rtc) { + talkingq_time_diag_trace("gnss-time-state"); + last_type = current_type; + last_status = current_status; + last_rtc = gps_nw_ctx_ptr.rtc_status; + } //RTI_LOG("Found an active pdp %d:%d:%d:%d:%d:%d!!!",tm.tm_year,tm.tm_mon,tm.tm_mday,tm.tm_hour,tm.tm_min,tm.tm_sec); } } @@ -472,6 +489,7 @@ int quec_get_nw_status(void) int gps_nw_active(void) { int cid_num = 0; + int dns_ret; cid_num = quec_gps_get_cid_act(); struct sockaddr sockaddr = {0}; if(cid_num>0) @@ -483,7 +501,9 @@ int gps_nw_active(void) quec_soc_get_ipv4v6_local_addr(cid_num, AF_INET, &sockaddr); memcpy(&gps_nw_ctx_ptr.gps_ip4_addr, &(((struct sockaddr_in *)&sockaddr)->sin_addr), sizeof(struct in_addr)); if(!ntp_dns_gain){ - quec_gps_ntp_set_server(quec_gps_cfg->ntp_url); + dns_ret = quec_gps_ntp_set_server(quec_gps_cfg->ntp_url); + printf("[TIME-DIAG] gnss_ntp_dns cid=%d server=%.31s rc=%d ip=%.31s\r\n", + cid_num, quec_gps_cfg->ntp_url, dns_ret, get_ntp_server_ip()); ntp_dns_gain++; } GPS_LOGI("Found an active pdp!!!"); diff --git a/ql-kernel/threadx/quec_mbedtls/ntp.c b/ql-kernel/threadx/quec_mbedtls/ntp.c index b788803..adfc6bd 100644 --- a/ql-kernel/threadx/quec_mbedtls/ntp.c +++ b/ql-kernel/threadx/quec_mbedtls/ntp.c @@ -77,6 +77,7 @@ static const char rcsid[] = "$OpenBSD: rdate.c,v 1.22 2004/02/18 20:10:53 jmc Ex #endif #include "utltime.h" #include "quec_cust_feature.h" +#include "../../../ql-config/config/talkingq_time_diag.h" /* there are systems without libutil; for portability */ #ifdef HAVE_UTIL_H #include @@ -204,6 +205,11 @@ int GetNTPStatus(void) return NTP_SYNC_SUCCESS; } +int talkingq_ntp_diag_ready(void) +{ + return NtpFlagRef != NULL && NTPTaskRef != NULL; +} + static unsigned int ntp_retry_timer[] = { (1 * 1000 / 5), /*2 sec*/ (10 * 1000 / 5), /*10 sec*/ @@ -278,11 +284,14 @@ extern char *get_ntp_server_ip(void); while(try_times > 0 && count < 8) { --try_times; + printf("[TIME-DIAG] ntp_request attempt=%d server=%.31s\r\n", + 3 - try_times, strlen(hname) > 0 ? hname : hname_default); if(strlen(hname) > 0) ret = ntp_client(hname, family, &new, &adjust, corrleaps); else ret = ntp_client(hname_default, family, &new, &adjust, corrleaps); + printf("[TIME-DIAG] ntp_result attempt=%d rc=%d\r\n", 3 - try_times, ret); if(ret != 0) { continue; @@ -297,6 +306,7 @@ extern char *get_ntp_server_ip(void); if (new.tv_sec > 60 * 60 * 24 * 365) { SaveNTPParameters(ltm); + printf("[TIME-DIAG] ntp_rtc_written epoch=%ld\r\n", (long)tim); break; } OSATaskSleep(200); @@ -311,6 +321,7 @@ extern char *get_ntp_server_ip(void); SetNTPStatus(2);//failed } + talkingq_time_diag_trace("ntp-finished"); } @@ -325,12 +336,14 @@ void NTP_Init_Internal(void) str = psm_get_wrapper("Debug", NULL, "debug_ntp_disable"); if (str && strcmp(str, "1") == 0) { + printf("[TIME-DIAG] ntp_init skipped debug_ntp_disable=1\r\n"); free(str); return; } if (str) free(str); + printf("[TIME-DIAG] ntp_init debug_ntp_disable=0\r\n"); /* Ntp Flag initialize. */ status = OSAFlagCreate(&NtpFlagRef); ASSERT(status == OS_SUCCESS); diff --git a/tools/test_time_diag.py b/tools/test_time_diag.py new file mode 100644 index 0000000..b78dd7a --- /dev/null +++ b/tools/test_time_diag.py @@ -0,0 +1,146 @@ +"""Host behavioral checks for the actual diagnostic modules; no device required.""" +from pathlib import Path +import re +import shutil +import subprocess +import tempfile + +ROOT = Path(__file__).resolve().parents[1] +APP = ROOT / 'ql-application/threadx/interface/custom_app' +KERNEL = ROOT / 'ql-kernel/threadx/api_map/talkingq_time_diag.c' + + +def api_hash(name): + value = 0 + for byte in name.encode(): + term = (value * 5527 + byte * 7) & 0xffffffff + value = (term ^ ((term & 65535) ** 2)) & 0xffffffff + return value + + +assert api_hash('ql_user_api_map_test') == 0x60BCEA5A +abi = (ROOT / 'ql-config/config/talkingq_time_diag.h').read_text() +hash_value = int(re.search(r'API_HASH 0x([0-9A-F]+)', abi)[1], 16) +assert api_hash('talkingq_time_diag_snapshot_v1') == hash_value +table = (ROOT / 'ql-kernel/threadx/api_map/ql_user_api_map.c').read_text() +assert f'{hash_value:08x}' not in table.lower() + +with tempfile.TemporaryDirectory(prefix='time-diag-') as directory: + work = Path(directory) + headers = { + 'ql_func.h': '#include \nextern intptr_t (*m_get_api_ptr)(const char *);\n', + 'ql_rtos.h': 'unsigned int ql_rtos_get_systicks(void);\n', + 'ql_dev.h': 'int ql_dev_get_firmware_version(char *, unsigned int);\n', + 'build_macro.h': '#define CUSTOM_APP_BUILD_VER "test"\n#define CUSTOM_APP_BUILD_TIME "test"\n#define CUSTOM_APP_BUILD_REV "test"\n', + 'ql_rtc.h': 'typedef struct { int tm_sec,tm_min,tm_hour,tm_mday,tm_mon,tm_year,tm_wday; } ql_rtc_time_t;\nint ql_rtc_get_time(ql_rtc_time_t *);\n', + 'ql_type.h': '', + 'quec_cust_feature.h': '', + 'pmic.h': 'typedef int PMIC_RTC_OFFSET_STORAGE;\nunsigned int PM812_RTC_GET_32B_SYS_OFFSET(void), PM812_RTC_GET_32B_APP_OFFSET(void), PM812_RTC_GET_32B_COUNTER(void);\n', + 'pmic_rtc.h': 'int pmic_rtc_INIT_FLAG_GET(void), pmic_userdata_get_app_rtc_ever_configed(void), PMIC_RTC_GetTimezone(void);\n', + 'quec_rtc.h': 'int GetTimeZone(void), quec_get_rtc_source(void);\n', + } + for name, content in headers.items(): + (work / name).write_text(content) + (work / 'harness.c').write_text(r''' +#include +#include +#include +#include +#include +#include "talkingq_time_diag.h" +#include "time_diag.h" +#include "ql_rtc.h" +unsigned char m_rtc_app_sys_keeping_synced; +int m_pmic_rtc_offset_storage_type; +char ntp_sync_cnt = 3, ntp_dns_gain = 1; +static int initialized, raw_reads, api_mode, sample_index, write_pointer; +static time_t samples[2]; +unsigned int ql_rtos_get_systicks(void) { return 123; } +int pmic_rtc_INIT_FLAG_GET(void) { return initialized; } +int pmic_userdata_get_app_rtc_ever_configed(void) { return 1; } +unsigned int PM812_RTC_GET_32B_COUNTER(void) { ++raw_reads; return 0xfffffff0U; } +unsigned int PM812_RTC_GET_32B_SYS_OFFSET(void) { ++raw_reads; return 100; } +unsigned int PM812_RTC_GET_32B_APP_OFFSET(void) { ++raw_reads; return 50; } +int PMIC_RTC_GetTimezone(void) { return 8; } +int GetTimeZone(void) { return 480; } +int quec_get_rtc_source(void) { return 1; } +int get_ntp_time_type(void) { return 0; } +int GetNTPStatus(void) { return 1; } +int talkingq_ntp_diag_ready(void) { return 1; } +int quec_get_rtc_status(void) { return 1; } +int quec_get_nw_status(void) { return 2; } +char *get_ntp_server_ip(void) { return "192.0.2.1"; } +int ql_dev_get_firmware_version(char *out, unsigned int size) { + snprintf(out, size, "test-firmware"); return 0; +} +int ql_rtc_get_time(ql_rtc_time_t *out) { (void)out; return -1; } +time_t time(time_t *out) { + time_t value; + assert(sample_index < 2); + value = samples[sample_index++]; + if (out && write_pointer) *out = value; + return value; +} +static int bad_snapshot(talkingq_time_diag_snapshot *out, unsigned int size) { + (void)size; out->abi_version = 99; return 0; +} +static intptr_t lookup(const char *name) { + assert(strcmp(name, TALKINGQ_TIME_DIAG_API_NAME) == 0); + if (api_mode == 0) return 0; + if (api_mode == 1) return (intptr_t)bad_snapshot; + return (intptr_t)talkingq_time_diag_snapshot_v1; +} +intptr_t (*m_get_api_ptr)(const char *) = lookup; +int main(void) { + talkingq_time_diag_snapshot s; + assert(sizeof(s) == 108); + assert(talkingq_time_diag_snapshot_v1(NULL, sizeof(s)) == -1); + assert(talkingq_time_diag_snapshot_v1(&s, sizeof(s)-1) == -1); + assert(talkingq_time_diag_snapshot_v1(&s, sizeof(s)) == 0); + assert(!s.rtc_initialized && raw_reads == 0); + initialized = 1; + assert(talkingq_time_diag_snapshot_v1(&s, sizeof(s)) == 0); + assert(raw_reads == 3 && s.sys_offset == 100 && s.app_offset == 50); + assert(s.counter + s.sys_offset == 84 && s.counter + s.app_offset == 34); + assert(s.app_follows_sys == 0 && m_rtc_app_sys_keeping_synced == 0); + assert(s.network_tz_minutes == 480 && s.rtc_tz_hours == 8); +#ifdef NTP + assert(s.ntp_ready == 1 && s.ntp_status == 1); +#else + assert(s.ntp_ready == -1 && s.ntp_status == -1); +#endif +#ifdef QUEC_GNSS_NTP + assert(s.gnss_cid == 2 && strcmp(s.ntp_server, "192.0.2.1") == 0); +#else + assert(s.gnss_cid == -1 && s.ntp_server[0] == 0); +#endif + talkingq_time_diag_boot(); /* old kernel */ + api_mode = 1; talkingq_time_diag_log("bad-abi"); + api_mode = 2; talkingq_time_diag_log("divergent"); + samples[0] = 100; samples[1] = 1800000000; + assert(talkingq_time_diag_wss_time() == 100); + samples[0] = 1800000000; samples[1] = 100; + sample_index = 0; write_pointer = 1; + assert(talkingq_time_diag_wss_time() == 1800000000); + assert(m_rtc_app_sys_keeping_synced == 0); + talkingq_time_diag_trace("kernel-check"); + puts("PASS"); + return 0; +} +''') + compiler = shutil.which('clang') or shutil.which('cc') + if not compiler: + raise SystemExit('A native C compiler is required') + for features in ([], ['-DNTP'], ['-DNTP', '-DQUEC_GNSS_NTP']): + command = [compiler, '-std=c99', '-Wall', '-Wextra', '-Werror', + '-I', str(work), '-I', str(APP / 'inc'), + '-I', str(ROOT / 'ql-config/config'), *features, + str(APP / 'time_diag.c'), str(KERNEL), str(work / 'harness.c'), + '-o', str(work / 'test')] + subprocess.run(command, check=True) + log = subprocess.check_output([str(work / 'test')], text=True) + for expected in ('kernel_diag=unavailable', 'kernel_diag=abi_mismatch', + 'sys_raw=84 app_raw=34', 'time_ptr_value=1', + 'time_ptr_value=100', 'valid=0', 'valid=1', 'PASS'): + assert expected in log, expected + print('PASS:', ' '.join(features) or 'optional features off')