Tarantool development patches archive
 help / color / mirror / Atom feed
* [Tarantool-patches] [PATCH] say: fix syslog format
@ 2020-03-24  8:52 Olga Arkhangelskaia
  2020-04-14 12:52 ` Igor Munkin
  2020-04-21 16:23 ` Alexander Turenko
  0 siblings, 2 replies; 7+ messages in thread
From: Olga Arkhangelskaia @ 2020-03-24  8:52 UTC (permalink / raw)
  To: tarantool-patches

While refactoring of say module in commit 2.0.4-837-g5db765a76
format of syslog was broken.

Closes #4785
---
 src/lib/core/say.c                   |  6 +++++-
 test/box-tap/gh-4785-syslog.result   |  1 +
 test/box-tap/gh-4785-syslog.test.lua | 22 ++++++++++++++++++++++
 3 files changed, 28 insertions(+), 1 deletion(-)
 create mode 100644 test/box-tap/gh-4785-syslog.result
 create mode 100755 test/box-tap/gh-4785-syslog.test.lua

diff --git a/src/lib/core/say.c b/src/lib/core/say.c
index dd05285a6..d03e687b5 100644
--- a/src/lib/core/say.c
+++ b/src/lib/core/say.c
@@ -199,7 +199,11 @@ void
 say_set_log_format(enum say_format format)
 {
 	log_format_func_t format_func;
-
+	bool allowed_to_change = log_default->type == SAY_LOGGER_STDERR ||
+			         log_default->type == SAY_LOGGER_PIPE ||
+				 log_default->type == SAY_LOGGER_FILE;
+	if (!allowed_to_change)
+		return;
 	switch (format) {
 	case SF_JSON:
 		assert(log_default->type != SAY_LOGGER_SYSLOG);
diff --git a/test/box-tap/gh-4785-syslog.result b/test/box-tap/gh-4785-syslog.result
new file mode 100644
index 000000000..bf3df9e6e
--- /dev/null
+++ b/test/box-tap/gh-4785-syslog.result
@@ -0,0 +1 @@
+<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool 
diff --git a/test/box-tap/gh-4785-syslog.test.lua b/test/box-tap/gh-4785-syslog.test.lua
new file mode 100755
index 000000000..586a2eb1a
--- /dev/null
+++ b/test/box-tap/gh-4785-syslog.test.lua
@@ -0,0 +1,22 @@
+#!/usr/bin/env tarantool
+test_run = require('test_run').new()
+
+local socket = require('socket')
+local log = require('log')
+local fio = require('fio')
+
+path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
+unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
+unix_socket:bind('unix/', path)
+
+opt = string.format("syslog:server=unix:%s,identity=tarantool", path)
+local buf = ''
+box.cfg{log = opt}
+buf = buf .. unix_socket:recv(100)
+str = string.format(buf)
+-- Check syslog format: TIMESTAMP IDENTATION[PID]
+--<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
+print(((((str:gsub("%d", "")):gsub("%p%p--%w+", "")):gsub("%w+  ::", "TIMESTAMP")):gsub("]", "PID]")))
+unix_socket:close()
+os.remove(path)
+os.exit(0)
-- 
2.20.1 (Apple Git-117)

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: [Tarantool-patches] [PATCH] say: fix syslog format
  2020-03-24  8:52 [Tarantool-patches] [PATCH] say: fix syslog format Olga Arkhangelskaia
@ 2020-04-14 12:52 ` Igor Munkin
  2020-04-15 13:25   ` Olga Arkhangelskaia
  2020-04-21 16:23 ` Alexander Turenko
  1 sibling, 1 reply; 7+ messages in thread
From: Igor Munkin @ 2020-04-14 12:52 UTC (permalink / raw)
  To: Olga Arkhangelskaia; +Cc: tarantool-patches

Olya,

Thanks for the patch! I left several comments below, please consider
them.

On 24.03.20, Olga Arkhangelskaia wrote:
> While refactoring of say module in commit 2.0.4-837-g5db765a76

AFAICS, we mention commits the following way:
| * b5b4809cf2e6d48230eb9e4301eac188b080e0f4 ('replication: update
| replica gc state on subscribe');

> format of syslog was broken.
> 
> Closes #4785
> ---
>  src/lib/core/say.c                   |  6 +++++-
>  test/box-tap/gh-4785-syslog.result   |  1 +
>  test/box-tap/gh-4785-syslog.test.lua | 22 ++++++++++++++++++++++
>  3 files changed, 28 insertions(+), 1 deletion(-)
>  create mode 100644 test/box-tap/gh-4785-syslog.result
>  create mode 100755 test/box-tap/gh-4785-syslog.test.lua
> 
> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
> index dd05285a6..d03e687b5 100644
> --- a/src/lib/core/say.c
> +++ b/src/lib/core/say.c
> @@ -199,7 +199,11 @@ void
>  say_set_log_format(enum say_format format)
>  {
>  	log_format_func_t format_func;
> -
> +	bool allowed_to_change = log_default->type == SAY_LOGGER_STDERR ||
> +			         log_default->type == SAY_LOGGER_PIPE ||
> +				 log_default->type == SAY_LOGGER_FILE;

Considering the values in SAY_LOGGER_* enum only two types are not
allowed to be changed: SAY_LOGGER_SYSLOG (since syslog format is fixed)
and SAY_LOGGER_BOOT (and I have no idea why). Thereby it would be great
to mention unchangable logger types with the corresponding reasons.
Also, considering the reasons the inverted condition looks more
convenient.

> +	if (!allowed_to_change)
> +		return;
>  	switch (format) {
>  	case SF_JSON:
>  		assert(log_default->type != SAY_LOGGER_SYSLOG);

This assertion never raises after the patch, so can be dropped.

> diff --git a/test/box-tap/gh-4785-syslog.result b/test/box-tap/gh-4785-syslog.result
> new file mode 100644
> index 000000000..bf3df9e6e
> --- /dev/null
> +++ b/test/box-tap/gh-4785-syslog.result
> @@ -0,0 +1 @@
> +<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool 
> diff --git a/test/box-tap/gh-4785-syslog.test.lua b/test/box-tap/gh-4785-syslog.test.lua
> new file mode 100755
> index 000000000..586a2eb1a
> --- /dev/null
> +++ b/test/box-tap/gh-4785-syslog.test.lua

Since you created a diff-based test it has to be moved to box directory
otherwise you can leave it here and transform it to a TAP-based one.
I propose to go the latter way.

> @@ -0,0 +1,22 @@
> +#!/usr/bin/env tarantool
> +test_run = require('test_run').new()

Seems like you don't need 'test_run' object here.

> +
> +local socket = require('socket')
> +local log = require('log')
> +local fio = require('fio')
> +
> +path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
> +unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
> +unix_socket:bind('unix/', path)
> +
> +opt = string.format("syslog:server=unix:%s,identity=tarantool", path)
> +local buf = ''
> +box.cfg{log = opt}
> +buf = buf .. unix_socket:recv(100)
> +str = string.format(buf)
> +-- Check syslog format: TIMESTAMP IDENTATION[PID]
> +--<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
> +print(((((str:gsub("%d", "")):gsub("%p%p--%w+", "")):gsub("%w+  ::", "TIMESTAMP")):gsub("]", "PID]")))

You can just use test:like here to check the received log entry. Also
<buf> and <opt> variables are excess and parentheses can be omitted.
Furthermore, syslog entry is a well documented format[1], so you can
match it against an RFC pattern. I reimplemented the test the following
way (the diff is below):

================================================================================

diff --git a/test/box-tap/gh-4785-syslog.result
b/test/box-tap/gh-4785-syslog.result
deleted file mode 100644
index bf3df9e6e..000000000
--- a/test/box-tap/gh-4785-syslog.result
+++ /dev/null
@@ -1 +0,0 @@
-<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool 
diff --git a/test/box-tap/gh-4785-syslog.test.lua b/test/box-tap/gh-4785-syslog.test.lua
index 586a2eb1a..bdf8d5d88 100755
--- a/test/box-tap/gh-4785-syslog.test.lua
+++ b/test/box-tap/gh-4785-syslog.test.lua
@@ -1,22 +1,39 @@
 #!/usr/bin/env tarantool
-test_run = require('test_run').new()
-
 local socket = require('socket')
 local log = require('log')
 local fio = require('fio')
+local tap = require('tap')
+
+local test = tap.test("Tarantool 4785")
+test:plan(1)
 
-path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
-unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
+local identity = 'tarantool'
+local path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
+local unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
 unix_socket:bind('unix/', path)

-opt = string.format("syslog:server=unix:%s,identity=tarantool", path)
-local buf = ''
-box.cfg{log = opt}
-buf = buf .. unix_socket:recv(100)
-str = string.format(buf)
--- Check syslog format: TIMESTAMP IDENTATION[PID]
---<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
-print(((((str:gsub("%d", "")):gsub("%p%p--%w+", "")):gsub("%w+  ::", "TIMESTAMP")):gsub("]", "PID]")))
+box.cfg{
+  log = string.format("syslog:server=unix:%s,identity=%s", path, identity)
+}
+
+local entry = unix_socket:recv(100)
+-- Check syslog format: <PRI><TIMESTAMP> IDENTITY[PID]: CORD/FID/FILE FACILITY>
+local patterns = {
+  PRI       = '<%d+>',
+  TIMESTAMP = '%u%l%l  ?%d?%d %d%d:%d%d:%d%d',
+  IDENTITY  = identity,
+  PID       = '%[%d+%]',
+  CORD      = 'main',
+  FID       = '%d+',
+  FILE      = '.+%.lua',
+  FACILITY  = '%u'
+}
+
+local pattern = string.format('%s%s %s%s: %s/%s/%s %s>',
+                              patterns.PRI, patterns.TIMESTAMP,
+                              patterns.IDENTITY, patterns.PID, patterns.CORD,
+                              patterns.FID, patterns.FILE, patterns.FACILITY)
+test:like(entry, pattern, 'syslog format')
 unix_socket:close()
 os.remove(path)
-os.exit(0)
+os.exit(test:check() and 0 or 1)

================================================================================

> +unix_socket:close()
> +os.remove(path)
> +os.exit(0)
> -- 
> 2.20.1 (Apple Git-117)
> 

[1]: https://tools.ietf.org/html/rfc3164#section-4.1

-- 
Best regards,
IM

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: [Tarantool-patches] [PATCH] say: fix syslog format
  2020-04-14 12:52 ` Igor Munkin
@ 2020-04-15 13:25   ` Olga Arkhangelskaia
  2020-04-16 21:15     ` Igor Munkin
  0 siblings, 1 reply; 7+ messages in thread
From: Olga Arkhangelskaia @ 2020-04-15 13:25 UTC (permalink / raw)
  To: Igor Munkin; +Cc: tarantool-patches

Hi Igor!

Thanks for the review!

I have fixed the patch according to what we have discussed.

Please, see diff below

14.04.2020 15:52, Igor Munkin пишет:
> Olya,
>
> Thanks for the patch! I left several comments below, please consider
> them.
>
> On 24.03.20, Olga Arkhangelskaia wrote:
>> While refactoring of say module in commit 2.0.4-837-g5db765a76
> AFAICS, we mention commits the following way:
> | * b5b4809cf2e6d48230eb9e4301eac188b080e0f4 ('replication: update
> | replica gc state on subscribe');
>
>> format of syslog was broken.
>>
>> Closes #4785
>> ---
>>   src/lib/core/say.c                   |  6 +++++-
>>   test/box-tap/gh-4785-syslog.result   |  1 +
>>   test/box-tap/gh-4785-syslog.test.lua | 22 ++++++++++++++++++++++
>>   3 files changed, 28 insertions(+), 1 deletion(-)
>>   create mode 100644 test/box-tap/gh-4785-syslog.result
>>   create mode 100755 test/box-tap/gh-4785-syslog.test.lua
>>
>> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
>> index dd05285a6..d03e687b5 100644
>> --- a/src/lib/core/say.c
>> +++ b/src/lib/core/say.c
>> @@ -199,7 +199,11 @@ void
>>   say_set_log_format(enum say_format format)
>>   {
>>   	log_format_func_t format_func;
>> -
>> +	bool allowed_to_change = log_default->type == SAY_LOGGER_STDERR ||
>> +			         log_default->type == SAY_LOGGER_PIPE ||
>> +				 log_default->type == SAY_LOGGER_FILE;
> Considering the values in SAY_LOGGER_* enum only two types are not
> allowed to be changed: SAY_LOGGER_SYSLOG (since syslog format is fixed)
> and SAY_LOGGER_BOOT (and I have no idea why). Thereby it would be great
> to mention unchangable logger types with the corresponding reasons.
> Also, considering the reasons the inverted condition looks more
> convenient.
>
>> +	if (!allowed_to_change)
>> +		return;
>>   	switch (format) {
>>   	case SF_JSON:
>>   		assert(log_default->type != SAY_LOGGER_SYSLOG);
> This assertion never raises after the patch, so can be dropped.
>
>> diff --git a/test/box-tap/gh-4785-syslog.result b/test/box-tap/gh-4785-syslog.result
>> new file mode 100644
>> index 000000000..bf3df9e6e
>> --- /dev/null
>> +++ b/test/box-tap/gh-4785-syslog.result
>> @@ -0,0 +1 @@
>> +<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
>> diff --git a/test/box-tap/gh-4785-syslog.test.lua b/test/box-tap/gh-4785-syslog.test.lua
>> new file mode 100755
>> index 000000000..586a2eb1a
>> --- /dev/null
>> +++ b/test/box-tap/gh-4785-syslog.test.lua
> Since you created a diff-based test it has to be moved to box directory
> otherwise you can leave it here and transform it to a TAP-based one.
> I propose to go the latter way.
>
>> @@ -0,0 +1,22 @@
>> +#!/usr/bin/env tarantool
>> +test_run = require('test_run').new()
> Seems like you don't need 'test_run' object here.
>
>> +
>> +local socket = require('socket')
>> +local log = require('log')
>> +local fio = require('fio')
>> +
>> +path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
>> +unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
>> +unix_socket:bind('unix/', path)
>> +
>> +opt = string.format("syslog:server=unix:%s,identity=tarantool", path)
>> +local buf = ''
>> +box.cfg{log = opt}
>> +buf = buf .. unix_socket:recv(100)
>> +str = string.format(buf)
>> +-- Check syslog format: TIMESTAMP IDENTATION[PID]
>> +--<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
>> +print(((((str:gsub("%d", "")):gsub("%p%p--%w+", "")):gsub("%w+  ::", "TIMESTAMP")):gsub("]", "PID]")))
> You can just use test:like here to check the received log entry. Also
> <buf> and <opt> variables are excess and parentheses can be omitted.
> Furthermore, syslog entry is a well documented format[1], so you can
> match it against an RFC pattern. I reimplemented the test the following
> way (the diff is below):
>
> ================================================================================
>
> diff --git a/test/box-tap/gh-4785-syslog.result
> b/test/box-tap/gh-4785-syslog.result
> deleted file mode 100644
> index bf3df9e6e..000000000
> --- a/test/box-tap/gh-4785-syslog.result
> +++ /dev/null
> @@ -1 +0,0 @@
> -<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
> diff --git a/test/box-tap/gh-4785-syslog.test.lua b/test/box-tap/gh-4785-syslog.test.lua
> index 586a2eb1a..bdf8d5d88 100755
> --- a/test/box-tap/gh-4785-syslog.test.lua
> +++ b/test/box-tap/gh-4785-syslog.test.lua
> @@ -1,22 +1,39 @@
>   #!/usr/bin/env tarantool
> -test_run = require('test_run').new()
> -
>   local socket = require('socket')
>   local log = require('log')
>   local fio = require('fio')
> +local tap = require('tap')
> +
> +local test = tap.test("Tarantool 4785")
> +test:plan(1)
>   
> -path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
> -unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
> +local identity = 'tarantool'
> +local path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
> +local unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
>   unix_socket:bind('unix/', path)
>
> -opt = string.format("syslog:server=unix:%s,identity=tarantool", path)
> -local buf = ''
> -box.cfg{log = opt}
> -buf = buf .. unix_socket:recv(100)
> -str = string.format(buf)
> --- Check syslog format: TIMESTAMP IDENTATION[PID]
> ---<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
> -print(((((str:gsub("%d", "")):gsub("%p%p--%w+", "")):gsub("%w+  ::", "TIMESTAMP")):gsub("]", "PID]")))
> +box.cfg{
> +  log = string.format("syslog:server=unix:%s,identity=%s", path, identity)
> +}
> +
> +local entry = unix_socket:recv(100)
> +-- Check syslog format: <PRI><TIMESTAMP> IDENTITY[PID]: CORD/FID/FILE FACILITY>
> +local patterns = {
> +  PRI       = '<%d+>',
> +  TIMESTAMP = '%u%l%l  ?%d?%d %d%d:%d%d:%d%d',
> +  IDENTITY  = identity,
> +  PID       = '%[%d+%]',
> +  CORD      = 'main',
> +  FID       = '%d+',
> +  FILE      = '.+%.lua',
> +  FACILITY  = '%u'
> +}
> +
> +local pattern = string.format('%s%s %s%s: %s/%s/%s %s>',
> +                              patterns.PRI, patterns.TIMESTAMP,
> +                              patterns.IDENTITY, patterns.PID, patterns.CORD,
> +                              patterns.FID, patterns.FILE, patterns.FACILITY)
> +test:like(entry, pattern, 'syslog format')
>   unix_socket:close()
>   os.remove(path)
> -os.exit(0)
> +os.exit(test:check() and 0 or 1)
>
> ================================================================================
>
>> +unix_socket:close()
>> +os.remove(path)
>> +os.exit(0)
>> -- 
>> 2.20.1 (Apple Git-117)
>>
> [1]: https://tools.ietf.org/html/rfc3164#section-4.1

  While refactoring of say module in commit
   7 5db765a76ab7270b350960a2dd6d89dcd3bdc032 (say: fix non-informative 
error
   8 messages for log cfg) format of syslog was broken.


  30 +`....../* For syslog, default or boot log type the log format can
  31 +`...... * not be changed.
  32 +`...... */
  33 +`......bool unchangeable =  log_default->type == SAY_LOGGER_BOOT ||
  34 +`......`.......`.......     log_default->type == SAY_LOGGER_SYSLOG;
  35 +`......if (unchangeable)
  36 +`......`.......return;
  37  `......switch (format) {
  38  `......case SF_JSON:
  39 -`......`.......assert(log_default->type != SAY_LOGGER_SYSLOG);
  40  `......`.......format_func = say_format_json;
  41 `......`.......break;
  42  `......case SF_PLAIN:
>

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: [Tarantool-patches] [PATCH] say: fix syslog format
  2020-04-15 13:25   ` Olga Arkhangelskaia
@ 2020-04-16 21:15     ` Igor Munkin
  2020-04-17  9:50       ` Olga Arkhangelskaia
  0 siblings, 1 reply; 7+ messages in thread
From: Igor Munkin @ 2020-04-16 21:15 UTC (permalink / raw)
  To: Olga Arkhangelskaia; +Cc: tarantool-patches

Olya,

Thanks for the patch! I left a couple nits below, please consider them.

Furthemore, I see there is still test/box-tap/gh-4785-syslog.result
in the diff. Please remove it.

On 15.04.20, Olga Arkhangelskaia wrote:
> Hi Igor!
> 
> Thanks for the review!
> 
> I have fixed the patch according to what we have discussed.
> 
> Please, see diff below
> 
> 14.04.2020 15:52, Igor Munkin пишет:
> > Olya,
> >
> > Thanks for the patch! I left several comments below, please consider
> > them.
> >
> > On 24.03.20, Olga Arkhangelskaia wrote:
> >> While refactoring of say module in commit 2.0.4-837-g5db765a76
> > AFAICS, we mention commits the following way:
> > | * b5b4809cf2e6d48230eb9e4301eac188b080e0f4 ('replication: update
> > | replica gc state on subscribe');
> >
> >> format of syslog was broken.
> >>
> >> Closes #4785
> >> ---
> >>   src/lib/core/say.c                   |  6 +++++-
> >>   test/box-tap/gh-4785-syslog.result   |  1 +
> >>   test/box-tap/gh-4785-syslog.test.lua | 22 ++++++++++++++++++++++
> >>   3 files changed, 28 insertions(+), 1 deletion(-)
> >>   create mode 100644 test/box-tap/gh-4785-syslog.result
> >>   create mode 100755 test/box-tap/gh-4785-syslog.test.lua
> >>
> >> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
> >> index dd05285a6..d03e687b5 100644
> >> --- a/src/lib/core/say.c
> >> +++ b/src/lib/core/say.c
> >> @@ -199,7 +199,11 @@ void
> >>   say_set_log_format(enum say_format format)
> >>   {
> >>   	log_format_func_t format_func;
> >> -
> >> +	bool allowed_to_change = log_default->type == SAY_LOGGER_STDERR ||
> >> +			         log_default->type == SAY_LOGGER_PIPE ||
> >> +				 log_default->type == SAY_LOGGER_FILE;
> > Considering the values in SAY_LOGGER_* enum only two types are not
> > allowed to be changed: SAY_LOGGER_SYSLOG (since syslog format is fixed)
> > and SAY_LOGGER_BOOT (and I have no idea why). Thereby it would be great
> > to mention unchangable logger types with the corresponding reasons.
> > Also, considering the reasons the inverted condition looks more
> > convenient.
> >
> >> +	if (!allowed_to_change)
> >> +		return;
> >>   	switch (format) {
> >>   	case SF_JSON:
> >>   		assert(log_default->type != SAY_LOGGER_SYSLOG);
> > This assertion never raises after the patch, so can be dropped.
> >
> >> diff --git a/test/box-tap/gh-4785-syslog.result b/test/box-tap/gh-4785-syslog.result
> >> new file mode 100644
> >> index 000000000..bf3df9e6e
> >> --- /dev/null
> >> +++ b/test/box-tap/gh-4785-syslog.result
> >> @@ -0,0 +1 @@
> >> +<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
> >> diff --git a/test/box-tap/gh-4785-syslog.test.lua b/test/box-tap/gh-4785-syslog.test.lua
> >> new file mode 100755
> >> index 000000000..586a2eb1a
> >> --- /dev/null
> >> +++ b/test/box-tap/gh-4785-syslog.test.lua
> > Since you created a diff-based test it has to be moved to box directory
> > otherwise you can leave it here and transform it to a TAP-based one.
> > I propose to go the latter way.
> >
> >> @@ -0,0 +1,22 @@
> >> +#!/usr/bin/env tarantool
> >> +test_run = require('test_run').new()
> > Seems like you don't need 'test_run' object here.
> >
> >> +
> >> +local socket = require('socket')
> >> +local log = require('log')
> >> +local fio = require('fio')
> >> +
> >> +path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
> >> +unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
> >> +unix_socket:bind('unix/', path)
> >> +
> >> +opt = string.format("syslog:server=unix:%s,identity=tarantool", path)
> >> +local buf = ''
> >> +box.cfg{log = opt}
> >> +buf = buf .. unix_socket:recv(100)
> >> +str = string.format(buf)
> >> +-- Check syslog format: TIMESTAMP IDENTATION[PID]
> >> +--<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
> >> +print(((((str:gsub("%d", "")):gsub("%p%p--%w+", "")):gsub("%w+  ::", "TIMESTAMP")):gsub("]", "PID]")))
> > You can just use test:like here to check the received log entry. Also
> > <buf> and <opt> variables are excess and parentheses can be omitted.
> > Furthermore, syslog entry is a well documented format[1], so you can
> > match it against an RFC pattern. I reimplemented the test the following
> > way (the diff is below):
> >
> > ================================================================================
> >
> > diff --git a/test/box-tap/gh-4785-syslog.result
> > b/test/box-tap/gh-4785-syslog.result
> > deleted file mode 100644
> > index bf3df9e6e..000000000
> > --- a/test/box-tap/gh-4785-syslog.result
> > +++ /dev/null
> > @@ -1 +0,0 @@
> > -<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
> > diff --git a/test/box-tap/gh-4785-syslog.test.lua b/test/box-tap/gh-4785-syslog.test.lua
> > index 586a2eb1a..bdf8d5d88 100755
> > --- a/test/box-tap/gh-4785-syslog.test.lua
> > +++ b/test/box-tap/gh-4785-syslog.test.lua
> > @@ -1,22 +1,39 @@
> >   #!/usr/bin/env tarantool
> > -test_run = require('test_run').new()
> > -
> >   local socket = require('socket')
> >   local log = require('log')
> >   local fio = require('fio')
> > +local tap = require('tap')
> > +
> > +local test = tap.test("Tarantool 4785")
> > +test:plan(1)
> >   
> > -path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
> > -unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
> > +local identity = 'tarantool'
> > +local path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
> > +local unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
> >   unix_socket:bind('unix/', path)
> >
> > -opt = string.format("syslog:server=unix:%s,identity=tarantool", path)
> > -local buf = ''
> > -box.cfg{log = opt}
> > -buf = buf .. unix_socket:recv(100)
> > -str = string.format(buf)
> > --- Check syslog format: TIMESTAMP IDENTATION[PID]
> > ---<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
> > -print(((((str:gsub("%d", "")):gsub("%p%p--%w+", "")):gsub("%w+  ::", "TIMESTAMP")):gsub("]", "PID]")))
> > +box.cfg{
> > +  log = string.format("syslog:server=unix:%s,identity=%s", path, identity)
> > +}
> > +
> > +local entry = unix_socket:recv(100)
> > +-- Check syslog format: <PRI><TIMESTAMP> IDENTITY[PID]: CORD/FID/FILE FACILITY>
> > +local patterns = {
> > +  PRI       = '<%d+>',
> > +  TIMESTAMP = '%u%l%l  ?%d?%d %d%d:%d%d:%d%d',
> > +  IDENTITY  = identity,
> > +  PID       = '%[%d+%]',
> > +  CORD      = 'main',
> > +  FID       = '%d+',
> > +  FILE      = '.+%.lua',
> > +  FACILITY  = '%u'
> > +}
> > +
> > +local pattern = string.format('%s%s %s%s: %s/%s/%s %s>',
> > +                              patterns.PRI, patterns.TIMESTAMP,
> > +                              patterns.IDENTITY, patterns.PID, patterns.CORD,
> > +                              patterns.FID, patterns.FILE, patterns.FACILITY)
> > +test:like(entry, pattern, 'syslog format')
> >   unix_socket:close()
> >   os.remove(path)
> > -os.exit(0)
> > +os.exit(test:check() and 0 or 1)
> >
> > ================================================================================
> >
> >> +unix_socket:close()
> >> +os.remove(path)
> >> +os.exit(0)
> >> -- 
> >> 2.20.1 (Apple Git-117)
> >>
> > [1]: https://tools.ietf.org/html/rfc3164#section-4.1
> 
>   While refactoring of say module in commit
>    7 5db765a76ab7270b350960a2dd6d89dcd3bdc032 (say: fix non-informative 
> error
>    8 messages for log cfg) format of syslog was broken.
> 
> 
>   30 +`....../* For syslog, default or boot log type the log format can
>   31 +`...... * not be changed.
>   32 +`...... */

At first, there is still no a word regarding the reasons why formats for
these logger types are unchanged.

Furthermore, Sasha mentioned[1] about the comment style we use in our
code, so I just cite him:

| We use two styles of comments (for one-line and multi-line comments):
|
|  | /* Hello. */
|
|  | /*
|  |  * Hello,
|  |  * world.
|  |  */
|
| Changed the comment to follow the latter style.
|
| If you're curious, Linus about comments style (strong language, you have
| been warned): https://lkml.org/lkml/2016/7/8/625

I propose to change the comment the following way:

================================================================================

diff --git a/src/lib/core/say.c b/src/lib/core/say.c
index 776321283..924ec8e77 100644
--- a/src/lib/core/say.c
+++ b/src/lib/core/say.c
@@ -199,8 +199,14 @@ void
 say_set_log_format(enum say_format format)
 {
        log_format_func_t format_func;
-       /* For syslog, default or boot log type the log format can
-        * not be changed.
+
+       /*
+        * When logger type is SAY_LOGGER_BOOT it simply prints
+        * every message to stdout intact and can't be formatted.
+        * SAY_LOGGER_SYSLOG type uses the well-documented and
+        * *recommended* format described in the RFC below:
+        * https://tools.ietf.org/html/rfc3164#section-4.1
+        * Thereby format can't be changed for this type either.
         */
        bool unchangeable =  log_default->type == SAY_LOGGER_BOOT ||
                             log_default->type == SAY_LOGGER_SYSLOG;

================================================================================

>   33 +`......bool unchangeable =  log_default->type == SAY_LOGGER_BOOT ||
>   34 +`......`.......`.......     log_default->type == SAY_LOGGER_SYSLOG;

Typo: space is doubled after the assignment sign.

>   35 +`......if (unchangeable)
>   36 +`......`.......return;
>   37  `......switch (format) {
>   38  `......case SF_JSON:
>   39 -`......`.......assert(log_default->type != SAY_LOGGER_SYSLOG);
>   40  `......`.......format_func = say_format_json;
>   41 `......`.......break;
>   42  `......case SF_PLAIN:
> >

[1]: https://lists.tarantool.org/pipermail/tarantool-patches/2020-February/014230.html

-- 
Best regards,
IM

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: [Tarantool-patches] [PATCH] say: fix syslog format
  2020-04-16 21:15     ` Igor Munkin
@ 2020-04-17  9:50       ` Olga Arkhangelskaia
  2020-04-17 11:56         ` Igor Munkin
  0 siblings, 1 reply; 7+ messages in thread
From: Olga Arkhangelskaia @ 2020-04-17  9:50 UTC (permalink / raw)
  To: Igor Munkin; +Cc: tarantool-patches

Igor, thanks a lot for your patience.

I have fixed all nits you have mentioned.

See diff below!

17.04.2020 0:15, Igor Munkin пишет:
> Olya,
>
> Thanks for the patch! I left a couple nits below, please consider them.
>
> Furthemore, I see there is still test/box-tap/gh-4785-syslog.result
Deleted!
> in the diff. Please remove it.
>
> On 15.04.20, Olga Arkhangelskaia wrote:
>> Hi Igor!
>>
>> Thanks for the review!
>>
>> I have fixed the patch according to what we have discussed.
>>
>> Please, see diff below
>>
>> 14.04.2020 15:52, Igor Munkin пишет:
>>> Olya,
>>>
>>> Thanks for the patch! I left several comments below, please consider
>>> them.
>>>
>>> On 24.03.20, Olga Arkhangelskaia wrote:
>>>> While refactoring of say module in commit 2.0.4-837-g5db765a76
>>> AFAICS, we mention commits the following way:
>>> | * b5b4809cf2e6d48230eb9e4301eac188b080e0f4 ('replication: update
>>> | replica gc state on subscribe');
>>>
>>>> format of syslog was broken.
>>>>
>>>> Closes #4785
>>>> ---
>>>>    src/lib/core/say.c                   |  6 +++++-
>>>>    test/box-tap/gh-4785-syslog.result   |  1 +
>>>>    test/box-tap/gh-4785-syslog.test.lua | 22 ++++++++++++++++++++++
>>>>    3 files changed, 28 insertions(+), 1 deletion(-)
>>>>    create mode 100644 test/box-tap/gh-4785-syslog.result
>>>>    create mode 100755 test/box-tap/gh-4785-syslog.test.lua
>>>>
>>>> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
>>>> index dd05285a6..d03e687b5 100644
>>>> --- a/src/lib/core/say.c
>>>> +++ b/src/lib/core/say.c
>>>> @@ -199,7 +199,11 @@ void
>>>>    say_set_log_format(enum say_format format)
>>>>    {
>>>>    	log_format_func_t format_func;
>>>> -
>>>> +	bool allowed_to_change = log_default->type == SAY_LOGGER_STDERR ||
>>>> +			         log_default->type == SAY_LOGGER_PIPE ||
>>>> +				 log_default->type == SAY_LOGGER_FILE;
>>> Considering the values in SAY_LOGGER_* enum only two types are not
>>> allowed to be changed: SAY_LOGGER_SYSLOG (since syslog format is fixed)
>>> and SAY_LOGGER_BOOT (and I have no idea why). Thereby it would be great
>>> to mention unchangable logger types with the corresponding reasons.
>>> Also, considering the reasons the inverted condition looks more
>>> convenient.
>>>
>>>> +	if (!allowed_to_change)
>>>> +		return;
>>>>    	switch (format) {
>>>>    	case SF_JSON:
>>>>    		assert(log_default->type != SAY_LOGGER_SYSLOG);
>>> This assertion never raises after the patch, so can be dropped.
>>>
>>>> diff --git a/test/box-tap/gh-4785-syslog.result b/test/box-tap/gh-4785-syslog.result
>>>> new file mode 100644
>>>> index 000000000..bf3df9e6e
>>>> --- /dev/null
>>>> +++ b/test/box-tap/gh-4785-syslog.result
>>>> @@ -0,0 +1 @@
>>>> +<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
>>>> diff --git a/test/box-tap/gh-4785-syslog.test.lua b/test/box-tap/gh-4785-syslog.test.lua
>>>> new file mode 100755
>>>> index 000000000..586a2eb1a
>>>> --- /dev/null
>>>> +++ b/test/box-tap/gh-4785-syslog.test.lua
>>> Since you created a diff-based test it has to be moved to box directory
>>> otherwise you can leave it here and transform it to a TAP-based one.
>>> I propose to go the latter way.
>>>
>>>> @@ -0,0 +1,22 @@
>>>> +#!/usr/bin/env tarantool
>>>> +test_run = require('test_run').new()
>>> Seems like you don't need 'test_run' object here.
>>>
>>>> +
>>>> +local socket = require('socket')
>>>> +local log = require('log')
>>>> +local fio = require('fio')
>>>> +
>>>> +path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
>>>> +unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
>>>> +unix_socket:bind('unix/', path)
>>>> +
>>>> +opt = string.format("syslog:server=unix:%s,identity=tarantool", path)
>>>> +local buf = ''
>>>> +box.cfg{log = opt}
>>>> +buf = buf .. unix_socket:recv(100)
>>>> +str = string.format(buf)
>>>> +-- Check syslog format: TIMESTAMP IDENTATION[PID]
>>>> +--<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
>>>> +print(((((str:gsub("%d", "")):gsub("%p%p--%w+", "")):gsub("%w+  ::", "TIMESTAMP")):gsub("]", "PID]")))
>>> You can just use test:like here to check the received log entry. Also
>>> <buf> and <opt> variables are excess and parentheses can be omitted.
>>> Furthermore, syslog entry is a well documented format[1], so you can
>>> match it against an RFC pattern. I reimplemented the test the following
>>> way (the diff is below):
>>>
>>> ================================================================================
>>>
>>> diff --git a/test/box-tap/gh-4785-syslog.result
>>> b/test/box-tap/gh-4785-syslog.result
>>> deleted file mode 100644
>>> index bf3df9e6e..000000000
>>> --- a/test/box-tap/gh-4785-syslog.result
>>> +++ /dev/null
>>> @@ -1 +0,0 @@
>>> -<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
>>> diff --git a/test/box-tap/gh-4785-syslog.test.lua b/test/box-tap/gh-4785-syslog.test.lua
>>> index 586a2eb1a..bdf8d5d88 100755
>>> --- a/test/box-tap/gh-4785-syslog.test.lua
>>> +++ b/test/box-tap/gh-4785-syslog.test.lua
>>> @@ -1,22 +1,39 @@
>>>    #!/usr/bin/env tarantool
>>> -test_run = require('test_run').new()
>>> -
>>>    local socket = require('socket')
>>>    local log = require('log')
>>>    local fio = require('fio')
>>> +local tap = require('tap')
>>> +
>>> +local test = tap.test("Tarantool 4785")
>>> +test:plan(1)
>>>    
>>> -path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
>>> -unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
>>> +local identity = 'tarantool'
>>> +local path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
>>> +local unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
>>>    unix_socket:bind('unix/', path)
>>>
>>> -opt = string.format("syslog:server=unix:%s,identity=tarantool", path)
>>> -local buf = ''
>>> -box.cfg{log = opt}
>>> -buf = buf .. unix_socket:recv(100)
>>> -str = string.format(buf)
>>> --- Check syslog format: TIMESTAMP IDENTATION[PID]
>>> ---<>TIMESTAMP tarantool[PID]: main//gh.test.lua C> Tarantool
>>> -print(((((str:gsub("%d", "")):gsub("%p%p--%w+", "")):gsub("%w+  ::", "TIMESTAMP")):gsub("]", "PID]")))
>>> +box.cfg{
>>> +  log = string.format("syslog:server=unix:%s,identity=%s", path, identity)
>>> +}
>>> +
>>> +local entry = unix_socket:recv(100)
>>> +-- Check syslog format: <PRI><TIMESTAMP> IDENTITY[PID]: CORD/FID/FILE FACILITY>
>>> +local patterns = {
>>> +  PRI       = '<%d+>',
>>> +  TIMESTAMP = '%u%l%l  ?%d?%d %d%d:%d%d:%d%d',
>>> +  IDENTITY  = identity,
>>> +  PID       = '%[%d+%]',
>>> +  CORD      = 'main',
>>> +  FID       = '%d+',
>>> +  FILE      = '.+%.lua',
>>> +  FACILITY  = '%u'
>>> +}
>>> +
>>> +local pattern = string.format('%s%s %s%s: %s/%s/%s %s>',
>>> +                              patterns.PRI, patterns.TIMESTAMP,
>>> +                              patterns.IDENTITY, patterns.PID, patterns.CORD,
>>> +                              patterns.FID, patterns.FILE, patterns.FACILITY)
>>> +test:like(entry, pattern, 'syslog format')
>>>    unix_socket:close()
>>>    os.remove(path)
>>> -os.exit(0)
>>> +os.exit(test:check() and 0 or 1)
>>>
>>> ================================================================================
>>>
>>>> +unix_socket:close()
>>>> +os.remove(path)
>>>> +os.exit(0)
>>>> -- 
>>>> 2.20.1 (Apple Git-117)
>>>>
>>> [1]: https://tools.ietf.org/html/rfc3164#section-4.1
>>    While refactoring of say module in commit
>>     7 5db765a76ab7270b350960a2dd6d89dcd3bdc032 (say: fix non-informative
>> error
>>     8 messages for log cfg) format of syslog was broken.
>>
>>
>>    30 +`....../* For syslog, default or boot log type the log format can
>>    31 +`...... * not be changed.
>>    32 +`...... */
> At first, there is still no a word regarding the reasons why formats for
> these logger types are unchanged.
>
> Furthermore, Sasha mentioned[1] about the comment style we use in our
> code, so I just cite him:
>
> | We use two styles of comments (for one-line and multi-line comments):
> |
> |  | /* Hello. */
> |
> |  | /*
> |  |  * Hello,
> |  |  * world.
> |  |  */
> |
> | Changed the comment to follow the latter style.
> |
> | If you're curious, Linus about comments style (strong language, you have
> | been warned): https://lkml.org/lkml/2016/7/8/625
>
> I propose to change the comment the following way:
>
> ================================================================================
>
> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
> index 776321283..924ec8e77 100644
> --- a/src/lib/core/say.c
> +++ b/src/lib/core/say.c
> @@ -199,8 +199,14 @@ void
>   say_set_log_format(enum say_format format)
>   {
>          log_format_func_t format_func;
> -       /* For syslog, default or boot log type the log format can
> -        * not be changed.
> +
> +       /*
> +        * When logger type is SAY_LOGGER_BOOT it simply prints
> +        * every message to stdout intact and can't be formatted.
> +        * SAY_LOGGER_SYSLOG type uses the well-documented and
> +        * *recommended* format described in the RFC below:
> +        * https://tools.ietf.org/html/rfc3164#section-4.1
> +        * Thereby format can't be changed for this type either.
>           */
>          bool unchangeable =  log_default->type == SAY_LOGGER_BOOT ||
>                               log_default->type == SAY_LOGGER_SYSLOG;
>
> ================================================================================
>
>>    33 +`......bool unchangeable =  log_default->type == SAY_LOGGER_BOOT ||
>>    34 +`......`.......`.......     log_default->type == SAY_LOGGER_SYSLOG;
> Typo: space is doubled after the assignment sign.
>
>>    35 +`......if (unchangeable)
>>    36 +`......`.......return;
>>    37  `......switch (format) {
>>    38  `......case SF_JSON:
>>    39 -`......`.......assert(log_default->type != SAY_LOGGER_SYSLOG);
>>    40  `......`.......format_func = say_format_json;
>>    41 `......`.......break;
>>    42  `......case SF_PLAIN:
  12  src/lib/core/say.c                   | 14 ++++++++--
  13  test/box-tap/gh-4785-syslog.test.lua | 42 
++++++++++++++++++++++++++++
  14  2 files changed, 54 insertions(+), 2 deletions(-)
  15  create mode 100755 test/box-tap/gh-4785-syslog.test.lua
  -
  26 +`....../*
  27 +`...... * When logger type is SAY_LOGGER_BOOT it simply prints
  28 +`...... * every message to stdout intact and can't be formatted.
  29 +`...... * SAY_LOGGER_SYSLOG type uses the well-documented and
  30 +`...... * *recommended* format described in the RFC below:
  31 +`...... * https://tools.ietf.org/html/rfc3164#section-4.1
  32 +`...... * Thereby format can't be changed for this type either.
  33 +`...... */
  34 +`......bool unchangeable = log_default->type == SAY_LOGGER_BOOT ||
  35 +`......`.......`.......    log_default->type == SAY_LOGGER_SYSLOG;
  36 +`......if (unchangeable)
> [1]: https://lists.tarantool.org/pipermail/tarantool-patches/2020-February/014230.html
>

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: [Tarantool-patches] [PATCH] say: fix syslog format
  2020-04-17  9:50       ` Olga Arkhangelskaia
@ 2020-04-17 11:56         ` Igor Munkin
  0 siblings, 0 replies; 7+ messages in thread
From: Igor Munkin @ 2020-04-17 11:56 UTC (permalink / raw)
  To: Olga Arkhangelskaia; +Cc: tarantool-patches

Olya,

Thanks, LGTM now.

Side note: I shared the recipe about diff pasting via vim[1] and hope it
is helpful.

On 17.04.20, Olga Arkhangelskaia wrote:
> Igor, thanks a lot for your patience.
> 
> I have fixed all nits you have mentioned.
> 
> See diff below!
> 

<snipped>

>   12  src/lib/core/say.c                   | 14 ++++++++--
>   13  test/box-tap/gh-4785-syslog.test.lua | 42 
> ++++++++++++++++++++++++++++
>   14  2 files changed, 54 insertions(+), 2 deletions(-)
>   15  create mode 100755 test/box-tap/gh-4785-syslog.test.lua
>   -
>   26 +`....../*
>   27 +`...... * When logger type is SAY_LOGGER_BOOT it simply prints
>   28 +`...... * every message to stdout intact and can't be formatted.
>   29 +`...... * SAY_LOGGER_SYSLOG type uses the well-documented and
>   30 +`...... * *recommended* format described in the RFC below:
>   31 +`...... * https://tools.ietf.org/html/rfc3164#section-4.1
>   32 +`...... * Thereby format can't be changed for this type either.
>   33 +`...... */
>   34 +`......bool unchangeable = log_default->type == SAY_LOGGER_BOOT ||
>   35 +`......`.......`.......    log_default->type == SAY_LOGGER_SYSLOG;
>   36 +`......if (unchangeable)

<snipped>

[1]: https://lists.tarantool.org/pipermail/tarantool-patches/2020-April/016121.html

-- 
Best regards,
IM

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: [Tarantool-patches] [PATCH] say: fix syslog format
  2020-03-24  8:52 [Tarantool-patches] [PATCH] say: fix syslog format Olga Arkhangelskaia
  2020-04-14 12:52 ` Igor Munkin
@ 2020-04-21 16:23 ` Alexander Turenko
  1 sibling, 0 replies; 7+ messages in thread
From: Alexander Turenko @ 2020-04-21 16:23 UTC (permalink / raw)
  To: Olga Arkhangelskaia; +Cc: tarantool-patches

LGTM.

Made minor changes and pushed to master, 2.4 and 2.3.

CCed Kirill.

See more below.

WBR, Alexander Turenko.

----

I wondered why a log format is attempted to change at all after setting
up syslog logger. Found that 'log' option is parsed at first box.cfg{},
but then 'log_format' is applied. This change disables it:

diff --git a/src/lib/core/say.c b/src/lib/core/say.c
index 5d572e1ab..fa3529194 100644
--- a/src/lib/core/say.c
+++ b/src/lib/core/say.c
@@ -694,7 +694,8 @@ say_logger_init(const char *init_str, int level, int nonblock,
        say_set_log_level(level);
        log_background = background;
        log_pid = log_default->pid;
-       say_set_log_format(say_format_by_name(format));
+       if (log_default->type != SAY_LOGGER_SYSLOG)
+               say_set_log_format(say_format_by_name(format));
 
        if (background) {
                fflush(stderr);

It allows the test to pass, but it does not fix the whole problem.
Messages that are generated during box.cfg{} have right format, but if
we'll call log.info(<...>) -- those ones will have 'plain' format.

NB: We should add log.info() case to the test.

There is one more place, where log_format is set during first box.cfg{}:

diff --git a/src/box/lua/load_cfg.lua b/src/box/lua/load_cfg.lua
index 5d818addf..daf2385c1 100644
--- a/src/box/lua/load_cfg.lua
+++ b/src/box/lua/load_cfg.lua
@@ -574,7 +574,11 @@ local function load_cfg(cfg)
             __call = locked(reload_cfg),
         })
     private.cfg_load()
+    -- XXX: Give an error if log_format and log are set both?
     for key, fun in pairs(dynamic_cfg) do
+        if key == 'log_format' and cfg.log ~= nil then
+            goto continue
+        end
         local val = cfg[key]
         if val ~= nil then
             if not dynamic_cfg_skip_at_load[key] then
@@ -587,6 +591,7 @@ local function load_cfg(cfg)
                 log.info("set '%s' configuration option to %s", key, json.encode(val))
             end
         end
+        ::continue::
     end
     if not box.cfg.read_only and not box.cfg.replication then
         box.schema.upgrade{auto = true}

After this the problem is gone.

Those exclusions looks fragile, so I would stick with your approach for
now: put the skip condition back to say_set_log_format().

IMHO, it is consequence of the way syslog is implemented now: it
requires specific format, but there is no such `enum say_format` value.
`log` option may configure actual format, but then default log_format is
set (and should be ignored underneath). This looks as the tech debt.

Now, changes I made to the patch:

I verify all arrived log messages instead of the first one. It requires
to make the syslog entry pattern less restrictive, because 'saving
snapshot' message comes from 'snapshot' fiber, not the main one).

I added the log.info() case into your test and also verified that
log.log_format('plain') does not change syslog format to 'plain'.

Minor style fixes.

The full diff is below:

diff --git a/test/box-tap/gh-4785-syslog.test.lua b/test/box-tap/gh-4785-syslog.test.lua
index ba43c1566..3d750b9ed 100755
--- a/test/box-tap/gh-4785-syslog.test.lua
+++ b/test/box-tap/gh-4785-syslog.test.lua
@@ -5,38 +5,64 @@ local log = require('log')
 local fio = require('fio')
 local tap = require('tap')
 
-local test = tap.test("Tarantool 4785")
-test:plan(1)
-
-local identity = 'tarantool'
-local path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
+-- A unix socket to read log entries from it.
+local path = fio.pathjoin(fio.cwd(), 'syslog.sock')
 local unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
+os.remove(path)
 unix_socket:bind('unix/', path)
 
+local identity = 'tarantool'
 box.cfg{
-  log = string.format("syslog:server=unix:%s,identity=%s", path, identity)
+    log = ('syslog:server=unix:%s,identity=%s'):format(path, identity),
 }
 
-local entry = unix_socket:recv(100)
--- Check syslog format: <PRI><TIMESTAMP> IDENTITY[PID]: CORD/FID/FILE FACILITY>
+-- Syslog format:
+--
+-- <PRI><TIMESTAMP> IDENTITY[PID]: CORD/FID/FILE FACILITY>
 local patterns = {
-  PRI       = '<%d+>',
-  TIMESTAMP = '%u%l%l  ?%d?%d %d%d:%d%d:%d%d',
-  IDENTITY  = identity,
-  PID       = '%[%d+%]',
-  CORD      = 'main',
-  FID       = '%d+',
-  FILE      = '.+%.lua',
-  FACILITY  = '%u'
+    '<%d+>',                         -- PRI
+    '%u%l%l  ?%d?%d %d%d:%d%d:%d%d', -- TIMESTAMP
+    identity,                        -- IDENTITY
+    '%[%d+%]',                       -- PID
+    '[%l%d]+',                       -- CORD
+    '%d+',                           -- FID
+    '[%l%d-_.]+',                    -- FILE
+    '%u',                            -- FACILITY
 }
+local pattern = ('%s%s %s%s: %s/%s/%s %s>'):format(unpack(patterns))
+
+local test = tap.test('gh-4785-syslog')
+test:plan(4)
 
-local pattern = string.format('%s%s %s%s: %s/%s/%s %s>',
-                              patterns.PRI, patterns.TIMESTAMP,
-                              patterns.IDENTITY, patterns.PID, patterns.CORD,
-                              patterns.FID, patterns.FILE, patterns.FACILITY)
-test:like(entry, pattern, 'syslog format')
+-- Verify all log entries we have after box.cfg().
+local ok = true
+local logs = {}
+while true do
+    local entry = unix_socket:recv(100)
+    if entry == nil then break end
+    ok = ok and entry:match(pattern)
+    table.insert(logs, entry)
+end
+test:ok(ok, 'box.cfg() log entries are in syslog format', {logs = logs})
 
+-- Verify a log entry written by log.info().
+log.info('hello')
+local entry = unix_socket:recv(100)
+test:like(entry, pattern, 'log.info() log entry is in syslog format',
+          {logs = {entry}})
+
+-- log.log_format('plain') is silently ignored.
+local ok = pcall(log.log_format, 'plain')
+test:ok(ok, "log.log_format('plain') is ignored with syslog")
+
+-- Verify log format again after log.log_format().
+log.info('world')
+local entry = unix_socket:recv(100)
+test:like(entry, pattern, 'log.info() log entry after log_format',
+          {logs = {entry}})
+
+-- Drop unix socket file.
 unix_socket:close()
 os.remove(path)
-os.exit(test:check() and 0 or 1)
 
+os.exit(test:check() and 0 or 1)

^ permalink raw reply	[flat|nested] 7+ messages in thread

end of thread, other threads:[~2020-04-21 16:23 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-03-24  8:52 [Tarantool-patches] [PATCH] say: fix syslog format Olga Arkhangelskaia
2020-04-14 12:52 ` Igor Munkin
2020-04-15 13:25   ` Olga Arkhangelskaia
2020-04-16 21:15     ` Igor Munkin
2020-04-17  9:50       ` Olga Arkhangelskaia
2020-04-17 11:56         ` Igor Munkin
2020-04-21 16:23 ` Alexander Turenko

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox