This is an automated email from the ASF dual-hosted git repository.
astitcher pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/qpid-proton.git
The following commit(s) were added to refs/heads/main by this push:
new e4e8da31d PROTON-2743: Cannot log raw incoming frames
e4e8da31d is described below
commit e4e8da31df3cc7f2d5be13535af95cc873caec83
Author: Andrew Stitcher <astitc...@apache.org>
AuthorDate: Thu Jun 8 15:33:19 2023 -0400
PROTON-2743: Cannot log raw incoming frames
* The raw trace also does not have any mark of the frame direction.
* Fixed off by one error that logged an extra character in the
character display after the very last byte of the frame.
---
c/src/core/framing.c | 22 +++++++++++++++++-----
c/src/core/logger.c | 7 +++----
c/src/core/logger_private.h | 14 +-------------
3 files changed, 21 insertions(+), 22 deletions(-)
diff --git a/c/src/core/framing.c b/c/src/core/framing.c
index 79ead8303..d8a0f557f 100644
--- a/c/src/core/framing.c
+++ b/c/src/core/framing.c
@@ -49,9 +49,18 @@ static inline void pn_do_rx_trace(pn_logger_t *logger,
uint16_t ch, pn_bytes_t f
}
}
-static inline void pn_do_raw_trace(pn_logger_t *logger, pn_buffer_t *output,
size_t size)
+static inline void pn_do_raw_tx_trace(pn_logger_t *logger, pn_bytes_t frame,
size_t size)
{
- PN_LOG_RAW(logger, PN_SUBSYSTEM_IO, PN_LEVEL_RAW, output, size);
+ if (PN_SHOULD_LOG(logger, PN_SUBSYSTEM_IO, PN_LEVEL_RAW)) {
+ pni_logger_log_raw(logger, PN_SUBSYSTEM_IO, PN_LEVEL_RAW, frame, size,
"->");
+ }
+}
+
+static inline void pn_do_raw_rx_trace(pn_logger_t *logger, pn_bytes_t frame,
size_t size)
+{
+ if (PN_SHOULD_LOG(logger, PN_SUBSYSTEM_IO, PN_LEVEL_RAW)) {
+ pni_logger_log_raw(logger, PN_SUBSYSTEM_IO, PN_LEVEL_RAW, frame, size,
"<-");
+ }
}
ssize_t pn_read_frame(pn_frame_t *frame, const char *bytes, size_t available,
uint32_t max, pn_logger_t *logger)
@@ -70,6 +79,7 @@ ssize_t pn_read_frame(pn_frame_t *frame, const char *bytes,
size_t available, ui
frame->channel = pni_read16(&bytes[6]);
pn_do_rx_trace(logger, frame->channel, frame->frame_payload0);
+ pn_do_raw_rx_trace(logger, (pn_bytes_t){.size=size, .start=bytes},
AMQP_HEADER_SIZE+frame->extended.size+frame->frame_payload0.size+frame->frame_payload1.size);
return size;
}
@@ -93,7 +103,10 @@ size_t pn_write_frame(pn_buffer_t* buffer, pn_frame_t
frame, pn_logger_t *logger
// Don't mess with the buffer unless we are logging frame traces to avoid
// shuffling the buffer unnecessarily.
- if (PN_SHOULD_LOG(logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_FRAME) ) {
+ if (
+ PN_SHOULD_LOG(logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_FRAME) ||
+ PN_SHOULD_LOG(logger, PN_SUBSYSTEM_IO, PN_LEVEL_RAW))
+ {
// Get current buffer pointer so we can trace dump performative and
payload together
pn_bytes_t smem = pn_buffer_bytes(buffer);
pn_buffer_append(buffer, frame.frame_payload0.start,
frame.frame_payload0.size);
@@ -104,12 +117,11 @@ size_t pn_write_frame(pn_buffer_t* buffer, pn_frame_t
frame, pn_logger_t *logger
assert(smem.start==emem.start);
pn_bytes_t frame_payload = {.size=emem.size-smem.size,
.start=smem.start+smem.size};
pn_do_tx_trace(logger, frame.channel, frame_payload);
+ pn_do_raw_tx_trace(logger, emem,
AMQP_HEADER_SIZE+frame.extended.size+frame.frame_payload0.size+frame.frame_payload1.size);
} else {
pn_buffer_append(buffer, frame.frame_payload0.start,
frame.frame_payload0.size);
pn_buffer_append(buffer, frame.frame_payload1.start,
frame.frame_payload1.size);
}
- pn_do_raw_trace(logger, buffer,
AMQP_HEADER_SIZE+frame.extended.size+frame.frame_payload0.size+frame.frame_payload1.size);
-
return size;
} else {
return 0;
diff --git a/c/src/core/logger.c b/c/src/core/logger.c
index 7e429b349..ea1659347 100644
--- a/c/src/core/logger.c
+++ b/c/src/core/logger.c
@@ -193,15 +193,14 @@ void pni_logger_log_data(pn_logger_t *logger,
pn_log_subsystem_t subsystem, pn_l
}
}
-void pni_logger_log_raw(pn_logger_t *logger, pn_log_subsystem_t subsystem,
pn_log_level_t severity, pn_buffer_t *output, size_t size)
+void pni_logger_log_raw(pn_logger_t *logger, pn_log_subsystem_t subsystem,
pn_log_level_t severity, pn_bytes_t bytes, size_t size, const char* msg)
{
char buf[256];
- pn_bytes_t bytes = pn_buffer_bytes(output);
const char *start = &bytes.start[bytes.size-size];
for (unsigned i = 0; i < size; i+=16) {
pn_fixed_string_t out = pn_fixed_string(buf, sizeof(buf));
- pn_fixed_string_addf(&out, "%04x/%04x: ", i, size);
+ pn_fixed_string_addf(&out, "%s%04x/%04x: ", msg, i, size);
for (unsigned j = 0; j<16; j++) {
if (i+j<size) {
pn_fixed_string_addf(&out, "%02hhx ", start[i+j]);
@@ -210,7 +209,7 @@ void pni_logger_log_raw(pn_logger_t *logger,
pn_log_subsystem_t subsystem, pn_lo
}
}
for (unsigned j = 0; j<16; j++) {
- if (i+j>size) break;
+ if (i+j>=size) break;
char c = start[i+j];
if (c>32) { // c is signed so the high bit set is negative
pn_fixed_string_append(&out, pn_string_const(&c, 1));
diff --git a/c/src/core/logger_private.h b/c/src/core/logger_private.h
index 27625993c..98a9b1e8a 100644
--- a/c/src/core/logger_private.h
+++ b/c/src/core/logger_private.h
@@ -43,7 +43,7 @@ void pni_logger_fini(pn_logger_t*);
void pni_logger_log(pn_logger_t *logger, pn_log_subsystem_t subsystem,
pn_log_level_t severity, const char *message);
void pni_logger_vlogf(pn_logger_t *logger, pn_log_subsystem_t subsystem,
pn_log_level_t severity, const char *fmt, va_list ap);
void pni_logger_log_data(pn_logger_t *logger, pn_log_subsystem_t subsystem,
pn_log_level_t severity, const char *msg, const char *bytes, size_t size);
-void pni_logger_log_raw(pn_logger_t *logger, pn_log_subsystem_t subsystem,
pn_log_level_t severity, pn_buffer_t *output, size_t size);
+void pni_logger_log_raw(pn_logger_t *logger, pn_log_subsystem_t subsystem,
pn_log_level_t severity, pn_bytes_t bytes, size_t size, const char* msg);
void pni_logger_log_msg_inspect(pn_logger_t *logger, pn_log_subsystem_t
subsystem, pn_log_level_t severity, void *object, const char *fmt, ...);
void pni_logger_log_msg_frame(pn_logger_t *logger, pn_log_subsystem_t
subsystem, pn_log_level_t severity, pn_bytes_t frame, const char *fmt, ...);
@@ -64,18 +64,6 @@ void pni_logger_log_msg_frame(pn_logger_t *logger,
pn_log_subsystem_t subsystem,
pni_logger_log_data(logger, (pn_log_subsystem_t) (subsys),
(pn_log_level_t) (sev), __VA_ARGS__); \
} while(0)
-#define PN_LOG_MSG_DATA(logger, subsys, sev, data, ...) \
- do { \
- if (PN_SHOULD_LOG(logger, subsys, sev)) \
- pni_logger_log_msg_data(logger, (pn_log_subsystem_t) (subsys),
(pn_log_level_t) (sev), data, __VA_ARGS__); \
- } while(0)
-
-#define PN_LOG_RAW(logger, subsys, sev, ...) \
- do { \
- if (PN_SHOULD_LOG(logger, subsys, sev)) \
- pni_logger_log_raw(logger, (pn_log_subsystem_t) (subsys),
(pn_log_level_t) (sev), __VA_ARGS__); \
- } while(0)
-
#if __cplusplus
}
#endif
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscr...@qpid.apache.org
For additional commands, e-mail: commits-h...@qpid.apache.org
