> 4 апр. 2019 г., в 15:06, Vladimir Davydov написал(а): > > On Thu, Apr 04, 2019 at 02:52:25PM +0300, Serge Petrenko wrote: >> >> Hi! >> >>> 3 апр. 2019 г., в 12:18, Vladimir Davydov написал(а): >>> >>> 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