mqtt: change the logging type of user properties

MQTT5 logs user properties wherein a user can send any metadata
over the wire in the form of key-value pairs.
MQTT logger used these key-value pairs directly to populate the common
"properties" field. But we do not want to use arbitrary json keys
(which may contain arbitrary characters)

1. A fixed new child object to the common "properties" called
   "user_properties" which carries a list of dicts.
2. Each key-value pair received as a part of the user properties is now
   saved as:

"properties": {
    ...
    "user_properties": [{"key": "mykey", "value": "myvalue"}]
    ...
}

instead of:

"properties": {
    ...
    "key": "value"
    ...
}

Ticket: 8785

doc/userguide/output/eve/eve-json-format.rst

@@ -2259,7 +2259,6 @@ Common fields from the MQTT fixed header:
 * "\*.retain": Boolean value of the MQTT 'retain' flag.
 * "\*.dup": Boolean value of the MQTT 'dup' (duplicate) flag.
 
-
 MQTT CONNECT fields
 ~~~~~~~~~~~~~~~~~~~
 
@@ -2310,7 +2309,7 @@ Example of MQTT CONNECT logging:
         "message_expiry_interval": 133,
         "payload_format_indicator": 144,
         "response_topic": "response_topic1",
-        "userprop": "uservalue",
+        "user_properties": [{"key": "userprop", "value": "uservalue"}],
         "will_delay_interval": 200
       }
     },
@@ -2319,8 +2318,7 @@ Example of MQTT CONNECT logging:
       "receive_maximum": 222,
       "session_expiry_interval": 555,
       "topic_alias_maximum": 666,
-      "userprop1": "userval1",
-      "userprop2": "userval2"
+      "user_properties": [{"key": "userprop1", "value": "userval1"}, {"key": "userprop2", "value": "userval2"}]
     }
   }
 
@@ -2372,7 +2370,7 @@ Example of MQTT PUBLISH logging:
       "payload_format_indicator": 88,
       "response_topic": "response_topic1",
       "topic_alias": 5,
-      "userprop": "userval"
+      "user_properties": [{"key": "userprop", "value":"userval"}]
     }
   }
 

doc/userguide/upgrade.rst

@@ -63,6 +63,11 @@ Logging Changes
   ``stats.app_layer.*.ftp-data`` becomes ``stats.app_layer.*.ftp_data``,
   and same for bittorrent_dht
 
+- MQTT user properties are now logged as a new object called ``user_properties``
+  as an array of key-value pairs like ``[{"key":"mykey", "value":"myvalue"}]``
+  under ``properties`` object, instead of as ``{key: value}`` pairs as a part
+  of the ``properties`` object itself.
+
 Removals
 ~~~~~~~~
 

rust/src/mqtt/logger.rs

@@ -20,6 +20,7 @@
 use super::mqtt::MQTTTransaction;
 use crate::jsonbuilder::{JsonBuilder, JsonError};
 use crate::mqtt::mqtt_message::{MQTTOperation, MQTTSubscribeTopicData};
+use crate::mqtt::mqtt_property::MQTTProperty;
 use crate::mqtt::parser::FixedHeader;
 use std;
 
@@ -44,6 +45,44 @@ fn log_mqtt_header(js: &mut JsonBuilder, hdr: &FixedHeader) -> Result<(), JsonEr
     return Ok(());
 }
 
+fn log_mqtt_user_properties(
+    js: &mut JsonBuilder, props: &[MQTTProperty], max_log_len: usize,
+) -> Result<(), JsonError> {
+    let mut open = false;
+    for prop in props {
+        if let MQTTProperty::USER_PROPERTY((k, v)) = prop {
+            if !open {
+                js.open_array("user_properties")?;
+                open = true;
+            }
+            js.start_object()?;
+            js.set_string_limited("key", k, max_log_len)?;
+            js.set_string_limited("value", v, max_log_len)?;
+            js.close()?;
+        }
+    }
+    if open {
+        js.close()?; // user_properties
+    }
+    return Ok(());
+}
+
+// Logs a list of properties as a "properties" object. User properties are
+// logged separately, as an array of [key, value] pairs, since their keys are
+// peer-controlled and can occur more than once.
+#[inline]
+fn log_mqtt_properties(
+    js: &mut JsonBuilder, props: &[MQTTProperty], max_log_len: usize,
+) -> Result<(), JsonError> {
+    js.open_object("properties")?;
+    for prop in props {
+        prop.set_json(js, max_log_len)?;
+    }
+    log_mqtt_user_properties(js, props, max_log_len)?;
+    js.close()?; // properties
+    return Ok(());
+}
+
 fn log_mqtt(
     tx: &MQTTTransaction, flags: u32, max_log_len: usize, js: &mut JsonBuilder,
 ) -> Result<(), JsonError> {
@@ -80,20 +119,12 @@ fn log_mqtt(
                         js.set_string_from_bytes_limited("message", will_message, max_log_len)?;
                     }
                     if let Some(will_properties) = &conn.will_properties {
-                        js.open_object("properties")?;
-                        for prop in will_properties {
-                            prop.set_json(js, max_log_len)?;
-                        }
-                        js.close()?; // properties
+                        log_mqtt_properties(js, will_properties, max_log_len)?;
                     }
                     js.close()?; // will
                 }
                 if let Some(properties) = &conn.properties {
-                    js.open_object("properties")?;
-                    for prop in properties {
-                        prop.set_json(js, max_log_len)?;
-                    }
-                    js.close()?; // properties
+                    log_mqtt_properties(js, properties, max_log_len)?;
                 }
                 js.close()?; // connect
             }
