diff --git a/docs/manual/config/config_file_reference.rst b/docs/manual/config/config_file_reference.rst index 8dfdc94161..65ba4940c7 100644 --- a/docs/manual/config/config_file_reference.rst +++ b/docs/manual/config/config_file_reference.rst @@ -2591,7 +2591,7 @@ The default value is: ``false`` ------------------------------------ One of: -* Comma-separated list of: fatal, error, warning, info, config, discovery, data, radmin, timing, traffic, topic, tcp, plist, whc, throttle, rhc, content, shm, trace +* Comma-separated list of: fatal, error, warning, info, config, discovery, data, radmin, timing, traffic, topic, tcp, plist, whc, throttle, rhc, content, malformed, trace * Or empty This element enables individual logging categories. These are enabled in addition to those enabled by Tracing/Verbosity. Recognised categories are: @@ -2616,16 +2616,25 @@ This element enables individual logging categories. These are enabled in additio * traffic: periodic reporting of total outgoing data + * throttle: tracing of throttling events + * whc: tracing of writer history cache changes + * rhc: tracing of reader history cache changes + * tcp: tracing of TCP-specific activity * topic: tracing of topic definitions * plist: tracing of discovery parameter list interpretation + * content: tracing of sample contents + + * malformed: dump malformed full packet as warning + + -In addition, there is the keyword trace that enables all but radmin, topic, plist and whc. +In addition, there is the keyword trace that enables: fatal, error, warning, info, config, discovery, data, trace, timing, traffic, tcp, throttle, content.. The categorisation of tracing output is incomplete and hence most of the verbosity levels and categories are not of much use in the current release. This is an ongoing process and here we describe the target situation rather than the current situation. Currently, the most useful is trace. The default value is: ```` @@ -2689,8 +2698,8 @@ The default value is: ``none`` .. generated from ddsi_config.h[6ffac6c47b890235276d70092a3c4c67d39ecb9e] generated from ddsi__cfgunits.h[bd22f0c0ed210501d0ecd3b07c992eca549ef5aa] - generated from ddsi__cfgelems.h[5a1d209ad4154846ecba5c55c4a8e6efa6419d15] - generated from ddsi_config.c[0a59324bd889637ea7d04765da9b76bbe74997c1] + generated from ddsi__cfgelems.h[0cb58370775b404955d589e41627aa7046b44a41] + generated from ddsi_config.c[c2d649fd4c5f8502d4c3bb124e5f7f7728257fa1] generated from _confgen.h[e32eabfc35e9f3a7dcb63b19ed148c0d17c6e5fc] generated from _confgen.c[237308acd53897a34e8c643e16e05a61d73ffd65] generated from generate_rnc.c[b50e4b7ab1d04b2bc1d361a0811247c337b74934] diff --git a/docs/manual/options.md b/docs/manual/options.md index df94df678e..4cb02fb8da 100644 --- a/docs/manual/options.md +++ b/docs/manual/options.md @@ -1801,7 +1801,7 @@ The default value is: `false` #### //CycloneDDS/Domain/Tracing/Category One of: -* Comma-separated list of: fatal, error, warning, info, config, discovery, data, radmin, timing, traffic, topic, tcp, plist, whc, throttle, rhc, content, shm, trace +* Comma-separated list of: fatal, error, warning, info, config, discovery, data, radmin, timing, traffic, topic, tcp, plist, whc, throttle, rhc, content, malformed, trace * Or empty This element enables individual logging categories. These are enabled in addition to those enabled by Tracing/Verbosity. Recognised categories are: @@ -1826,15 +1826,24 @@ This element enables individual logging categories. These are enabled in additio * traffic: periodic reporting of total outgoing data + * throttle: tracing of throttling events + * whc: tracing of writer history cache changes + * rhc: tracing of reader history cache changes + * tcp: tracing of TCP-specific activity * topic: tracing of topic definitions * plist: tracing of discovery parameter list interpretation -In addition, there is the keyword trace that enables all but radmin, topic, plist and whc. + * content: tracing of sample contents + + * malformed: dump malformed full packet as warning + + +In addition, there is the keyword trace that enables: fatal, error, warning, info, config, discovery, data, trace, timing, traffic, tcp, throttle, content.. The categorisation of tracing output is incomplete and hence most of the verbosity levels and categories are not of much use in the current release. This is an ongoing process and here we describe the target situation rather than the current situation. Currently, the most useful is trace. The default value is: `` @@ -1883,8 +1892,8 @@ The categorisation of tracing output is incomplete and hence most of the verbosi The default value is: `none` - - + + diff --git a/etc/cyclonedds.rnc b/etc/cyclonedds.rnc index fe1815c0f7..d23c03e04b 100644 --- a/etc/cyclonedds.rnc +++ b/etc/cyclonedds.rnc @@ -1258,15 +1258,20 @@ MIIEpAIBAAKCAQEA3HIh...AOBaaqSV37XBUJg==
  • radmin: receive buffer administration
  • timing: periodic reporting of CPU loads per thread
  • traffic: periodic reporting of total outgoing data
  • +
  • throttle: tracing of throttling events
  • whc: tracing of writer history cache changes
  • +
  • rhc: tracing of reader history cache changes
  • tcp: tracing of TCP-specific activity
  • topic: tracing of topic definitions
  • -
  • plist: tracing of discovery parameter list interpretation
  • -

    In addition, there is the keyword trace that enables all but radmin, topic, plist and whc

    . +
  • plist: tracing of discovery parameter list interpretation
  • +
  • content: tracing of sample contents
  • +
  • malformed: dump malformed full packet as warning
  • + +

    In addition, there is the keyword trace that enables: fatal, error, warning, info, config, discovery, data, trace, timing, traffic, tcp, throttle, content.

    .

    The categorisation of tracing output is incomplete and hence most of the verbosity levels and categories are not of much use in the current release. This is an ongoing process and here we describe the target situation rather than the current situation. Currently, the most useful is trace.

    The default value is: <empty>

    """ ] ] element Category { - xsd:token { pattern = "((fatal|error|warning|info|config|discovery|data|radmin|timing|traffic|topic|tcp|plist|whc|throttle|rhc|content|shm|trace)(,(fatal|error|warning|info|config|discovery|data|radmin|timing|traffic|topic|tcp|plist|whc|throttle|rhc|content|shm|trace))*)|" } + xsd:token { pattern = "((fatal|error|warning|info|config|discovery|data|radmin|timing|traffic|topic|tcp|plist|whc|throttle|rhc|content|malformed|trace)(,(fatal|error|warning|info|config|discovery|data|radmin|timing|traffic|topic|tcp|plist|whc|throttle|rhc|content|malformed|trace))*)|" } }? & [ a:documentation [ xml:lang="en" """

    This option specifies where the logging is printed to. Note that stdout and stderr are treated as special values, representing "standard out" and "standard error" respectively. No file is created unless logging categories are enabled using the Tracing/Verbosity or Tracing/EnabledCategory settings.

    @@ -1306,8 +1311,8 @@ MIIEpAIBAAKCAQEA3HIh...AOBaaqSV37XBUJg==
    } # generated from ddsi_config.h[6ffac6c47b890235276d70092a3c4c67d39ecb9e] # generated from ddsi__cfgunits.h[bd22f0c0ed210501d0ecd3b07c992eca549ef5aa] -# generated from ddsi__cfgelems.h[5a1d209ad4154846ecba5c55c4a8e6efa6419d15] -# generated from ddsi_config.c[0a59324bd889637ea7d04765da9b76bbe74997c1] +# generated from ddsi__cfgelems.h[0cb58370775b404955d589e41627aa7046b44a41] +# generated from ddsi_config.c[c2d649fd4c5f8502d4c3bb124e5f7f7728257fa1] # generated from _confgen.h[e32eabfc35e9f3a7dcb63b19ed148c0d17c6e5fc] # generated from _confgen.c[237308acd53897a34e8c643e16e05a61d73ffd65] # generated from generate_rnc.c[b50e4b7ab1d04b2bc1d361a0811247c337b74934] diff --git a/etc/cyclonedds.xsd b/etc/cyclonedds.xsd index f21e9eb921..407c9373a9 100644 --- a/etc/cyclonedds.xsd +++ b/etc/cyclonedds.xsd @@ -1884,17 +1884,22 @@ MIIEpAIBAAKCAQEA3HIh...AOBaaqSV37XBUJg==<br> <li><i>radmin</i>: receive buffer administration</li> <li><i>timing</i>: periodic reporting of CPU loads per thread</li> <li><i>traffic</i>: periodic reporting of total outgoing data</li> +<li><i>throttle</i>: tracing of throttling events</li> <li><i>whc</i>: tracing of writer history cache changes</li> +<li><i>rhc</i>: tracing of reader history cache changes</li> <li><i>tcp</i>: tracing of TCP-specific activity</li> <li><i>topic</i>: tracing of topic definitions</li> -<li><i>plist</i>: tracing of discovery parameter list interpretation</li></ul> -<p>In addition, there is the keyword <i>trace</i> that enables all but <i>radmin</i>, <i>topic</i>, <i>plist</i> and <i>whc</i></p>. +<li><i>plist</i>: tracing of discovery parameter list interpretation</li> +<li><i>content</i>: tracing of sample contents</li> +<li><i>malformed</i>: dump malformed full packet as warning</li> +</ul> +<p>In addition, there is the keyword <i>trace</i> that enables: <i>fatal</i>, <i>error</i>, <i>warning</i>, <i>info</i>, <i>config</i>, <i>discovery</i>, <i>data</i>, <i>trace</i>, <i>timing</i>, <i>traffic</i>, <i>tcp</i>, <i>throttle</i>, <i>content</i>.</p>. <p>The categorisation of tracing output is incomplete and hence most of the verbosity levels and categories are not of much use in the current release. This is an ongoing process and here we describe the target situation rather than the current situation. Currently, the most useful is <i>trace</i>.</p> <p>The default value is: <code>&lt;empty&gt;</code></p> - + @@ -1964,8 +1969,8 @@ MIIEpAIBAAKCAQEA3HIh...AOBaaqSV37XBUJg==<br> - - + + diff --git a/src/core/ddsi/defconfig.c b/src/core/ddsi/defconfig.c index 90d35f5578..a5ee9a5384 100644 --- a/src/core/ddsi/defconfig.c +++ b/src/core/ddsi/defconfig.c @@ -101,8 +101,8 @@ void ddsi_config_init_default (struct ddsi_config *cfg) } /* generated from ddsi_config.h[6ffac6c47b890235276d70092a3c4c67d39ecb9e] */ /* generated from ddsi__cfgunits.h[bd22f0c0ed210501d0ecd3b07c992eca549ef5aa] */ -/* generated from ddsi__cfgelems.h[5a1d209ad4154846ecba5c55c4a8e6efa6419d15] */ -/* generated from ddsi_config.c[0a59324bd889637ea7d04765da9b76bbe74997c1] */ +/* generated from ddsi__cfgelems.h[0cb58370775b404955d589e41627aa7046b44a41] */ +/* generated from ddsi_config.c[c2d649fd4c5f8502d4c3bb124e5f7f7728257fa1] */ /* generated from _confgen.h[e32eabfc35e9f3a7dcb63b19ed148c0d17c6e5fc] */ /* generated from _confgen.c[237308acd53897a34e8c643e16e05a61d73ffd65] */ /* generated from generate_rnc.c[b50e4b7ab1d04b2bc1d361a0811247c337b74934] */ diff --git a/src/core/ddsi/src/ddsi__cfgelems.h b/src/core/ddsi/src/ddsi__cfgelems.h index c2f47f90a8..4d3194f844 100644 --- a/src/core/ddsi/src/ddsi__cfgelems.h +++ b/src/core/ddsi/src/ddsi__cfgelems.h @@ -2005,13 +2005,19 @@ static struct cfgelem tracing_cfgelems[] = { "
  • radmin: receive buffer administration
  • \n" "
  • timing: periodic reporting of CPU loads per thread
  • \n" "
  • traffic: periodic reporting of total outgoing data
  • \n" + "
  • throttle: tracing of throttling events
  • \n" "
  • whc: tracing of writer history cache changes
  • \n" + "
  • rhc: tracing of reader history cache changes
  • \n" "
  • tcp: tracing of TCP-specific activity
  • \n" "
  • topic: tracing of topic definitions
  • \n" - "
  • plist: tracing of discovery parameter list interpretation
  • " + "
  • plist: tracing of discovery parameter list interpretation
  • \n" + "
  • content: tracing of sample contents
  • \n" + "
  • malformed: dump malformed full packet as warning
  • \n" "\n" - "

    In addition, there is the keyword trace that enables all " - "but radmin, topic, plist and whc

    .\n" + "

    In addition, there is the keyword trace that enables: " + "fatal, error, warning, info, config, " + "discovery, data, trace, timing, traffic, " + "tcp, throttle, content.

    .\n" "

    The categorisation of tracing output is incomplete and hence most " "of the verbosity levels and categories are not of much use in the " "current release. This is an ongoing process and here we describe the " @@ -2020,7 +2026,7 @@ static struct cfgelem tracing_cfgelems[] = { VALUES( "fatal","error","warning","info","config","discovery","data","radmin", "timing","traffic","topic","tcp","plist","whc","throttle","rhc", - "content","shm","trace" + "content","malformed","trace" )), ENUM("Verbosity", NULL, 1, "none", NOMEMBER, diff --git a/src/core/ddsi/src/ddsi_config.c b/src/core/ddsi/src/ddsi_config.c index 18617573ef..2744cd942c 100644 --- a/src/core/ddsi/src/ddsi_config.c +++ b/src/core/ddsi/src/ddsi_config.c @@ -1007,10 +1007,10 @@ GENERIC_ENUM_CTYPE (shm_loglevel, enum ddsi_shm_loglevel) /* "trace" is special: it enables (nearly) everything */ static const char *tracemask_names[] = { - "fatal", "error", "warning", "info", "config", "discovery", "data", "radmin", "timing", "traffic", "topic", "tcp", "plist", "whc", "throttle", "rhc", "content", "trace", NULL + "fatal", "error", "warning", "info", "config", "discovery", "data", "radmin", "timing", "traffic", "topic", "tcp", "plist", "whc", "throttle", "rhc", "content", "malformed", "trace", NULL }; static const uint32_t tracemask_codes[] = { - DDS_LC_FATAL, DDS_LC_ERROR, DDS_LC_WARNING, DDS_LC_INFO, DDS_LC_CONFIG, DDS_LC_DISCOVERY, DDS_LC_DATA, DDS_LC_RADMIN, DDS_LC_TIMING, DDS_LC_TRAFFIC, DDS_LC_TOPIC, DDS_LC_TCP, DDS_LC_PLIST, DDS_LC_WHC, DDS_LC_THROTTLE, DDS_LC_RHC, DDS_LC_CONTENT, DDS_LC_ALL + DDS_LC_FATAL, DDS_LC_ERROR, DDS_LC_WARNING, DDS_LC_INFO, DDS_LC_CONFIG, DDS_LC_DISCOVERY, DDS_LC_DATA, DDS_LC_RADMIN, DDS_LC_TIMING, DDS_LC_TRAFFIC, DDS_LC_TOPIC, DDS_LC_TCP, DDS_LC_PLIST, DDS_LC_WHC, DDS_LC_THROTTLE, DDS_LC_RHC, DDS_LC_CONTENT, DDS_LC_MALFORMED, DDS_LC_ALL }; static enum update_result uf_tracemask (struct ddsi_cfgst *cfgst, UNUSED_ARG (void *parent), UNUSED_ARG (struct cfgelem const * const cfgelem), UNUSED_ARG (int first), const char *value) diff --git a/src/core/ddsi/src/ddsi_receive.c b/src/core/ddsi/src/ddsi_receive.c index c4206c381f..d4e46219b4 100644 --- a/src/core/ddsi/src/ddsi_receive.c +++ b/src/core/ddsi/src/ddsi_receive.c @@ -2793,16 +2793,19 @@ static const char *submsg_name (ddsi_rtps_submessage_kind_t id, struct submsg_na return buffer->x; } -static void malformed_packet_received (const struct ddsi_domaingv *gv, const unsigned char *msg, const unsigned char *submsg, size_t len, ddsi_vendorid_t vendorid) +static void malformed_packet_received_shortmsg (const struct ddsi_domaingv *gv, const unsigned char *msg, const unsigned char *submsg, size_t len, ddsi_vendorid_t vendorid) { char tmp[1024]; size_t i, pos, smsize; - + struct submsg_name submsg_name_buffer; ddsi_rtps_submessage_kind_t smkind; const char *state0; const char *state1; - if (submsg == NULL || (submsg < msg || submsg >= msg + len)) { + // can safely subtract the two pointers after casting to uintptr_t, on all practical platforms + // this'll just give us a useful offset as long as submsg isn't a null pointer + const intptr_t offset = (intptr_t) ((uintptr_t) submsg - (uintptr_t) msg); + if (submsg == NULL || (submsg < msg || submsg > msg + len)) { // outside buffer shouldn't happen, but this is for dealing with junk, so better be careful smkind = DDSI_RTPS_SMID_PAD; state0 = ""; @@ -2818,19 +2821,20 @@ static void malformed_packet_received (const struct ddsi_domaingv *gv, const uns state1 = submsg_name (smkind, &submsg_name_buffer); } assert (submsg >= msg && submsg <= msg + len); - + const size_t clamped_offset = (offset < 0) ? 0 : ((size_t) offset > len) ? len : (size_t) offset; + /* Show beginning of message and of submessage (as hex dumps) */ - pos = (size_t) snprintf (tmp, sizeof (tmp), "malformed packet received from vendor %u.%u state %s%s <", vendorid.id[0], vendorid.id[1], state0, state1); - for (i = 0; i < 32 && i < len && msg + i < submsg && pos < sizeof (tmp); i++) + pos = (size_t) snprintf (tmp, sizeof (tmp), "malformed packet received from vendor %u.%u length %" PRIuSIZE " state %s%s <", vendorid.id[0], vendorid.id[1], len, state0, state1); + for (i = 0; i < 32 && i < len && i < clamped_offset && pos < sizeof (tmp); i++) pos += (size_t) snprintf (tmp + pos, sizeof (tmp) - pos, "%s%02x", (i > 0 && (i%4) == 0) ? " " : "", msg[i]); if (pos < sizeof (tmp)) - pos += (size_t) snprintf (tmp + pos, sizeof (tmp) - pos, " @0x%x ", (int) (submsg - msg)); - for (i = 0; i < 64 && i < len - (size_t) (submsg - msg) && pos < sizeof (tmp); i++) - pos += (size_t) snprintf (tmp + pos, sizeof (tmp) - pos, "%s%02x", (i > 0 && (i%4) == 0) ? " " : "", submsg[i]); + pos += (size_t) snprintf (tmp + pos, sizeof (tmp) - pos, " @%" PRIdPTR " ", offset); + for (i = 0; i < 64 && i < len - clamped_offset && pos < sizeof (tmp); i++) + pos += (size_t) snprintf (tmp + pos, sizeof (tmp) - pos, "%s%02x", (i > 0 && (i%4) == 0) ? " " : "", msg[clamped_offset + i]); if (pos < sizeof (tmp)) pos += (size_t) snprintf (tmp + pos, sizeof (tmp) - pos, "> (note: maybe partially bswap'd)"); assert (pos < (int) sizeof (tmp)); - + /* Partially decode header if we have enough bytes available */ smsize = len - (size_t) (submsg - msg); if (smsize >= DDSI_RTPS_SUBMESSAGE_HEADER_SIZE && pos < sizeof (tmp)) { @@ -2902,6 +2906,44 @@ static void malformed_packet_received (const struct ddsi_domaingv *gv, const uns GVWARNING ("%s\n", tmp); } +static void malformed_packet_received_fulldump (const struct ddsi_domaingv *gv, const unsigned char *msg, const unsigned char *submsg, size_t len, ddsi_vendorid_t vendorid, uint32_t logmask) +{ + GVLOG (logmask, "malformed packet: vendor %u.%u msg %p submsg %p length %" PRIuSIZE " contents:\n", vendorid.id[0], vendorid.id[1], (void *) msg, (void *) submsg, len); + for (size_t off16 = 0; off16 < len; off16 += 16) + { + GVLOG (logmask, "%c%04" PRIxSIZE " ", (msg + off16 <= submsg && (size_t) (submsg - (msg + off16)) < 16) ? '*' : ' ', off16); + char sep = ' '; + size_t off1; + for (off1 = 0; off1 < 16 && off16 + off1 < len; off1++) { + if (msg + off16 + off1 == submsg) + sep = '['; + else if (sep == '[') + sep = ']'; + else + sep =' '; + GVLOG (logmask, "%s%c%02x", (off1 == 8) ? " " : "", sep, msg[off16 + off1]); + } + for (; off1 < 16; off1++) { + GVLOG (logmask, "%s%c ", (off1 == 8) ? " " : "", (sep == '[') ? ']' : sep); + sep = ' '; + } + GVLOG (logmask, " |"); + for (off1 = 0; off1 < 16 && off16 + off1 < len; off1++) { + GVLOG (logmask, "%c", isprint (msg[off16 + off1]) ? msg[off16 + off1] : '.'); + } + GVLOG (logmask, "|\n"); + } +} + +static void malformed_packet_received (const struct ddsi_domaingv *gv, const unsigned char *msg, const unsigned char *submsg, size_t len, ddsi_vendorid_t vendorid) +{ + malformed_packet_received_shortmsg (gv, msg, submsg, len, vendorid); + if (gv->logconfig.c.mask & DDS_LC_MALFORMED) + malformed_packet_received_fulldump (gv, msg, submsg, len, vendorid, DDS_LC_WARNING); + else // dump it if we're writing a trace file, no matter the tracing options + malformed_packet_received_fulldump (gv, msg, submsg, len, vendorid, DDS_TRACE_MASK); +} + static struct ddsi_receiver_state *rst_cow_if_needed (int *rst_live, struct ddsi_rmsg *rmsg, struct ddsi_receiver_state *rst) { if (! *rst_live) diff --git a/src/ddsrt/include/dds/ddsrt/log.h b/src/ddsrt/include/dds/ddsrt/log.h index 53730aa12d..42f905f508 100644 --- a/src/ddsrt/include/dds/ddsrt/log.h +++ b/src/ddsrt/include/dds/ddsrt/log.h @@ -76,6 +76,8 @@ extern "C" { #define DDS_LC_RHC (65536u) /** Include content in traces. */ #define DDS_LC_CONTENT (131072u) +/** Output full dump of malformed messages as warnings */ +#define DDS_LC_MALFORMED (262144u) /** All common trace categories. */ #define DDS_LC_ALL \ (DDS_LC_FATAL | DDS_LC_ERROR | DDS_LC_WARNING | DDS_LC_INFO | \