<html><body style="word-wrap: break-word; -webkit-nbsp-mode: space; line-break: after-white-space;" class=""><br class=""><br class=""><blockquote type="cite" class="">4 апр. 2019 г., в 15:06, Vladimir Davydov <<a href="mailto:vdavydov.dev@gmail.com" class="">vdavydov.dev@gmail.com</a>> написал(а):<br class=""><br class="">On Thu, Apr 04, 2019 at 02:52:25PM +0300, Serge Petrenko wrote:<br class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px; text-decoration: none;" class=""><br class="">Hi!<br class=""><br class=""><blockquote type="cite" class="">3 апр. 2019 г., в 12:18, Vladimir Davydov <<a href="mailto:vdavydov.dev@gmail.com" class="">vdavydov.dev@gmail.com</a>> написал(а):<br class=""><br class="">On Mon, Apr 01, 2019 at 04:09:06PM +0300, Serge Petrenko wrote:<br class=""><blockquote type="cite" class="">Add row hex printing to log on verbose level. This would be useful<br class="">during investigation of errors related to invalid msgpack packet<br class="">arrival.<br class=""><br class="">Here's some example output:<br class="">```<br class="">2019-04-01 16:04:51.629 [31304] iproto V> Corrupted row is: 3D A5 41 55 99 18 A8 08 C2 40 2B BA 50 12 F6 C6 0B 27 66 1C<br class="">2019-04-01 16:04:51.629 [31304] iproto xrow.c:133 E> ER_INVALID_MSGPACK: Invalid MsgPack - packet header<br class="">```<br class=""><br class="">Related to #4040<br class="">---<br class=""><a href="https://github.com/tarantool/tarantool/tree/sp/xrow-decode-verbose-err" class="">https://github.com/tarantool/tarantool/tree/sp/xrow-decode-verbose-err</a><br class="">https://github.com/tarantool/tarantool/issues/4040<br class=""><br class="">Changes in v2:<br class="">- make xrow_on_decode_err a macro instead of a<br class=""> function to preserve line where error occurs.<br class="">- add a test case.<br class="">- always allocate buffer for hex dump with malloc<br class="">- add logging on all errors related to invalid<br class=""> msgpack and missing request field.<br class=""><br class="">src/box/xrow.c | 116 ++++++++++++++++++++++++++------------<br class="">test/box/net.box.result | 34 +++++++++++<br class="">test/box/net.box.test.lua | 16 ++++++<br class="">3 files changed, 131 insertions(+), 35 deletions(-)<br class=""><br class="">diff --git a/src/box/xrow.c b/src/box/xrow.c<br class="">index 73d9e739b..fdd15bef3 100644<br class="">--- a/src/box/xrow.c<br class="">+++ b/src/box/xrow.c<br class="">@@ -88,15 +88,49 @@ mp_decode_vclock(const char **data, struct vclock *vclock)<br class=""><span class="Apple-tab-span" style="white-space:pre"> </span>return 0;<br class="">}<br class=""><br class="">+/**<br class="">+ * Set diagnostics with an error and log the corrupted row<br class="">+ * which caused the error.<br class="">+ * Optionally, if log_level is 'verbose' or greater,<br class="">+ * dump the corrupted row contents in hex to the log.<br class="">+ *<br class="">+ * @param what - exception to set.<br class="">+ * @param desc_str - error description string.<br class="">+ */<br class="">+#define xrow_on_decode_err(_start, _end, _what, _desc_str) do {<span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span>\<br class="">+<span class="Apple-tab-span" style="white-space:pre"> </span>diag_set(ClientError, _what, _desc_str);<span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span>\<br class="">+<span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span>\<br class="">+<span class="Apple-tab-span" style="white-space:pre"> </span>if (!say_log_level_is_enabled(S_VERBOSE))<span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span>\<br class="">+<span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span>break;<span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span>\<br class="">+<span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span>\<br class="">+<span class="Apple-tab-span" style="white-space:pre"> </span>size_t _len = 3 * ((const char *)(_end) - (const char *)(_start) + 1);<span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span>\<br class=""></blockquote><br class="">Nit: shouldn't +1 be outside the parentheses?<br class=""></blockquote><br class="">Yes, I guess I meant the interval to be inclusive.<br class="">But since it is not, the ‘+1’ should be outside.<br class=""><br class=""><blockquote type="cite" class=""><br class=""><blockquote type="cite" class="">+<span class="Apple-tab-span" style="white-space:pre"> </span>char *_buf = (char *)malloc(_len);<span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span><span class="Apple-tab-span" style="white-space:pre"> </span>\<br class=""></blockquote><br class="">Nit: we don't usually prefix names with underscores, because this may<br class="">conflict with libc internal macro definitions.<br class=""></blockquote><br class="">Ok. Do you want me to fix it?<br class=""></blockquote><br class="">Yes, please do and update the branch.<br class=""></blockquote><br class="">Done, here’s the diff.<br class=""><br class="">diff --git a/src/box/xrow.c b/src/box/xrow.c<br class="">index fdd15bef3..6aebe5c50 100644<br class="">--- a/src/box/xrow.c<br class="">+++ b/src/box/xrow.c<br class="">@@ -97,28 +97,28 @@ mp_decode_vclock(const char **data, struct vclock *vclock)<br class=""> * @param what - exception to set.<br class=""> * @param desc_str - error description string.<br class=""> */<br class="">-#define xrow_on_decode_err(_start, _end, _what, _desc_str) do { \<br class="">- diag_set(ClientError, _what, _desc_str); \<br class="">+#define xrow_on_decode_err(start, end, what, desc_str) do { \<br class="">+ diag_set(ClientError, what, desc_str); \<br class=""> \<br class=""> if (!say_log_level_is_enabled(S_VERBOSE)) \<br class=""> break; \<br class=""> \<br class="">- size_t _len = 3 * ((const char *)(_end) - (const char *)(_start) + 1); \<br class="">- char *_buf = (char *)malloc(_len); \<br class="">- if (!_buf) { \<br class="">+ size_t len = 3 * ((const char *)(end) - (const char *)(start) + 1); \<br class="">+ char *buf = (char *)malloc(len); \<br class="">+ if (!buf) { \<br class=""> say_verbose("Got a corrupted row during decoding. " \<br class=""> "Not enough memory to dump row contents."); \<br class=""> break; \<br class=""> } \<br class=""> \<br class="">- char *_pos = _buf; \<br class="">- char *_buf_end = _buf + _len; \<br class="">- for (const char *_cur = _start; _cur < _end; ++_cur) { \<br class="">- _pos += snprintf(_pos, _buf_end - _pos, "%02X ", (unsigned char)*_cur); \<br class="">+ char *pos = buf; \<br class="">+ char *buf_end = buf + len; \<br class="">+ for (const char *cur = start; cur < end; ++cur) { \<br class="">+ pos += snprintf(pos, buf_end - pos, "%02X ", (unsigned char)*cur); \<br class=""> } \<br class="">- say_verbose("Corrupted row is: %s", _buf); \<br class="">+ say_verbose("Corrupted row is: %s", buf); \<br class=""> \<br class="">- free(_buf); \<br class="">+ free(buf); \<br class=""> } while (0)<br class=""> <br class=""> int</body></html>