From 6fb01c7337bd41f6f8deed392f6369301df3eeb0 Mon Sep 17 00:00:00 2001 From: "Roger A. Light" Date: Wed, 26 Nov 2025 14:31:50 +0000 Subject: [PATCH] Add broker logging for protocol errors --- lib/handle_ping.c | 7 ++++++ lib/handle_pubackcomp.c | 14 +++++++++++ lib/handle_pubrec.c | 24 +++++++++++++++++-- lib/handle_pubrel.c | 28 ++++++++++++++++++++-- lib/handle_suback.c | 4 ++++ lib/handle_unsuback.c | 4 ++++ lib/packet_mosq.c | 4 ++++ src/database.c | 5 ++++ src/handle_auth.c | 16 ++++++++++++- src/handle_connack.c | 1 + src/handle_connect.c | 52 +++++++++++++++++++++++++++++++++------- src/handle_disconnect.c | 4 ++++ src/handle_publish.c | 5 ++++ src/handle_subscribe.c | 3 +++ src/handle_unsubscribe.c | 2 ++ src/property_broker.c | 5 ++++ src/send_auth.c | 5 +++- 17 files changed, 168 insertions(+), 15 deletions(-) diff --git a/lib/handle_ping.c b/lib/handle_ping.c index 545e2784..659cee2a 100644 --- a/lib/handle_ping.c +++ b/lib/handle_ping.c @@ -42,6 +42,9 @@ int handle__pingreq(struct mosquitto *mosq) assert(mosq); if(mosquitto__get_state(mosq) != mosq_cs_active){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PINGREQ before session is active.", mosq->id); +#endif return MOSQ_ERR_PROTOCOL; } if(mosq->in_packet.command != CMD_PINGREQ){ @@ -61,12 +64,16 @@ int handle__pingresp(struct mosquitto *mosq) assert(mosq); if(mosquitto__get_state(mosq) != mosq_cs_active){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PINGRESP before session is active.", mosq->id); +#endif return MOSQ_ERR_PROTOCOL; } mosq->ping_t = 0; /* No longer waiting for a PINGRESP. */ #ifdef WITH_BROKER if(mosq->bridge == NULL){ + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PINGRESP when not a bridge.", mosq->id); return MOSQ_ERR_PROTOCOL; } log__printf(NULL, MOSQ_LOG_DEBUG, "Received PINGRESP from %s", SAFE_PRINT(mosq->id)); diff --git a/lib/handle_pubackcomp.c b/lib/handle_pubackcomp.c index 30d91239..75221d47 100644 --- a/lib/handle_pubackcomp.c +++ b/lib/handle_pubackcomp.c @@ -49,6 +49,9 @@ int handle__pubackcomp(struct mosquitto *mosq, const char *type) assert(mosq); if(mosquitto__get_state(mosq) != mosq_cs_active){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: %s before session is active.", mosq->id, type); +#endif return MOSQ_ERR_PROTOCOL; } if(mosq->protocol != mosq_p_mqtt31){ @@ -75,6 +78,9 @@ int handle__pubackcomp(struct mosquitto *mosq, const char *type) qos = 2; } if(mid == 0){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: %s with mid = 0.", mosq->id, type); +#endif return MOSQ_ERR_PROTOCOL; } @@ -101,6 +107,10 @@ int handle__pubackcomp(struct mosquitto *mosq, const char *type) ){ mosquitto_property_free_all(&properties); +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: %s with reason code = %d.", + mosq->id, type, reason_code); +#endif return MOSQ_ERR_PROTOCOL; } }else{ @@ -109,6 +119,10 @@ int handle__pubackcomp(struct mosquitto *mosq, const char *type) ){ mosquitto_property_free_all(&properties); +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: %s with reason code = %d.", + mosq->id, type, reason_code); +#endif return MOSQ_ERR_PROTOCOL; } } diff --git a/lib/handle_pubrec.c b/lib/handle_pubrec.c index 13e78128..9d956bf1 100644 --- a/lib/handle_pubrec.c +++ b/lib/handle_pubrec.c @@ -47,6 +47,9 @@ int handle__pubrec(struct mosquitto *mosq) assert(mosq); if(mosquitto__get_state(mosq) != mosq_cs_active){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBREC before session is active.", mosq->id); +#endif return MOSQ_ERR_PROTOCOL; } if(mosq->in_packet.command != CMD_PUBREC){ @@ -55,7 +58,13 @@ int handle__pubrec(struct mosquitto *mosq) rc = packet__read_uint16(&mosq->in_packet, &mid); if(rc) return rc; - if(mid == 0) return MOSQ_ERR_PROTOCOL; + if(mid == 0){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBREC with mid = 0.", + mosq->id); +#endif + return MOSQ_ERR_PROTOCOL; + } if(mosq->protocol == mosq_p_mqtt5 && mosq->in_packet.remaining_length > 2){ rc = packet__read_byte(&mosq->in_packet, &reason_code); @@ -71,12 +80,23 @@ int handle__pubrec(struct mosquitto *mosq) && reason_code != MQTT_RC_QUOTA_EXCEEDED && reason_code != MQTT_RC_PAYLOAD_FORMAT_INVALID){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBREC with reason code = %d.", + mosq->id, reason_code); +#endif return MOSQ_ERR_PROTOCOL; } if(mosq->in_packet.remaining_length > 3){ rc = property__read_all(CMD_PUBREC, &mosq->in_packet, &properties); - if(rc) return rc; + if(rc){ + if(rc == MOSQ_ERR_PROTOCOL){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBREC with invalid properties.", mosq->id); +#endif + } + return rc; + } /* Immediately free, we don't do anything with Reason String or User Property at the moment */ mosquitto_property_free_all(&properties); diff --git a/lib/handle_pubrel.c b/lib/handle_pubrel.c index 0e5251c6..3e226028 100644 --- a/lib/handle_pubrel.c +++ b/lib/handle_pubrel.c @@ -51,6 +51,9 @@ int handle__pubrel(struct mosquitto *mosq) assert(mosq); if(mosquitto__get_state(mosq) != mosq_cs_active){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBREL before session is active.", mosq->id); +#endif return MOSQ_ERR_PROTOCOL; } if(mosq->protocol != mosq_p_mqtt31 && mosq->in_packet.command != (CMD_PUBREL|2)){ @@ -59,24 +62,45 @@ int handle__pubrel(struct mosquitto *mosq) if(mosq->protocol != mosq_p_mqtt31){ if((mosq->in_packet.command&0x0F) != 0x02){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBREL with non-zero reserved flags (%02X).", + mosq->id, mosq->in_packet.command); +#endif return MOSQ_ERR_PROTOCOL; } } rc = packet__read_uint16(&mosq->in_packet, &mid); if(rc) return rc; - if(mid == 0) return MOSQ_ERR_PROTOCOL; + if(mid == 0){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBREL with mid = 0.", + mosq->id); +#endif + return MOSQ_ERR_PROTOCOL; + } if(mosq->protocol == mosq_p_mqtt5 && mosq->in_packet.remaining_length > 2){ rc = packet__read_byte(&mosq->in_packet, &reason_code); if(rc) return rc; if(reason_code != MQTT_RC_SUCCESS && reason_code != MQTT_RC_PACKET_ID_NOT_FOUND){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBREL with reason code = %d.", + mosq->id, reason_code); +#endif return MOSQ_ERR_PROTOCOL; } if(mosq->in_packet.remaining_length > 3){ rc = property__read_all(CMD_PUBREL, &mosq->in_packet, &properties); - if(rc) return rc; + if(rc){ + if(rc == MOSQ_ERR_PROTOCOL){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: PUBREL with invalid properties.", mosq->id); +#endif + } + return rc; + } } } diff --git a/lib/handle_suback.c b/lib/handle_suback.c index 100177cc..de855fff 100644 --- a/lib/handle_suback.c +++ b/lib/handle_suback.c @@ -48,6 +48,9 @@ int handle__suback(struct mosquitto *mosq) assert(mosq); if(mosquitto__get_state(mosq) != mosq_cs_active){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: SUBACK before session is active.", mosq->id); +#endif return MOSQ_ERR_PROTOCOL; } if(mosq->in_packet.command != CMD_SUBACK){ @@ -57,6 +60,7 @@ int handle__suback(struct mosquitto *mosq) #ifdef WITH_BROKER if(mosq->bridge == NULL){ /* Client is not a bridge, so shouldn't be sending SUBACK */ + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: SUBACK when not a bridge.", mosq->id); return MOSQ_ERR_PROTOCOL; } log__printf(NULL, MOSQ_LOG_DEBUG, "Received SUBACK from %s", SAFE_PRINT(mosq->id)); diff --git a/lib/handle_unsuback.c b/lib/handle_unsuback.c index 94e45f48..7cd21631 100644 --- a/lib/handle_unsuback.c +++ b/lib/handle_unsuback.c @@ -48,6 +48,9 @@ int handle__unsuback(struct mosquitto *mosq) assert(mosq); if(mosquitto__get_state(mosq) != mosq_cs_active){ +#ifdef WITH_BROKER + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: UNSUBACK before session is active.", mosq->id); +#endif return MOSQ_ERR_PROTOCOL; } if(mosq->in_packet.command != CMD_UNSUBACK){ @@ -57,6 +60,7 @@ int handle__unsuback(struct mosquitto *mosq) #ifdef WITH_BROKER if(mosq->bridge == NULL){ /* Client is not a bridge, so shouldn't be sending SUBACK */ + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s: UNSUBACK when not a bridge.", mosq->id); return MOSQ_ERR_PROTOCOL; } log__printf(NULL, MOSQ_LOG_DEBUG, "Received UNSUBACK from %s", SAFE_PRINT(mosq->id)); diff --git a/lib/packet_mosq.c b/lib/packet_mosq.c index 698a5a1c..87c581fe 100644 --- a/lib/packet_mosq.c +++ b/lib/packet_mosq.c @@ -398,11 +398,15 @@ int packet__read(struct mosquitto *mosq) G_BYTES_RECEIVED_INC(1); /* Clients must send CONNECT as their first command. */ if(!(mosq->bridge) && state == mosq_cs_new && (byte&0xF0) != CMD_CONNECT){ + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: First packet not CONNECT (%02X).", + mosq->address, mosq->remote_port, byte); return MOSQ_ERR_PROTOCOL; }else if((byte&0xF0) == CMD_RESERVED){ if(mosq->protocol == mosq_p_mqtt5){ send__disconnect(mosq, MQTT_RC_PROTOCOL_ERROR, NULL); } + log__printf(NULL, MOSQ_LOG_INFO, "Protocol error from %s:%d: RESERVED packet.", + mosq->address, mosq->remote_port); return MOSQ_ERR_PROTOCOL; } #endif diff --git a/src/database.c b/src/database.c index 6f4b0dd0..9f35a124 100644 --- a/src/database.c +++ b/src/database.c @@ -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; diff --git a/src/handle_auth.c b/src/handle_auth.c index 812f368a..60a5499e 100644 --- a/src/handle_auth.c +++ b/src/handle_auth.c @@ -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); diff --git a/src/handle_connack.c b/src/handle_connack.c index e6418662..a11bcf7c 100644 --- a/src/handle_connack.c +++ b/src/handle_connack.c @@ -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){ diff --git a/src/handle_connect.c b/src/handle_connect.c index bb86c9aa..382de1c2 100644 --- a/src/handle_connect.c +++ b/src/handle_connect.c @@ -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; } diff --git a/src/handle_disconnect.c b/src/handle_disconnect.c index 4de8bdc7..c4cb2f23 100644 --- a/src/handle_disconnect.c +++ b/src/handle_disconnect.c @@ -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; } diff --git a/src/handle_publish.c b/src/handle_publish.c index d3b88e68..fbb9153c 100644 --- a/src/handle_publish.c +++ b/src/handle_publish.c @@ -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{ diff --git a/src/handle_subscribe.c b/src/handle_subscribe.c index ee17daab..6af52c31 100644 --- a/src/handle_subscribe.c +++ b/src/handle_subscribe.c @@ -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); diff --git a/src/handle_unsubscribe.c b/src/handle_unsubscribe.c index 8c0af2a8..50a65379 100644 --- a/src/handle_unsubscribe.c +++ b/src/handle_unsubscribe.c @@ -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; diff --git a/src/property_broker.c b/src/property_broker.c index f2fb5427..5aca4063 100644 --- a/src/property_broker.c +++ b/src/property_broker.c @@ -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; diff --git a/src/send_auth.c b/src/send_auth.c index dbd0b8e8..fa518aa5 100644 --- a/src/send_auth.c +++ b/src/send_auth.c @@ -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);