Skip to content

Commit 75e93ce

Browse files
committed
app: Fix CMUX tracing and allow configurable drop
Fix CMUX tracing after the latest pipe changes. Allow TX timeout and drop policy to be defined by Kconfig. Remove unnecessary loop from trace backend as nRF library already loops on -EAGAIN. Signed-off-by: Seppo Takalo <seppo.takalo@nordicsemi.no>
1 parent 4ef72a9 commit 75e93ce

File tree

5 files changed

+92
-39
lines changed

5 files changed

+92
-39
lines changed

app/Kconfig

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -349,7 +349,18 @@ config SM_MODEM_TRACE_BACKEND_CMUX
349349

350350
endchoice # NRF_MODEM_LIB_TRACE_BACKEND
351351

352-
endif
352+
if SM_MODEM_TRACE_BACKEND_CMUX
353+
354+
config SM_MODEM_TRACE_DROP_ON_TIMEOUT
355+
bool "Drop modem trace data if the CMUX trace channel is slow"
356+
default y
357+
358+
config SM_MODEM_TRACE_CMUX_TX_TIMEOUT_MS
359+
int "Timeout for sending modem trace data over CMUX in milliseconds"
360+
default 100
361+
362+
endif # SM_MODEM_TRACE_BACKEND_CMUX
363+
endif # NRF_MODEM_LIB_TRACE
353364

354365
#
355366
# Hardware RX byte counting for UART

app/src/sm_cmux.c

Lines changed: 17 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -5,9 +5,8 @@
55
*/
66
#include "sm_cmux.h"
77
#include "sm_at_host.h"
8-
#if defined(CONFIG_SM_PPP)
98
#include "sm_ppp.h"
10-
#endif
9+
#include "sm_trace_backend_cmux.h"
1110
#include "sm_util.h"
1211
#include "sm_uart_handler.h"
1312
#include <zephyr/logging/log.h>
@@ -123,13 +122,17 @@ static void stop_work_fn(struct k_work *work)
123122
ARG_UNUSED(work);
124123

125124
if (sm_cmux_is_started()) {
126-
modem_cmux_release(&cmux.instance);
127-
128-
cmux.at_channel = 0;
129125
if (IS_ENABLED(CONFIG_SM_PPP)) {
130126
sm_ppp_detach();
131127
}
132128

129+
if (IS_ENABLED(CONFIG_SM_MODEM_TRACE_BACKEND_CMUX)) {
130+
sm_trace_backend_detach();
131+
}
132+
133+
modem_cmux_release(&cmux.instance);
134+
cmux.at_channel = 0;
135+
133136
/* Return AT host to UART pipe */
134137
sm_at_host_set_pipe(sm_at_host_get_urc_ctx(), cmux.uart_pipe);
135138
cmux.uart_pipe = NULL;
@@ -189,6 +192,15 @@ static int cmux_start(void)
189192
sm_at_host_release(sm_at_host_get_ctx_from(ppp_pipe));
190193
sm_ppp_attach(ppp_pipe);
191194
}
195+
if (IS_ENABLED(CONFIG_SM_MODEM_TRACE_BACKEND_CMUX)) {
196+
/* Reserve trace channel pipe for trace backend */
197+
struct modem_pipe *trace_pipe = sm_cmux_get_dlci(CMUX_MODEM_TRACE_CHANNEL);
198+
199+
LOG_DBG("Reserving CMUX trace channel pipe %p for trace backend",
200+
(void *)trace_pipe);
201+
sm_at_host_release(sm_at_host_get_ctx_from(trace_pipe));
202+
sm_trace_backend_attach(trace_pipe);
203+
}
192204

193205
/* Attach CMUX to UART pipe (AT host will be detached by transition) */
194206
ret = modem_cmux_attach(&cmux.instance, cmux.uart_pipe);

app/src/sm_cmux.h

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -16,9 +16,7 @@ enum cmux_channel {
1616
#if defined(CONFIG_SM_PPP)
1717
CMUX_PPP_CHANNEL = 2,
1818
#endif
19-
#if defined(CONFIG_SM_MODEM_TRACE_BACKEND_CMUX)
2019
CMUX_MODEM_TRACE_CHANNEL = 3,
21-
#endif
2220
CMUX_USER_CHANNEL_0,
2321
CMUX_USER_CHANNEL_1,
2422
CMUX_EXT_CHANNEL_COUNT

app/src/sm_trace_backend_cmux.c

Lines changed: 54 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -9,13 +9,14 @@
99
#include <zephyr/modem/pipe.h>
1010
#include <modem/nrf_modem_lib_trace.h>
1111
#include <modem/trace_backend.h>
12-
#include "sm_cmux.h"
12+
#include "sm_util.h"
1313

1414
LOG_MODULE_REGISTER(modem_trace_backend, CONFIG_MODEM_TRACE_BACKEND_LOG_LEVEL);
1515

1616
static K_SEM_DEFINE(tx_idle_sem, 0, 1);
1717

1818
static trace_backend_processed_cb trace_processed_callback;
19+
static struct modem_pipe *trace_pipe;
1920

2021
static void modem_pipe_event_handler(struct modem_pipe *pipe,
2122
enum modem_pipe_event event, void *user_data)
@@ -25,7 +26,14 @@ static void modem_pipe_event_handler(struct modem_pipe *pipe,
2526
case MODEM_PIPE_EVENT_TRANSMIT_IDLE:
2627
k_sem_give(&tx_idle_sem);
2728
break;
28-
29+
case MODEM_PIPE_EVENT_CLOSED:
30+
LOG_INF("Trace pipe closed");
31+
trace_pipe = NULL;
32+
break;
33+
case MODEM_PIPE_EVENT_OPENED:
34+
LOG_INF("Trace pipe opened");
35+
trace_pipe = pipe;
36+
break;
2937
default:
3038
break;
3139
}
@@ -38,58 +46,73 @@ int trace_backend_init(trace_backend_processed_cb trace_processed_cb)
3846
}
3947

