Add broker logging for protocol errors

This commit is contained in:
Roger A. Light
2025-11-26 14:31:50 +00:00
parent a0fa07f9ed
commit 6fb01c7337
17 changed files with 168 additions and 15 deletions

View File

@@ -404,8 +404,10 @@ int db__message_delete_outgoing(struct mosquitto *context, uint16_t mid, enum mo
DL_FOREACH_SAFE(context->msgs_out.inflight, tail, tmp){
if(tail->mid == mid){
if(tail->qos != qos){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: Mismatched QoS (%d:%d) when deleting outgoing message.", context->id, tail->qos, qos);
return MOSQ_ERR_PROTOCOL;
}else if(qos == 2 && tail->state != expect_state){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: Mismatched state (%d:%d) when deleting outgoing message.", context->id, tail->state, expect_state);
return MOSQ_ERR_PROTOCOL;
}
db__message_remove_from_inflight(&context->msgs_out, tail);
@@ -635,6 +637,7 @@ int db__message_update_outgoing(struct mosquitto *context, uint16_t mid, enum mo
DL_FOREACH(context->msgs_out.inflight, tail){
if(tail->mid == mid){
if(tail->qos != qos){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: Mismatched QoS (%d:%d) when updating outgoing message.", context->id, tail->qos, qos);
return MOSQ_ERR_PROTOCOL;
}
tail->state = state;
@@ -972,6 +975,7 @@ int db__message_remove_incoming(struct mosquitto* context, uint16_t mid)
DL_FOREACH_SAFE(context->msgs_in.inflight, tail, tmp){
if(tail->mid == mid) {
if(tail->store->qos != 2){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: Incorrect QoS (%d) when deleting incoming message.", context->id, tail->store->qos);
return MOSQ_ERR_PROTOCOL;
}
db__message_remove_from_inflight(&context->msgs_in, tail);
@@ -997,6 +1001,7 @@ int db__message_release_incoming(struct mosquitto *context, uint16_t mid)
DL_FOREACH_SAFE(context->msgs_in.inflight, tail, tmp){
if(tail->mid == mid){
if(tail->store->qos != 2){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: Incorrect QoS (%d) when releasing incoming message.", context->id, tail->store->qos);
return MOSQ_ERR_PROTOCOL;
}
topic = tail->store->topic;

View File

@@ -44,7 +44,12 @@ int handle__auth(struct mosquitto *context)
if(!context) return MOSQ_ERR_INVAL;
if(context->protocol != mosq_p_mqtt5 || context->auth_method == NULL){
if(context->protocol != mosq_p_mqtt5){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: AUTH packet when session not MQTT v5.0.", context->id);
return MOSQ_ERR_PROTOCOL;
}
if(context->auth_method == NULL){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: AUTH packet without existing auth-method.", context->id);
return MOSQ_ERR_PROTOCOL;
}
if(context->in_packet.command != CMD_AUTH){
@@ -57,6 +62,8 @@ int handle__auth(struct mosquitto *context)
&& reason_code != MQTT_RC_REAUTHENTICATE){
send__disconnect(context, MQTT_RC_PROTOCOL_ERROR, NULL);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: AUTH packet with reason-code = %d.",
context->id, reason_code);
return MOSQ_ERR_PROTOCOL;
}
@@ -65,6 +72,9 @@ int handle__auth(struct mosquitto *context)
&& context->state != mosq_cs_authenticating && context->state != mosq_cs_reauthenticating)){
send__disconnect(context, MQTT_RC_PROTOCOL_ERROR, NULL);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: AUTH reauthentication packet before session is active,",
context->id);
log__printf(NULL, MOSQ_LOG_INFO, " or attempted to continue authentication when no authentication in progress.");
return MOSQ_ERR_PROTOCOL;
}
@@ -78,6 +88,8 @@ int handle__auth(struct mosquitto *context)
if(mosquitto_property_read_string(properties, MQTT_PROP_AUTHENTICATION_METHOD, &auth_method, false) == NULL){
mosquitto_property_free_all(&properties);
send__disconnect(context, MQTT_RC_UNSPECIFIED, NULL);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: AUTH packet without auth-method property.",
context->id);
return MOSQ_ERR_PROTOCOL;
}
@@ -86,6 +98,8 @@ int handle__auth(struct mosquitto *context)
mosquitto__free(auth_method);
mosquitto_property_free_all(&properties);
send__disconnect(context, MQTT_RC_PROTOCOL_ERROR, NULL);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: AUTH packet with non-matching auth-method property (%s:%s).",
context->id, context->auth_method, auth_method);
return MOSQ_ERR_PROTOCOL;
}
mosquitto__free(auth_method);

View File

@@ -44,6 +44,7 @@ int handle__connack(struct mosquitto *context)
return MOSQ_ERR_INVAL;
}
if(context->bridge == NULL){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: CONNACK when not a bridge.", context->id);
return MOSQ_ERR_PROTOCOL;
}
if(context->in_packet.command != CMD_CONNACK){

View File

@@ -356,6 +356,8 @@ static int will__read(struct mosquitto *context, const char *client_id, struct m
rc = packet__read_string(&context->in_packet, &will_struct->msg.topic, &tlen);
if(rc) goto error_cleanup;
if(!tlen){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: Will with empty topic.",
context->id);
rc = MOSQ_ERR_PROTOCOL;
goto error_cleanup;
}
@@ -463,7 +465,8 @@ int handle__connect(struct mosquitto *context)
/* Don't accept multiple CONNECT commands. */
if(context->state != mosq_cs_new){
log__printf(NULL, MOSQ_LOG_NOTICE, "Bad client %s sending multiple CONNECT messages.", context->id);
log__printf(NULL, MOSQ_LOG_NOTICE, "Bad client %s:%d sending multiple CONNECT messages.",
context->address, context->remote_port);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
@@ -472,28 +475,36 @@ int handle__connect(struct mosquitto *context)
* because the length is fixed and we can check that. Removes the need
* for another malloc as well. */
if(packet__read_uint16(&context->in_packet, &slen)){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with missing protocol string length.",
context->address, context->remote_port);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
if(slen != 4 /* MQTT */ && slen != 6 /* MQIsdp */){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with incorrect protocol string length (%d).",
context->address, context->remote_port, slen);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
if(packet__read_bytes(&context->in_packet, protocol_name, slen)){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with missing protocol string.",
context->address, context->remote_port);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
protocol_name[slen] = '\0';
if(packet__read_byte(&context->in_packet, &protocol_version)){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with missing protocol version.",
context->address, context->remote_port);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
if(!strcmp(protocol_name, PROTOCOL_NAME_v31)){
if((protocol_version&0x7F) != PROTOCOL_VERSION_v31){
if(db.config->connection_messages == true){
log__printf(NULL, MOSQ_LOG_INFO, "Invalid protocol version %d in CONNECT from %s.",
protocol_version, context->address);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with invalid protocol version (%d).",
context->address, context->remote_port, protocol_version);
}
send__connack(context, 0, CONNACK_REFUSED_PROTOCOL_VERSION, NULL);
rc = MOSQ_ERR_PROTOCOL;
@@ -514,8 +525,8 @@ int handle__connect(struct mosquitto *context)
context->protocol = mosq_p_mqtt5;
}else{
if(db.config->connection_messages == true){
log__printf(NULL, MOSQ_LOG_INFO, "Invalid protocol version %d in CONNECT from %s.",
protocol_version, context->address);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with invalid protocol version (%d).",
context->address, context->remote_port, protocol_version);
}
send__connack(context, 0, CONNACK_REFUSED_PROTOCOL_VERSION, NULL);
rc = MOSQ_ERR_PROTOCOL;
@@ -523,13 +534,15 @@ int handle__connect(struct mosquitto *context)
}
if((context->in_packet.command&0x0F) != 0x00){
/* Reserved flags not set to 0, must disconnect. */
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with non-zero reserved flags (%02X).",
context->address, context->remote_port, context->in_packet.command);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
}else{
if(db.config->connection_messages == true){
log__printf(NULL, MOSQ_LOG_INFO, "Invalid protocol \"%s\" in CONNECT from %s.",
protocol_name, context->address);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with invalid protocol \"%s\".",
context->address, context->remote_port, protocol_name);
}
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
@@ -539,11 +552,15 @@ int handle__connect(struct mosquitto *context)
}
if(packet__read_byte(&context->in_packet, &connect_flags)){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with missing connect flags.",
context->address, context->remote_port);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
if(context->protocol == mosq_p_mqtt311 || context->protocol == mosq_p_mqtt5){
if((connect_flags & 0x01) != 0x00){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with non-zero connect reserved flag (%02X).",
context->address, context->remote_port, connect_flags);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
@@ -560,8 +577,8 @@ int handle__connect(struct mosquitto *context)
will = connect_flags & 0x04;
will_qos = (connect_flags & 0x18) >> 3;
if(will_qos == 3){
log__printf(NULL, MOSQ_LOG_INFO, "Invalid Will QoS in CONNECT from %s.",
context->address);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with invalid Will QoS (%d).",
context->address, context->remote_port, will_qos);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
@@ -582,6 +599,8 @@ int handle__connect(struct mosquitto *context)
keepalive__remove(context);
if(packet__read_uint16(&context->in_packet, &(context->keepalive))){
log__printf(NULL, MOSQ_LOG_INFO, "%s sent CONNECT with missing keepalive.",
context->id);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
@@ -608,6 +627,8 @@ int handle__connect(struct mosquitto *context)
mosquitto_property_free_all(&properties); /* FIXME - TEMPORARY UNTIL PROPERTIES PROCESSED */
if(packet__read_string(&context->in_packet, &client_id, &slen)){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: CONNECT with missing clientid string.",
context->address);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
@@ -615,6 +636,8 @@ int handle__connect(struct mosquitto *context)
if(slen == 0){
if(context->protocol == mosq_p_mqtt31){
send__connack(context, 0, CONNACK_REFUSED_IDENTIFIER_REJECTED, NULL);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: v3.1 CONNECT with zero length clientid.",
context->address, context->remote_port);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}else{ /* mqtt311/mqtt5 */
@@ -632,6 +655,8 @@ int handle__connect(struct mosquitto *context)
}else{
send__connack(context, 0, MQTT_RC_UNSPECIFIED, NULL);
}
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: CONNECT with zero length clientid when forbidden.",
context->address, context->remote_port);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}else{
@@ -668,6 +693,8 @@ int handle__connect(struct mosquitto *context)
}else{
if(context->protocol == mosq_p_mqtt311 || context->protocol == mosq_p_mqtt5){
if(will_qos != 0 || will_retain != 0){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: CONNECT without Will with non-zero QoS (%d) or retain (%d).",
client_id, will_qos, will_retain);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
@@ -684,6 +711,8 @@ int handle__connect(struct mosquitto *context)
/* Username flag given, but no username. Ignore. */
username_flag = 0;
}else{
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: CONNECT with username flag but no username.",
client_id);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
@@ -707,6 +736,8 @@ int handle__connect(struct mosquitto *context)
if(context->protocol == mosq_p_mqtt31){
/* Password flag given, but no password. Ignore. */
}else{
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: CONNECT with password flag but no password.",
client_id);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}
@@ -715,6 +746,9 @@ int handle__connect(struct mosquitto *context)
if(context->in_packet.pos != context->in_packet.remaining_length){
/* Surplus data at end of packet, this must be an error. */
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: CONNECT packet with overlong remaining length (%d:%d).",
context->id, context->in_packet.pos, context->in_packet.remaining_length);
rc = MOSQ_ERR_PROTOCOL;
goto handle_connect_error;
}

View File

@@ -59,11 +59,15 @@ int handle__disconnect(struct mosquitto *context)
mosquitto_property_free_all(&properties); /* FIXME - TEMPORARY UNTIL PROPERTIES PROCESSED */
if(context->in_packet.pos != context->in_packet.remaining_length){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: DISCONNECT packet with overlong remaining length (%d:%d).",
context->id, context->in_packet.pos, context->in_packet.remaining_length);
return MOSQ_ERR_PROTOCOL;
}
log__printf(NULL, MOSQ_LOG_DEBUG, "Received DISCONNECT from %s", context->id);
if(context->protocol == mosq_p_mqtt311 || context->protocol == mosq_p_mqtt5){
if((context->in_packet.command&0x0F) != 0x00){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: DISCONNECT packet with incorrect flags %02X.",
context->id, context->in_packet.command);
do_disconnect(context, MOSQ_ERR_PROTOCOL);
return MOSQ_ERR_PROTOCOL;
}

