Re: [Tarantool-patches] [PATCH v2 1/2] coio/say: fix getaddrinfo error handling on macOS

[Roman Khabibov <roman.habibov@tarantool.org>]

Hi!
I decided to stay diag_log() as it is. I tried to use new diag_add() from
the stacked diagnostics patch, but it don’t log this error. We have to
log this error to print error message from getaddrinfo after panic with
“say”.

See the following reproducer:

tarantool> socket = require('socket')
---
...

tarantool> log = require('log')
---
...

tarantool> fio = require('fio')
---
...

tarantool> 
---
...

tarantool> path = fio.pathjoin(fio.cwd(), 'log_unix_socket_test.sock')
---
...

tarantool> unix_socket = socket('AF_UNIX', 'SOCK_DGRAM', 0)
---
...

tarantool> unix_socket:bind('unix/', path)
---
- false
...

tarantool> 
---
...

tarantool> opt = string.format("syslog:server=non_exists_hostname:%s,identity=tarantool", path)
---
...

tarantool> box.cfg{log = opt, log_nonblock=true}
SystemError getaddrinfo: nodename nor servname provided, or not known: Input/output error
SystemError syslog logger: Input/output error: Input/output error
failed to initialize logging subsystem

If we remove diag_log(), we will lose getaddrinfo error in the log after
panic. I didn’t add it to test, because once upon a time with Vova
we decided that panic is hard to test, and it's not worth it.

