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

[Sergey Ostanevich <sergos@tarantool.org>]

Hi!

Thanks for the update, LGTM.

Sergos

On 23 Jun 16:27, Roman Khabibov wrote:
> 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 ***
>