View File

@@ -54,6 +54,7 @@ int handle__publish(struct mosquitto *context)
uint16_t mid = 0;
if(context->state != mosq_cs_active){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBLISH before session is active.", context->id);
return MOSQ_ERR_PROTOCOL;
}
@@ -106,6 +107,7 @@ int handle__publish(struct mosquitto *context)
}
if(mid == 0){
db__msg_store_free(msg);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBLISH packet with mid = 0.", context->id);
return MOSQ_ERR_PROTOCOL;
}
/* It is important to have a separate copy of mid, because msg may be
@@ -188,6 +190,8 @@ int handle__publish(struct mosquitto *context)
rc = alias__find(context, &msg->topic, (uint16_t)topic_alias);
if(rc){
db__msg_store_free(msg);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBLISH invalid topic alias (%d).",
context->id, topic_alias);
return MOSQ_ERR_PROTOCOL;
}
}
@@ -359,6 +363,7 @@ int handle__publish(struct mosquitto *context)
rc2 = send__pubrec(context, stored->source_mid, 0, NULL);
if(rc2) rc = rc2;
}else{
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBLISH with dup = %d.", context->id, dup);
return MOSQ_ERR_PROTOCOL;
}
}else{

View File

@@ -50,6 +50,7 @@ int handle__subscribe(struct mosquitto *context)
if(!context) return MOSQ_ERR_INVAL;
if(context->state != mosq_cs_active){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: SUBSCRIBE before session is active.", context->id);
return MOSQ_ERR_PROTOCOL;
}
if(context->in_packet.command != (CMD_SUBSCRIBE|2)){
@@ -73,6 +74,7 @@ int handle__subscribe(struct mosquitto *context)
* MOSQ_ERR_MALFORMED_PACKET, but this is would change the library
* return codes so needs doc changes as well. */
if(rc == MOSQ_ERR_PROTOCOL){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: SUBSCRIBE packet with invalid properties.", context->id);
return MOSQ_ERR_MALFORMED_PACKET;
}else{
return rc;
@@ -134,6 +136,7 @@ int handle__subscribe(struct mosquitto *context)
if((subscription_options & MQTT_SUB_OPT_NO_LOCAL) && !strncmp(sub, "$share/", 7)){
mosquitto__free(sub);
mosquitto__free(payload);
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: $share subscription with no-local set.", context->id);
return MOSQ_ERR_PROTOCOL;
}
retain_handling = (subscription_options & 0x30);

View File

@@ -43,6 +43,7 @@ int handle__unsubscribe(struct mosquitto *context)
if(!context) return MOSQ_ERR_INVAL;
if(context->state != mosq_cs_active){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: UNSUBSCRIBE before session is active.", context->id);
return MOSQ_ERR_PROTOCOL;
}
if(context->in_packet.command != (CMD_UNSUBSCRIBE|2)){
@@ -65,6 +66,7 @@ int handle__unsubscribe(struct mosquitto *context)
* MOSQ_ERR_MALFORMED_PACKET, but this is would change the library
* return codes so needs doc changes as well. */
if(rc == MOSQ_ERR_PROTOCOL){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: UNSUBSCRIBE packet with invalid properties.", context->id);
return MOSQ_ERR_MALFORMED_PACKET;
}else{
return rc;

View File

@@ -38,6 +38,7 @@ int property__process_connect(struct mosquitto *context, mosquitto_property **pr
context->session_expiry_interval = p->value.i32;
}else if(p->identifier == MQTT_PROP_RECEIVE_MAXIMUM){
if(p->value.i16 == 0){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: CONNECT packet with receive-maximum = 0.", context->id);
return MOSQ_ERR_PROTOCOL;
}
@@ -45,6 +46,7 @@ int property__process_connect(struct mosquitto *context, mosquitto_property **pr
context->msgs_out.inflight_quota = context->msgs_out.inflight_maximum;
}else if(p->identifier == MQTT_PROP_MAXIMUM_PACKET_SIZE){
if(p->value.i32 == 0){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: CONNECT packet with maximum-packet-size = 0.", context->id);
return MOSQ_ERR_PROTOCOL;
}
context->maximum_packet_size = p->value.i32;
@@ -103,6 +105,7 @@ int property__process_will(struct mosquitto *context, struct mosquitto_message_a
default:
msg->properties = msg_properties;
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: CONNECT packet invalid property (%d).", context->id, p->identifier);
return MOSQ_ERR_PROTOCOL;
break;
}
@@ -124,6 +127,8 @@ int property__process_disconnect(struct mosquitto *context, mosquitto_property *
while(p){
if(p->identifier == MQTT_PROP_SESSION_EXPIRY_INTERVAL){
if(context->session_expiry_interval == 0 && p->value.i32 != 0){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: DISCONNECT packet with mismatched session-expiry-interval (%d:%d).",
context->id, context->session_expiry_interval, p->value.i32);
return MOSQ_ERR_PROTOCOL;
}
context->session_expiry_interval = p->value.i32;

View File

@@ -33,7 +33,10 @@ int send__auth(struct mosquitto *context, uint8_t reason_code, const void *auth_
uint32_t remaining_length;
if(context->auth_method == NULL) return MOSQ_ERR_INVAL;
if(context->protocol != mosq_p_mqtt5) return MOSQ_ERR_PROTOCOL;
if(context->protocol != mosq_p_mqtt5){
log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: Sending AUTH packet when session not MQTT v5.0.", context->id);
return MOSQ_ERR_PROTOCOL;
}
log__printf(NULL, MOSQ_LOG_DEBUG, "Sending AUTH to %s (rc%d, %s)", context->id, reason_code, context->auth_method);