> On Apr 17, 2020, at 12:37, Sergey Ostanevich <sergos@tarantool.org> wrote:
> 
>>>> Note: diag_log() in say.c was added, because otherwise it will be
>>>> hid by the following diagnostic and it should be handled in a
>>>> better way after #1148. Also, two diag_set() in
>>> Please, notify owner of #1148 about follow-up that will be needed.
>>> 
> 
> As I can see from #1148 comments, it is already closed. Can you address
> the problem now with a new gh issue?
> 
> Otherwise LGTM.
> 
> Sergos
> 
>>>> syslog_connect_unix() was added to avoid asserts in this
>>>> diag_log().
>>>> 
>>>> Need for #4138
>>>> ---
>>>> src/lib/core/coio_task.c |  2 +-
>>>> src/lib/core/say.c       | 12 ++++++++++--
>>>> test/unit/coio.cc        | 29 ++++++++++++++++++++++++++++-
>>>> test/unit/coio.result    |  4 +++-
>>>> 4 files changed, 42 insertions(+), 5 deletions(-)
>>>> 
>>>> diff --git a/src/lib/core/coio_task.c b/src/lib/core/coio_task.c
>>>> index 908b336ed..83f669d05 100644
>>>> --- a/src/lib/core/coio_task.c
>>>> +++ b/src/lib/core/coio_task.c
>>>> @@ -413,7 +413,7 @@ coio_getaddrinfo(const char *host, const char *port,
>>>> 		return -1; /* timed out or cancelled */
>>>> 
>>>> 	/* Task finished */
>>>> -	if (task->rc < 0) {
>>>> +	if (task->rc != 0) {
>>>> 		/* getaddrinfo() failed */
>>>> 		errno = EIO;
>>>> 		diag_set(SystemError, "getaddrinfo: %s",
>>>> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
>>>> index 64a637c58..8ad88ad57 100644
>>>> --- a/src/lib/core/say.c
>>>> +++ b/src/lib/core/say.c
>>>> @@ -459,14 +459,17 @@ static inline int
>>>> syslog_connect_unix(const char *path)
>>>> {
>>>> 	int fd = socket(PF_UNIX, SOCK_DGRAM, 0);
>>>> -	if (fd < 0)
>>>> +	if (fd < 0) {
>>>> +		diag_set(SystemError, "socket");
>>> This error message gives nothing. Please, describe the error behind it
>>> using the strerror(errno)
>>>> 		return -1;
>>>> +	}
>>>> 	struct sockaddr_un un;
>>>> 	memset(&un, 0, sizeof(un));
>>>> 	snprintf(un.sun_path, sizeof(un.sun_path), "%s", path);
>>>> 	un.sun_family = AF_UNIX;
>>>> 	if (connect(fd, (struct sockaddr *) &un, sizeof(un)) != 0) {
>>>> 		close(fd);
>>>> +		diag_set(SystemError, "connect");
>>> Ditto.
>> @@ -465,13 +465,16 @@ static inline int
>> syslog_connect_unix(const char *path)
>> {
>> 	int fd = socket(PF_UNIX, SOCK_DGRAM, 0);
>> -	if (fd < 0)
>> +	if (fd < 0) {
>> +		diag_set(SystemError, strerror(errno));
>> 		return -1;
>> +	}
>> 	struct sockaddr_un un;
>> 	memset(&un, 0, sizeof(un));
>> 	snprintf(un.sun_path, sizeof(un.sun_path), "%s", path);
>> 	un.sun_family = AF_UNIX;
>> 	if (connect(fd, (struct sockaddr *) &un, sizeof(un)) != 0) {
>> +		diag_set(SystemError, strerror(errno));
>> 		close(fd);
>> 		return -1;
>> 	}
>> 
>>>> 		return -1;
>>>> 	}
>>>> 	return fd;
>>>> @@ -506,7 +509,7 @@ syslog_connect_remote(const char *server_address)
>>>> 	hints.ai_protocol = IPPROTO_UDP;
>>>> 
>>>> 	ret = getaddrinfo(remote, portnum, &hints, &inf);
>>>> -	if (ret < 0) {
>>>> +	if (ret != 0) {
>>>> 		errno = EIO;
>>>> 		diag_set(SystemError, "getaddrinfo: %s",
>>>> 			 gai_strerror(ret));
>>>> @@ -593,6 +596,11 @@ log_syslog_init(struct log *log, const char *init_str)
>>>> 	say_free_syslog_opts(&opts);
>>>> 	log->fd = log_syslog_connect(log);
>>>> 	if (log->fd < 0) {
>>>> +		/*
>>>> +		 * We need to log a diagnostics here until stacked
>>>> +		 * diagnostics will be implemented (#1148).
>>>> +		 */
>>>> +		diag_log();
>>> Make a poniter about this in #1148
>> Ok.
>> 
>>>> 		/* syslog indent is freed in atexit(). */
>>>> 		diag_set(SystemError, "syslog logger: %s", strerror(errno));
>>>> 		return -1;
>>>> diff --git a/test/unit/coio.cc b/test/unit/coio.cc
>>>> index bb8bd7131..957c58ede 100644
>>>> --- a/test/unit/coio.cc
>>>> +++ b/test/unit/coio.cc
>>>> @@ -72,7 +72,7 @@ static void
>>>> test_getaddrinfo(void)
>>>> {
>>>> 	header();
>>>> -	plan(1);
>>>> +	plan(3);
>>>> 	const char *host = "127.0.0.1";
>>>> 	const char *port = "3333";
>>>> 	struct addrinfo *i;
>>>> @@ -81,6 +81,33 @@ test_getaddrinfo(void)
>>>> 	is(rc, 0, "getaddrinfo");
>>>> 	freeaddrinfo(i);
>>>> 
>>>> +	/*
>>>> +	 * gh-4138: Check getaddrinfo() retval and diagnostics
>>>> +	 * area.
>>>> +	 */
>>>> +	rc = coio_getaddrinfo("non_exists_hostname", port, NULL, &i,
>>>> +			      15768000000);
>>>> +	isnt(rc, 0, "getaddrinfo retval");
>>>> +	const char *errmsg = diag_get()->last->errmsg;
>>>> +	const char *exp_errmsg_1 = "getaddrinfo: nodename nor servname provided"
>>>> +		", or not known";
>>>> +	const char *exp_errmsg_2 = "getaddrinfo: Servname not supported for "
>>>> +		"ai_socktype";
>>>> +	const char *exp_errmsg_3 = "getaddrinfo: Name or service not known";
>>>> +	const char *exp_errmsg_4 = "getaddrinfo: hostname nor servname provided"
>>>> +		", or not known";
>>>> +	const char *exp_errmsg_5 = "getaddrinfo: Temporary failure in name "
>>>> +		"resolution";
>>>> +	const char *exp_errmsg_6 = "getaddrinfo: Name could not be resolved at "
>>>> +		"this time";
>>>> +	bool is_match_with_exp = strcmp(errmsg, exp_errmsg_1) == 0 ||
>>>> +		strcmp(errmsg, exp_errmsg_2) == 0 ||
>>>> +		strcmp(errmsg, exp_errmsg_3) == 0 ||
>>>> +		strcmp(errmsg, exp_errmsg_4) == 0 ||
>>>> +		strcmp(errmsg, exp_errmsg_5) == 0 ||
>>>> +		strcmp(errmsg, exp_errmsg_6) == 0;
>>>> +	is(is_match_with_exp, true, "getaddrinfo error message");
>>>> +
>>> Why did you made such a test - you're not sure which one will be
>>> triggered? Can you create a test that will check all possible errors?
>> See Alexander answer. I added comments about the constants.
>> 
>>>> 	/*
>>>> 	 * gh-4209: 0 timeout should not be a special value and
>>>> 	 * detach a task. Before a fix it led to segfault
>>>> diff --git a/test/unit/coio.result b/test/unit/coio.result
>>>> index 5019fa48a..90b567140 100644
>>>> --- a/test/unit/coio.result
>>>> +++ b/test/unit/coio.result
>>>> @@ -7,6 +7,8 @@
>>>> # call done with res 0
>>>> 	*** test_call_f: done ***
>>>> 	*** test_getaddrinfo ***
>>>> -1..1
>>>> +1..3
>>>> ok 1 - getaddrinfo
>>>> +ok 2 - getaddrinfo retval
>>>> +ok 3 - getaddrinfo error message
>>>> 	*** test_getaddrinfo: done ***
>>>> -- 
>>>> 2.21.0 (Apple Git-122)
>> 
>> commit f17e3e73ae2689dd2ec1dcd94d699636f19f93a5
>> Author: Roman Khabibov <roman.habibov@tarantool.org>
>> Date:   Tue Jul 30 15:39:21 2019 +0300
>> 
>>    coio/say: fix getaddrinfo error handling on macOS
>> 
>>    Before this patch, branch when getaddrinfo() returns error codes
>>    couldn't be reached on macOS, because they are greater than 0 on
>>    macOS (assumption "rc < 0" in commit ea1da04 is incorrect for
>>    macOS).
>> 
>>    Note: diag_log() in say.c was added, because otherwise it will be
>>    hid by the following diagnostic and it should be handled in a
>>    better way after #1148. Also, two diag_set() in
>>    syslog_connect_unix() was added to avoid asserts in this
>>    diag_log().
>> 
>>    Need for #4138
>> 
>> diff --git a/src/lib/core/coio_task.c b/src/lib/core/coio_task.c
>> index 908b336ed..83f669d05 100644
>> --- a/src/lib/core/coio_task.c
>> +++ b/src/lib/core/coio_task.c
>> @@ -413,7 +413,7 @@ coio_getaddrinfo(const char *host, const char *port,
>> 		return -1; /* timed out or cancelled */
>> 
>> 	/* Task finished */
>> -	if (task->rc < 0) {
>> +	if (task->rc != 0) {
>> 		/* getaddrinfo() failed */
>> 		errno = EIO;
>> 		diag_set(SystemError, "getaddrinfo: %s",
>> diff --git a/src/lib/core/say.c b/src/lib/core/say.c
>> index dd05285a6..0f8db4587 100644
>> --- a/src/lib/core/say.c
>> +++ b/src/lib/core/say.c
>> @@ -465,13 +465,16 @@ static inline int
>> syslog_connect_unix(const char *path)
>> {
>> 	int fd = socket(PF_UNIX, SOCK_DGRAM, 0);
>> -	if (fd < 0)
>> +	if (fd < 0) {
>> +		diag_set(SystemError, strerror(errno));
>> 		return -1;
>> +	}
>> 	struct sockaddr_un un;
>> 	memset(&un, 0, sizeof(un));
>> 	snprintf(un.sun_path, sizeof(un.sun_path), "%s", path);
>> 	un.sun_family = AF_UNIX;
>> 	if (connect(fd, (struct sockaddr *) &un, sizeof(un)) != 0) {
>> +		diag_set(SystemError, strerror(errno));
>> 		close(fd);
>> 		return -1;
>> 	}
>> @@ -512,7 +515,7 @@ syslog_connect_remote(const char *server_address)
>> 	hints.ai_protocol = IPPROTO_UDP;
>> 
>> 	ret = getaddrinfo(remote, portnum, &hints, &inf);
>> -	if (ret < 0) {
>> +	if (ret != 0) {
>> 		errno = EIO;
>> 		diag_set(SystemError, "getaddrinfo: %s",
>> 			 gai_strerror(ret));
>> @@ -599,6 +602,11 @@ log_syslog_init(struct log *log, const char *init_str)
>> 	say_free_syslog_opts(&opts);
>> 	log->fd = log_syslog_connect(log);
>> 	if (log->fd < 0) {
>> +		/*
>> +		 * We need to log a diagnostics here until stacked
>> +		 * diagnostics will be implemented (#1148).
>> +		 */
>> +		diag_log();
>> 		/* syslog indent is freed in atexit(). */
>> 		diag_set(SystemError, "syslog logger: %s", strerror(errno));
>> 		return -1;
>> diff --git a/test/unit/coio.cc b/test/unit/coio.cc
>> index bb8bd7131..69f78829c 100644
>> --- a/test/unit/coio.cc
>> +++ b/test/unit/coio.cc
>> @@ -72,7 +72,7 @@ static void
>> test_getaddrinfo(void)
>> {
>> 	header();
>> -	plan(1);
>> +	plan(3);
>> 	const char *host = "127.0.0.1";
>> 	const char *port = "3333";
>> 	struct addrinfo *i;
>> @@ -81,6 +81,39 @@ test_getaddrinfo(void)
>> 	is(rc, 0, "getaddrinfo");
>> 	freeaddrinfo(i);
>> 
>> +	/*
>> +	 * gh-4138: Check getaddrinfo() retval and diagnostics
>> +	 * area.
>> +	 */
>> +	rc = coio_getaddrinfo("non_exists_hostname", port, NULL, &i,
>> +			      15768000000);
>> +	isnt(rc, 0, "getaddrinfo retval");
>> +	const char *errmsg = diag_get()->last->errmsg;
>> +	/* EAI_NONAME */
>> +	const char *exp_errmsg_1 = "getaddrinfo: nodename nor servname provided"
>> +		", or not known";
>> +	/* EAI_SERVICE */
>> +	const char *exp_errmsg_2 = "getaddrinfo: Servname not supported for "
>> +		"ai_socktype";
>> +	/* EAI_NONAME */
>> +	const char *exp_errmsg_3 = "getaddrinfo: Name or service not known";
>> +	/* EAI_NONAME */
>> +	const char *exp_errmsg_4 = "getaddrinfo: hostname nor servname provided"
>> +		", or not known";
>> +	/* EAI_AGAIN */
>> +	const char *exp_errmsg_5 = "getaddrinfo: Temporary failure in name "
>> +		"resolution";
>> +	/* EAI_AGAIN */
>> +	const char *exp_errmsg_6 = "getaddrinfo: Name could not be resolved at "
>> +		"this time";
>> +	bool is_match_with_exp = strcmp(errmsg, exp_errmsg_1) == 0 ||
>> +		strcmp(errmsg, exp_errmsg_2) == 0 ||
>> +		strcmp(errmsg, exp_errmsg_3) == 0 ||
>> +		strcmp(errmsg, exp_errmsg_4) == 0 ||
>> +		strcmp(errmsg, exp_errmsg_5) == 0 ||
>> +		strcmp(errmsg, exp_errmsg_6) == 0;
>> +	is(is_match_with_exp, true, "getaddrinfo error message");
>> +
>> 	/*
>> 	 * gh-4209: 0 timeout should not be a special value and
>> 	 * detach a task. Before a fix it led to segfault
>> diff --git a/test/unit/coio.result b/test/unit/coio.result
>> index 5019fa48a..90b567140 100644
>> --- a/test/unit/coio.result
>> +++ b/test/unit/coio.result
>> @@ -7,6 +7,8 @@
>> # call done with res 0
>> 	*** test_call_f: done ***
>> 	*** test_getaddrinfo ***
>> -1..1
>> +1..3
>> ok 1 - getaddrinfo
>> +ok 2 - getaddrinfo retval
>> +ok 3 - getaddrinfo error message
>> 	*** test_getaddrinfo: done ***
>> 
>> 

commit cd5333e3acd35602e004a48eaefefd58dbd08cdd (HEAD)
Author: Roman Khabibov <roman.habibov@tarantool.org>
Date:   Tue Jul 30 15:39:21 2019 +0300

    coio/say: fix getaddrinfo error handling on macOS
    
    Before this patch, branch when getaddrinfo() returns error codes
    couldn't be reached on macOS, because they are greater than 0 on
    macOS (assumption "rc < 0" in commit ea1da04 is incorrect for
    macOS).
    
    Note: diag_log() in say.c was added, because otherwise it will be
    hid in the case of panic(). Also, two diag_set() in
    syslog_connect_unix() was added to avoid asserts in this
    diag_log().
    
    Needed for #4138

diff --git a/src/lib/core/coio_task.c b/src/lib/core/coio_task.c
index 908b336ed..83f669d05 100644
--- a/src/lib/core/coio_task.c
+++ b/src/lib/core/coio_task.c
@@ -413,7 +413,7 @@ coio_getaddrinfo(const char *host, const char *port,
 		return -1; /* timed out or cancelled */
 
 	/* Task finished */
-	if (task->rc < 0) {
+	if (task->rc != 0) {
 		/* getaddrinfo() failed */
 		errno = EIO;
 		diag_set(SystemError, "getaddrinfo: %s",
diff --git a/src/lib/core/say.c b/src/lib/core/say.c
index 791011e6f..9841ade25 100644
--- a/src/lib/core/say.c
+++ b/src/lib/core/say.c
@@ -485,13 +485,16 @@ static inline int
 syslog_connect_unix(const char *path)
 {
 	int fd = socket(PF_UNIX, SOCK_DGRAM, 0);
-	if (fd < 0)
+	if (fd < 0) {
+		diag_set(SystemError, strerror(errno));
 		return -1;
+	}
 	struct sockaddr_un un;
 	memset(&un, 0, sizeof(un));
 	snprintf(un.sun_path, sizeof(un.sun_path), "%s", path);
 	un.sun_family = AF_UNIX;
 	if (connect(fd, (struct sockaddr *) &un, sizeof(un)) != 0) {
+		diag_set(SystemError, strerror(errno));
 		close(fd);
 		return -1;
 	}
@@ -532,7 +535,7 @@ syslog_connect_remote(const char *server_address)
 	hints.ai_protocol = IPPROTO_UDP;
 
 	ret = getaddrinfo(remote, portnum, &hints, &inf);
-	if (ret < 0) {
+	if (ret != 0) {
 		errno = EIO;
 		diag_set(SystemError, "getaddrinfo: %s",
 			 gai_strerror(ret));
@@ -619,6 +622,7 @@ log_syslog_init(struct log *log, const char *init_str)
 	say_free_syslog_opts(&opts);
 	log->fd = log_syslog_connect(log);
 	if (log->fd < 0) {
+		diag_log();
 		/* syslog indent is freed in atexit(). */
 		diag_set(SystemError, "syslog logger: %s", strerror(errno));
 		return -1;
diff --git a/test/unit/coio.cc b/test/unit/coio.cc
index bb8bd7131..69f78829c 100644
--- a/test/unit/coio.cc
+++ b/test/unit/coio.cc
@@ -72,7 +72,7 @@ static void
 test_getaddrinfo(void)
 {
 	header();
-	plan(1);
+	plan(3);
 	const char *host = "127.0.0.1";
 	const char *port = "3333";
 	struct addrinfo *i;
@@ -81,6 +81,39 @@ test_getaddrinfo(void)
 	is(rc, 0, "getaddrinfo");
 	freeaddrinfo(i);
 
+	/*
+	 * gh-4138: Check getaddrinfo() retval and diagnostics
+	 * area.
+	 */
+	rc = coio_getaddrinfo("non_exists_hostname", port, NULL, &i,
+			      15768000000);
+	isnt(rc, 0, "getaddrinfo retval");
+	const char *errmsg = diag_get()->last->errmsg;
+	/* EAI_NONAME */
+	const char *exp_errmsg_1 = "getaddrinfo: nodename nor servname provided"
+		", or not known";
+	/* EAI_SERVICE */
+	const char *exp_errmsg_2 = "getaddrinfo: Servname not supported for "
+		"ai_socktype";
+	/* EAI_NONAME */
+	const char *exp_errmsg_3 = "getaddrinfo: Name or service not known";
+	/* EAI_NONAME */
+	const char *exp_errmsg_4 = "getaddrinfo: hostname nor servname provided"
+		", or not known";
+	/* EAI_AGAIN */
+	const char *exp_errmsg_5 = "getaddrinfo: Temporary failure in name "
+		"resolution";
+	/* EAI_AGAIN */
+	const char *exp_errmsg_6 = "getaddrinfo: Name could not be resolved at "
+		"this time";
+	bool is_match_with_exp = strcmp(errmsg, exp_errmsg_1) == 0 ||
+		strcmp(errmsg, exp_errmsg_2) == 0 ||
+		strcmp(errmsg, exp_errmsg_3) == 0 ||
+		strcmp(errmsg, exp_errmsg_4) == 0 ||
+		strcmp(errmsg, exp_errmsg_5) == 0 ||
+		strcmp(errmsg, exp_errmsg_6) == 0;
+	is(is_match_with_exp, true, "getaddrinfo error message");
+
 	/*
 	 * gh-4209: 0 timeout should not be a special value and
 	 * detach a task. Before a fix it led to segfault
diff --git a/test/unit/coio.result b/test/unit/coio.result
index 5019fa48a..90b567140 100644
--- a/test/unit/coio.result
+++ b/test/unit/coio.result
@@ -7,6 +7,8 @@
 # call done with res 0
 	*** test_call_f: done ***
 	*** test_getaddrinfo ***
-1..1
+1..3
 ok 1 - getaddrinfo
+ok 2 - getaddrinfo retval
+ok 3 - getaddrinfo error message
 	*** test_getaddrinfo: done ***