4048
trace_processed_callback = trace_processed_cb;
49+
trace_pipe = NULL;
4150

4251
return 0;
4352
}
4453

4554
int trace_backend_deinit(void)
4655
{
47-
sm_cmux_release(CMUX_MODEM_TRACE_CHANNEL);
48-
56+
if (trace_pipe) {
57+
modem_pipe_release(trace_pipe);
58+
trace_pipe = NULL;
59+
}
4960
return 0;
5061
}
5162

63+
void sm_trace_backend_attach(struct modem_pipe *pipe)
64+
{
65+
modem_pipe_attach(pipe, modem_pipe_event_handler, NULL);
66+
}
67+
68+
void sm_trace_backend_detach(void)
69+
{
70+
if (trace_pipe) {
71+
modem_pipe_release(trace_pipe);
72+
trace_pipe = NULL;
73+
}
74+
}
75+
5276
int trace_backend_write(const void *data, size_t len)
5377
{
54-
struct modem_pipe *pipe = sm_cmux_reserve(CMUX_MODEM_TRACE_CHANNEL);
55-
const uint8_t *buf = (const uint8_t *)data;
56-
size_t sent_len = 0;
5778
int ret = 0;
5879

59-
if (!sm_cmux_dlci_is_open(CMUX_MODEM_TRACE_CHANNEL)) {
60-
LOG_DBG("Dropped %u bytes.", len);
80+
if (!trace_pipe || !sm_pipe_is_open(trace_pipe)) {
81+
LOG_DBG_RATELIMIT("Pipe closed, dropped %u bytes.", len);
6182
trace_processed_callback(len);
6283
return len;
6384
}
6485

65-
modem_pipe_attach(pipe, modem_pipe_event_handler, NULL);
66-
67-
while (sent_len < len) {
68-
ret = modem_pipe_transmit(pipe, buf, len - sent_len);
69-
if (ret < 0) {
70-
LOG_WRN("TX error (%d). Dropped %u bytes.", ret, len - sent_len);
86+
/* No need to retry here.
87+
* The nrf_modem_lib_trace.c:trace_fragment_write() handles
88+
* retrying if the backend returns -EAGAIN.
89+
*
90+
* It is important to call trace_processed_callback(len) for
91+
* every fragment written to ensure the trace fifos are not
92+
* overflowing. Even if we drop the fragment.
93+
*/
94+
95+
if (k_sem_take(&tx_idle_sem, K_MSEC(CONFIG_SM_MODEM_TRACE_CMUX_TX_TIMEOUT_MS)) != 0) {
96+
if (IS_ENABLED(CONFIG_SM_MODEM_TRACE_DROP_ON_TIMEOUT)) {
97+
LOG_WRN_RATELIMIT("Timeout, dropping %u bytes.", len);
7198
trace_processed_callback(len);
72-
return ret;
73-
} else if (ret == 0) {
74-
if (k_sem_take(&tx_idle_sem, K_SECONDS(1)) != 0) {
75-
LOG_WRN("TX timeout.");
76-
break;
77-
}
78-
} else {
79-
sent_len += ret;
80-
buf += ret;
99+
return len;
81100
}
101+
LOG_WRN_RATELIMIT("TX timeout.");
102+
return -EAGAIN;
82103
}
83104

84-
if (sent_len) {
85-
trace_processed_callback(sent_len);
86-
}
87-
88-
if (sent_len < len) {
89-
LOG_DBG("Sent %u out of %u bytes.", sent_len, len);
105+
ret = modem_pipe_transmit(trace_pipe, data, len);
106+
if (ret < 0) {
107+
LOG_WRN("TX error (%d). Dropped %u bytes.", ret, len);
108+
trace_processed_callback(len);
109+
return ret;
110+
} else if (ret == 0) {
111+
return -EAGAIN;
90112
}
113+
trace_processed_callback(ret);
91114

92-
return sent_len;
115+
return ret;
93116
}
94117

95118
struct nrf_modem_lib_trace_backend trace_backend = {

app/src/sm_trace_backend_cmux.h

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,9 @@
1+
/*
2+
* Copyright (c) 2026 Nordic Semiconductor ASA
3+
*
4+
* SPDX-License-Identifier: LicenseRef-Nordic-5-Clause
5+
*/
6+
7+
void sm_trace_backend_attach(struct modem_pipe *pipe);
8+
9+
void sm_trace_backend_detach(void);

0 commit comments

Comments
 (0)