Skip to content

Add ring broadcast, ring timeout watchdog, CMTI dedup, and hangup fix #1

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
KerseyFabrications merged 3 commits into from
Apr 17, 2026
Merged

Add ring broadcast, ring timeout watchdog, CMTI dedup, and hangup fix #1

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
5f3ecce
Add ring broadcast, ring timeout watchdog, CMTI dedup, and hangup fix
KerseyFabrications Apr 17, 2026
cc6fa1f
Fix ring timestamp atomics, hangup NO_CARRIER handling, and review items
KerseyFabrications Apr 17, 2026
0fcf76a
Add millisecond timestamps to log output
KerseyFabrications Apr 17, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
23 changes: 20 additions & 3 deletions src/logging.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,9 @@
#include <stdarg.h>
#include <stdlib.h>
#include <string.h>
#include <sys/time.h>
#include <syslog.h>
#include <time.h>

static FILE *log_file = NULL;

Expand All @@ -38,6 +40,18 @@ static FILE *log_file = NULL;

static int use_syslog = 0;

/* Get current timestamp with milliseconds (thread-safe) */
static void get_timestamp_ms(char *buffer, size_t buffer_size) {
struct timeval tv;
struct tm tm_storage;

gettimeofday(&tv, NULL);
localtime_r(&tv.tv_sec, &tm_storage);

snprintf(buffer, buffer_size, "%02d:%02d:%02d.%03d", tm_storage.tm_hour, tm_storage.tm_min,
tm_storage.tm_sec, (int)(tv.tv_usec / 1000));
}

int init_syslog(const char *ident) {
if (log_file) {
fclose(log_file);
Expand All @@ -56,7 +70,7 @@ static const char *get_filename(const char *path) {
return filename ? filename + 1 : path;
}

#define PREAMBLE_WIDTH 35
#define PREAMBLE_WIDTH 45

static void remove_newlines(char *str) {
char *src = str, *dst = str;
Expand Down Expand Up @@ -107,9 +121,12 @@ void log_message(log_level_t level, const char *file, int line, const char *fmt,

const char *filename = get_filename(file);

char timestamp[13]; /* "HH:MM:SS.mmm" */
get_timestamp_ms(timestamp, sizeof(timestamp));

char preamble[PREAMBLE_WIDTH + 1];
int preamble_length = snprintf(preamble, sizeof(preamble), "[%s] %s:%d: ", level_str, filename,
line);
int preamble_length = snprintf(preamble, sizeof(preamble), "[%s] %s %s:%d: ", level_str,
timestamp, filename, line);

if (preamble_length > PREAMBLE_WIDTH) {
preamble[PREAMBLE_WIDTH] = '\0';
Expand Down
83 changes: 80 additions & 3 deletions src/oasis-echo.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,12 @@ static rate_bucket_t g_sms_bucket;
/* Thread-safe call state using __atomic builtins (GCC) */
static call_state_t g_call_state = CALL_STATE_IDLE;

/* Ring timeout: if RINGING_IN persists this long after the last RING URC,
* poll AT+CLCC to confirm. Modem sends RING every ~5s, so 10s gap means
* the carrier forwarded to voicemail without a termination URC. */
#define RING_TIMEOUT_SEC 10
static time_t g_last_ring_time = 0;

static call_state_t get_call_state(void) {
return __atomic_load_n(&g_call_state, __ATOMIC_ACQUIRE);
}
Expand All @@ -57,6 +63,14 @@ static void set_call_state(call_state_t state) {
__atomic_store_n(&g_call_state, state, __ATOMIC_RELEASE);
}

static time_t get_last_ring_time(void) {
return __atomic_load_n(&g_last_ring_time, __ATOMIC_ACQUIRE);
}

static void set_last_ring_time(time_t t) {
__atomic_store_n(&g_last_ring_time, t, __ATOMIC_RELEASE);
}

/* ── Command queue (thread-safe, lock-free SPSC ring) ────────────────── */

#define CMD_QUEUE_SIZE 16
Expand Down Expand Up @@ -186,8 +200,12 @@ static void on_urc_event(const urc_event_t *event, void *userdata) {

switch (event->type) {
case URC_RING: {
/* Suppress duplicate RING events — only publish on first RING */
set_last_ring_time(time(NULL));
/* Subsequent RINGs — publish lightweight ring event for MIRAGE/DAWN */
if (get_call_state() == CALL_STATE_RINGING_IN) {
if (mqtt_build_event_json("ring", NULL, json, sizeof(json)) >= 0) {
mqtt_publish_event(json);
}
Comment thread
KerseyFabrications marked this conversation as resolved.
break;
}
set_call_state(CALL_STATE_RINGING_IN);
Expand Down Expand Up @@ -224,6 +242,7 @@ static void on_urc_event(const urc_event_t *event, void *userdata) {
break;
}
set_call_state(CALL_STATE_IDLE);
set_last_ring_time(0);
const char *reason = (prev == CALL_STATE_DIALING) ? "no_carrier" : "remote_hangup";
struct json_object *extra = json_object_new_object();
json_object_object_add(extra, "reason", json_object_new_string(reason));
Expand Down Expand Up @@ -285,7 +304,18 @@ static void on_urc_event(const urc_event_t *event, void *userdata) {

case URC_CMTI: {
/* Defer SMS read to main thread — calling at_command_send from
* the URC reader would deadlock (reader waits for itself). */
* the URC reader would deadlock (reader waits for itself).
* Deduplicate: SIM7600 sometimes sends duplicate +CMTI for same index. */
static int last_cmti_index = -1;
static time_t last_cmti_time = 0;
time_t now_t = time(NULL);
if (event->index == last_cmti_index && (now_t - last_cmti_time) < 3) {
OLOG_INFO("Suppressing duplicate CMTI for index %d", event->index);
break;
}
last_cmti_index = event->index;
last_cmti_time = now_t;

OLOG_INFO("New SMS at index %d, deferring read to main loop", event->index);
cmd_entry_t cmd;
memset(&cmd, 0, sizeof(cmd));
Expand Down Expand Up @@ -467,12 +497,28 @@ static void process_mqtt_command(const cmd_entry_t *cmd) {

/* hangup — AT+CHUP works in all call states on SIM7600 (ATH does not) */
if (strcmp(action, "hangup") == 0) {
call_state_t prev = get_call_state();
set_call_state(CALL_STATE_HANGING_UP);
at_response_t resp;
at_status_t rc = at_command_send(&g_at_ctx, "AT+CHUP", &resp, AT_TIMEOUT_DEFAULT);
set_call_state(CALL_STATE_IDLE);
if (rc == AT_OK) {
set_last_ring_time(0);
/* AT+CHUP may return OK or NO CARRIER — both mean the call ended */
if (rc == AT_OK || rc == AT_NO_CARRIER) {
mqtt_publish_response(action, request_id, true, NULL, NULL, NULL);
/* Publish call_ended directly — don't rely on URC which we'll suppress
* since state is already IDLE by the time it arrives. */
if (prev != CALL_STATE_IDLE) {
char json[1024];
struct json_object *extra = json_object_new_object();
json_object_object_add(extra, "reason", json_object_new_string("local_hangup"));
json_object_object_add(extra, "duration", json_object_new_int(0));
if (mqtt_build_event_json("call_ended", extra, json, sizeof(json)) >= 0) {
mqtt_publish_event(json);
}
json_object_put(extra);
OLOG_INFO("Call ended: local hangup");
}
} else {
mqtt_publish_response(action, request_id, false, NULL, at_status_str(rc), "Hangup failed");
}
Comment thread
KerseyFabrications marked this conversation as resolved.
Expand Down Expand Up @@ -862,6 +908,37 @@ int main(int argc, char *argv[]) {
last_at_success = time(NULL);
}

/* Ring timeout watchdog — if ringing for too long without a termination URC,
* poll the modem to confirm call state before transitioning to idle. */
time_t last_ring = get_last_ring_time();
if (get_call_state() == CALL_STATE_RINGING_IN && last_ring > 0 &&
(now - last_ring) >= RING_TIMEOUT_SEC) {
/* Ask the modem if any calls are active (AT+CLCC lists current calls) */
at_response_t clcc_resp;
at_status_t clcc_rc = at_command_send(&g_at_ctx, "AT+CLCC", &clcc_resp, 3000);
if (clcc_rc == AT_OK && strstr(clcc_resp.data, "+CLCC:") == NULL) {
/* Modem confirms no active calls — carrier forwarded to voicemail */
set_call_state(CALL_STATE_IDLE);
set_last_ring_time(0);
char json[1024];
struct json_object *extra = json_object_new_object();
json_object_object_add(extra, "reason", json_object_new_string("ring_timeout"));
if (mqtt_build_event_json("call_ended", extra, json, sizeof(json)) >= 0) {
mqtt_publish_event(json);
}
json_object_put(extra);
OLOG_INFO("Ring timeout: modem confirms no active calls after %ds", RING_TIMEOUT_SEC);
} else if (clcc_rc == AT_OK) {
/* Call still active on modem — extend the timeout */
set_last_ring_time(now);
OLOG_INFO("Ring timeout check: modem reports call still active, extending");
} else {
/* AT command failed — extend timeout, don't make assumptions */
set_last_ring_time(now);
OLOG_WARNING("Ring timeout check: AT+CLCC failed (rc=%d), extending", clcc_rc);
}
}

/* Telemetry polling */
if (now - last_telemetry >= config.telemetry_interval_s) {
modem_telemetry_t telem;
Expand Down