Re: [tarantool-patches] Re: [PATCH v2] xrow: print corrupted rows on decoding error.

[Serge Petrenko <sergepetrenko@tarantool.org>]

[-- Attachment #1: Type: text/plain, Size: 6296 bytes --]



> 4 апр. 2019 г., в 15:06, Vladimir Davydov <vdavydov.dev@gmail.com> написал(а):
> 
> On Thu, Apr 04, 2019 at 02:52:25PM +0300, Serge Petrenko wrote:
>> 
>> Hi!
>> 
>>> 3 апр. 2019 г., в 12:18, Vladimir Davydov <vdavydov.dev@gmail.com> написал(а):
>>> 
>>> On Mon, Apr 01, 2019 at 04:09:06PM +0300, Serge Petrenko wrote:
>>>> Add row hex printing to log on verbose level. This would be useful
>>>> during investigation of errors related to invalid msgpack packet
>>>> arrival.
>>>> 
>>>> Here's some example output:
>>>> ```
>>>> 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
>>>> 2019-04-01 16:04:51.629 [31304] iproto xrow.c:133 E> ER_INVALID_MSGPACK: Invalid MsgPack - packet header
>>>> ```
>>>> 
>>>> Related to #4040
>>>> ---
>>>> https://github.com/tarantool/tarantool/tree/sp/xrow-decode-verbose-err
>>>> https://github.com/tarantool/tarantool/issues/4040
>>>> 
>>>> Changes in v2:
>>>> - make xrow_on_decode_err a macro instead of a
>>>>   function to preserve line where error occurs.
>>>> - add a test case.
>>>> - always allocate buffer for hex dump with malloc
>>>> - add logging on all errors related to invalid
>>>>   msgpack and missing request field.
>>>> 
>>>> src/box/xrow.c            | 116 ++++++++++++++++++++++++++------------
>>>> test/box/net.box.result   |  34 +++++++++++
>>>> test/box/net.box.test.lua |  16 ++++++
>>>> 3 files changed, 131 insertions(+), 35 deletions(-)
>>>> 
>>>> diff --git a/src/box/xrow.c b/src/box/xrow.c
>>>> index 73d9e739b..fdd15bef3 100644
>>>> --- a/src/box/xrow.c
>>>> +++ b/src/box/xrow.c
>>>> @@ -88,15 +88,49 @@ mp_decode_vclock(const char **data, struct vclock *vclock)
>>>> 	return 0;
>>>> }
>>>> 
>>>> +/**
>>>> + * Set diagnostics with an error and log the corrupted row
>>>> + * which caused the error.
>>>> + * Optionally, if log_level is 'verbose' or greater,
>>>> + * dump the corrupted row contents in hex to the log.
>>>> + *
>>>> + * @param what - exception to set.
>>>> + * @param desc_str - error description string.
>>>> + */
>>>> +#define xrow_on_decode_err(_start, _end, _what, _desc_str) do {				\
>>>> +	diag_set(ClientError, _what, _desc_str);					\
>>>> +											\
>>>> +	if (!say_log_level_is_enabled(S_VERBOSE))					\
>>>> +		break;									\
>>>> +											\
>>>> +	size_t _len = 3 * ((const char *)(_end) - (const char *)(_start) + 1);		\
>>> 
>>> Nit: shouldn't +1 be outside the parentheses?
>> 
>> Yes, I guess I meant the interval to be inclusive.
>> But since it is not, the ‘+1’ should be outside.
>> 
>>> 
>>>> +	char *_buf = (char *)malloc(_len);						\
>>> 
>>> Nit: we don't usually prefix names with underscores, because this may
>>> conflict with libc internal macro definitions.
>> 
>> Ok. Do you want me to fix it?
> 
> Yes, please do and update the branch.

Done, here’s the diff.

diff --git a/src/box/xrow.c b/src/box/xrow.c
index fdd15bef3..6aebe5c50 100644
--- a/src/box/xrow.c
+++ b/src/box/xrow.c
@@ -97,28 +97,28 @@ mp_decode_vclock(const char **data, struct vclock *vclock)
  * @param what - exception to set.
  * @param desc_str - error description string.
  */
-#define xrow_on_decode_err(_start, _end, _what, _desc_str) do {                                \
-       diag_set(ClientError, _what, _desc_str);                                        \
+#define xrow_on_decode_err(start, end, what, desc_str) do {                            \
+       diag_set(ClientError, what, desc_str);                                  \
                                                                                        \
        if (!say_log_level_is_enabled(S_VERBOSE))                                       \
                break;                                                                  \
                                                                                        \
-       size_t _len = 3 * ((const char *)(_end) - (const char *)(_start) + 1);          \
-       char *_buf = (char *)malloc(_len);                                              \
-       if (!_buf) {                                                                    \
+       size_t len = 3 * ((const char *)(end) - (const char *)(start) + 1);             \
+       char *buf = (char *)malloc(len);                                                \
+       if (!buf) {                                                                     \
                say_verbose("Got a corrupted row during decoding. "                     \
                            "Not enough memory to dump row contents.");                 \
                break;                                                                  \
        }                                                                               \
                                                                                        \
-       char *_pos = _buf;                                                              \
-       char *_buf_end = _buf + _len;                                                   \
-       for (const char *_cur = _start; _cur < _end; ++_cur) {                          \
-               _pos += snprintf(_pos, _buf_end - _pos, "%02X ", (unsigned char)*_cur); \
+       char *pos = buf;                                                                \
+       char *buf_end = buf + len;                                                      \
+       for (const char *cur = start; cur < end; ++cur) {                               \
+               pos += snprintf(pos, buf_end - pos, "%02X ", (unsigned char)*cur);      \
        }                                                                               \
-       say_verbose("Corrupted row is: %s", _buf);                                      \
+       say_verbose("Corrupted row is: %s", buf);                                       \
                                                                                        \
-       free(_buf);                                                                     \
+       free(buf);                                                                      \
 } while (0)
 
 int

[-- Attachment #2: Type: text/html, Size: 17066 bytes --]