@@ -103,11 +134,7 @@ fn log_mqtt(
                 js.set_bool("session_present", connack.session_present)?;
                 js.set_uint("return_code", connack.return_code as u64)?;
                 if let Some(properties) = &connack.properties {
-                    js.open_object("properties")?;
-                    for prop in properties {
-                        prop.set_json(js, max_log_len)?;
-                    }
-                    js.close()?; // properties
+                    log_mqtt_properties(js, properties, max_log_len)?;
                 }
                 js.close()?; // connack
             }
@@ -120,11 +147,7 @@ fn log_mqtt(
                 }
                 js.set_string_from_bytes_limited("message", &publish.message, max_log_len)?;
                 if let Some(properties) = &publish.properties {
-                    js.open_object("properties")?;
-                    for prop in properties {
-                        prop.set_json(js, max_log_len)?;
-                    }
-                    js.close()?; // properties
+                    log_mqtt_properties(js, properties, max_log_len)?;
                 }
                 js.close()?; // publish
             }
@@ -136,11 +159,7 @@ fn log_mqtt(
                     js.set_uint("reason_code", *reason_code as u64)?;
                 }
                 if let Some(properties) = &msgidonly.properties {
-                    js.open_object("properties")?;
-                    for prop in properties {
-                        prop.set_json(js, max_log_len)?;
-                    }
-                    js.close()?; // properties
+                    log_mqtt_properties(js, properties, max_log_len)?;
                 }
                 js.close()?; // puback
             }
@@ -152,11 +171,7 @@ fn log_mqtt(
                     js.set_uint("reason_code", *reason_code as u64)?;
                 }
                 if let Some(properties) = &msgidonly.properties {
-                    js.open_object("properties")?;
-                    for prop in properties {
-                        prop.set_json(js, max_log_len)?;
-                    }
-                    js.close()?; // properties
+                    log_mqtt_properties(js, properties, max_log_len)?;
                 }
                 js.close()?; // pubrec
             }
@@ -168,11 +183,7 @@ fn log_mqtt(
                     js.set_uint("reason_code", *reason_code as u64)?;
                 }
                 if let Some(properties) = &msgidonly.properties {
-                    js.open_object("properties")?;
-                    for prop in properties {
-                        prop.set_json(js, max_log_len)?;
-                    }
-                    js.close()?; // properties
+                    log_mqtt_properties(js, properties, max_log_len)?;
                 }
                 js.close()?; // pubrel
             }
@@ -184,11 +195,7 @@ fn log_mqtt(
                     js.set_uint("reason_code", *reason_code as u64)?;
                 }
                 if let Some(properties) = &msgidonly.properties {
-                    js.open_object("properties")?;
-                    for prop in properties {
-                        prop.set_json(js, max_log_len)?;
-                    }
-                    js.close()?; // properties
+                    log_mqtt_properties(js, properties, max_log_len)?;
                 }
                 js.close()?; // pubcomp
             }
@@ -210,11 +217,7 @@ fn log_mqtt(
                 }
                 js.close()?; //topics
                 if let Some(properties) = &subs.properties {
-                    js.open_object("properties")?;
-                    for prop in properties {
-                        prop.set_json(js, max_log_len)?;
-                    }
-                    js.close()?; // properties
+                    log_mqtt_properties(js, properties, max_log_len)?;
                 }
                 js.close()?; // subscribe
             }
@@ -270,11 +273,7 @@ fn log_mqtt(
                 log_mqtt_header(js, &msg.header)?;
                 js.set_uint("reason_code", auth.reason_code as u64)?;
                 if let Some(properties) = &auth.properties {
-                    js.open_object("properties")?;
-                    for prop in properties {
-                        prop.set_json(js, max_log_len)?;
-                    }
-                    js.close()?; // properties
+                    log_mqtt_properties(js, properties, max_log_len)?;
                 }
                 js.close()?; // auth
             }
@@ -285,11 +284,7 @@ fn log_mqtt(
                     js.set_uint("reason_code", *reason_code as u64)?;
                 }
                 if let Some(properties) = &disco.properties {
-                    js.open_object("properties")?;
-                    for prop in properties {
-                        prop.set_json(js, max_log_len)?;
-                    }
-                    js.close()?; // properties
+                    log_mqtt_properties(js, properties, max_log_len)?;
                 }
                 js.close()?; // disconnect
             }

rust/src/mqtt/mqtt_property.rs

@@ -126,8 +126,8 @@ impl crate::mqtt::mqtt_property::MQTTProperty {
             crate::mqtt::mqtt_property::MQTTProperty::RETAIN_AVAILABLE(v) => {
                 js.set_uint("retain_available", *v as u64)?;
             }
-            crate::mqtt::mqtt_property::MQTTProperty::USER_PROPERTY((k, v)) => {
-                js.set_string_limited(k, v, limit)?;
+            crate::mqtt::mqtt_property::MQTTProperty::USER_PROPERTY(_) => {
+                // handled in the logger
             }
             crate::mqtt::mqtt_property::MQTTProperty::MAXIMUM_PACKET_SIZE(v) => {
                 js.set_uint("maximum_packet_size", *v as u64)?;