modem: cmux: Clean debugging a bit

Full CMUX frames are way too much to fill the debug log
so disable those by default.
Sometimes it is enough to see the CMD and response types, without
hexdump.
Added also debug messages for opening and closing events.

Signed-off-by: Seppo Takalo <[email protected]>

Author: SeppoTakalo

subsys/modem/Kconfig

@@ -55,6 +55,12 @@ module = MODEM_CMUX
 module-str = modem_cmux
 source "subsys/logging/Kconfig.template.log_config"
 
+config MODEM_CMUX_LOG_FRAMES
+	bool "Log CMUX frames"
+	depends on MODEM_CMUX_LOG_LEVEL_DBG
+	help
+	  Enable logging of CMUX frames. This can produce a lot of log data.
+
 endif
 
 config MODEM_PIPE

subsys/modem/modem_cmux.c

@@ -101,6 +101,7 @@ static struct modem_cmux_command *modem_cmux_command_wrap(const uint8_t *data)
 	return (struct modem_cmux_command *)data;
 }
 
+#if CONFIG_MODEM_CMUX_LOG_FRAMES
 static const char *modem_cmux_frame_type_to_str(enum modem_cmux_frame_types frame_type)
 {
 	switch (frame_type) {
@@ -131,8 +132,14 @@ static void modem_cmux_log_frame(const struct modem_cmux_frame *frame,
 {
 	LOG_DBG("%s ch:%u cr:%u pf:%u type:%s dlen:%u", action, frame->dlci_address,
 		frame->cr, frame->pf, modem_cmux_frame_type_to_str(frame->type), frame->data_len);
-	LOG_HEXDUMP_DBG(frame->data, hexdump_len, "data:");
+	if (hexdump_len > 0) {
+		LOG_HEXDUMP_DBG(frame->data, hexdump_len, "data:");
+	}
 }
+#else
+#define modem_cmux_log_frame(frame, action, hexdump_len) \
+	do { ARG_UNUSED(frame); ARG_UNUSED(action); ARG_UNUSED(hexdump_len); } while (0)
+#endif /* CONFIG_MODEM_CMUX_LOG_FRAMES */
 
 static void modem_cmux_log_transmit_frame(const struct modem_cmux_frame *frame)
 {
@@ -225,14 +232,12 @@ static void modem_cmux_log_transmit_command(const struct modem_cmux_command *com
 {
 	LOG_DBG("ea:%u,cr:%u,type:%s", command->type.ea, command->type.cr,
 		modem_cmux_command_type_to_str(command->type.value));
-	LOG_HEXDUMP_DBG(command->value, command->length.value, "data:");
 }
 
 static void modem_cmux_log_received_command(const struct modem_cmux_command *command)
 {
 	LOG_DBG("ea:%u,cr:%u,type:%s", command->type.ea, command->type.cr,
 		modem_cmux_command_type_to_str(command->type.value));
-	LOG_HEXDUMP_DBG(command->value, command->length.value, "data:");
 }
 
 static void modem_cmux_raise_event(struct modem_cmux *cmux, enum modem_cmux_event event)
@@ -438,6 +443,7 @@ static void modem_cmux_on_cld_command(struct modem_cmux *cmux, struct modem_cmux
 		k_work_cancel_delayable(&cmux->disconnect_work);
 	}
 
+	LOG_DBG("CMUX disconnected");
 	cmux->state = MODEM_CMUX_STATE_DISCONNECTED;
 	k_mutex_lock(&cmux->transmit_rb_lock, K_FOREVER);
 	cmux->flow_control_on = false;
@@ -455,6 +461,7 @@ static void modem_cmux_on_control_frame_ua(struct modem_cmux *cmux)
 		return;
 	}
 
+	LOG_DBG("CMUX connected");
 	cmux->state = MODEM_CMUX_STATE_CONNECTED;
 	k_mutex_lock(&cmux->transmit_rb_lock, K_FOREVER);
 	cmux->flow_control_on = true;
@@ -534,6 +541,7 @@ static void modem_cmux_on_control_frame_sabm(struct modem_cmux *cmux)
 		return;
 	}
 
+	LOG_DBG("CMUX connection request received");
 	cmux->state = MODEM_CMUX_STATE_CONNECTED;
 	k_mutex_lock(&cmux->transmit_rb_lock, K_FOREVER);
 	cmux->flow_control_on = true;
@@ -561,7 +569,7 @@ static void modem_cmux_on_control_frame(struct modem_cmux *cmux)
 		break;
 
 	default:
-		LOG_WRN("Unknown %s frame type", "control");
+		LOG_WRN("Unknown %s frame type %d", "control", cmux->frame.type);
 		break;
 	}
 }
@@ -586,6 +594,7 @@ static void modem_cmux_on_dlci_frame_ua(struct modem_cmux_dlci *dlci)
 {
 	switch (dlci->state) {
 	case MODEM_CMUX_DLCI_STATE_OPENING:
+		LOG_DBG("DLCI %u opened", dlci->dlci_address);
 		dlci->state = MODEM_CMUX_DLCI_STATE_OPEN;
 		modem_pipe_notify_opened(&dlci->pipe);
 		k_work_cancel_delayable(&dlci->open_work);
@@ -595,6 +604,7 @@ static void modem_cmux_on_dlci_frame_ua(struct modem_cmux_dlci *dlci)
 		break;
 
 	case MODEM_CMUX_DLCI_STATE_CLOSING:
+		LOG_DBG("DLCI %u closed", dlci->dlci_address);
 		dlci->state = MODEM_CMUX_DLCI_STATE_CLOSED;
 		modem_pipe_notify_closed(&dlci->pipe);
 		k_work_cancel_delayable(&dlci->close_work);
@@ -637,6 +647,7 @@ static void modem_cmux_on_dlci_frame_sabm(struct modem_cmux_dlci *dlci)
 		return;
 	}
 
+	LOG_DBG("DLCI %u SABM request accepted, DLCI opened", dlci->dlci_address);
 	dlci->state = MODEM_CMUX_DLCI_STATE_OPEN;
 	modem_pipe_notify_opened(&dlci->pipe);
 	k_mutex_lock(&dlci->receive_rb_lock, K_FOREVER);
@@ -655,6 +666,7 @@ static void modem_cmux_on_dlci_frame_disc(struct modem_cmux_dlci *dlci)
 		return;
 	}
 
+	LOG_DBG("DLCI %u disconnected", dlci->dlci_address);
 	dlci->state = MODEM_CMUX_DLCI_STATE_CLOSED;
 	modem_pipe_notify_closed(&dlci->pipe);
 }
@@ -690,7 +702,8 @@ static void modem_cmux_on_dlci_frame(struct modem_cmux *cmux)
 		break;
 
 	default:
-		LOG_WRN("Unknown %s frame type", "DLCI");
+		LOG_WRN("Unknown %s frame type (%d, DLCI %d)", "DLCI", cmux->frame.type,
+			cmux->frame.dlci_address);
 		break;
 	}
 }