Re: segfault writing to log from Lua

[Dragan Dosen]

Hi all,

On 29.09.2015 19:31, Willy Tarreau wrote:
>>
>> Maybe, we should build a defaults strings (one for each rfc) at the
>> start of haproxy, and uses these default strings if the proxy "*p" is
>> NULL in the function "__send_log()" ?
> 
> Yes indeed we should have one of each, statically defined in log.c with
> the global log tag I guess. In fact this would even allow not to allocate
> one tag per proxy since we'd be able to reuse the global one when a proxy
> defines no log-tag.
> 

I've managed to fix this problem by using individual vectors instead of
the pre-generated strings, log_htp and log_htp_rfc5424.

This should also resolve another problem related to "pid" in
log_htp(_rfc5424), when haproxy is started in daemon/systemd mode.

The patch is in attachment.


Best regards,
Dragan Dosen

>From 7c9ed80a2979cfbb1860330393915dafccc617aa Mon Sep 17 00:00:00 2001
From: Dragan Dosen 
Date: Thu, 1 Oct 2015 13:18:13 +0200
Subject: [PATCH] BUG/MEDIUM: logs: segfault writing to log from Lua

Michael Ezzell reported a bug causing haproxy to segfault during startup
when trying to send syslog message from Lua. The function __send_log() can
be called with *p that is NULL and/or when the configuration is not fully
parsed, as is the case with Lua.

This patch fixes this problem by using individual vectors instead of the
pre-generated strings log_htp and log_htp_rfc5424.

Also, this patch fixes a problem causing haproxy to write the wrong pid in
the logs -- the log_htp(_rfc5424) strings were generated at the haproxy
start, but "pid" value would be changed after haproxy is started in
daemon/systemd mode.
---
 include/proto/log.h|5 --
 include/types/global.h |2 +-
 include/types/log.h|2 +-
 include/types/proxy.h  |4 +-
 src/cfgparse.c |   62 --
 src/haproxy.c  |6 +-
 src/log.c  |  169 +++-
 7 files changed, 127 insertions(+), 123 deletions(-)

diff --git a/include/proto/log.h b/include/proto/log.h
index dcc5ae4..02e01f7 100644
--- a/include/proto/log.h
+++ b/include/proto/log.h
@@ -148,11 +148,6 @@ char *lf_ip(char *dst, struct sockaddr *sockaddr, size_t size, struct logformat_
  */
 char *lf_port(char *dst, struct sockaddr *sockaddr, size_t size, struct logformat_node *node);
 
-/*
- * Write hostname, log_tag and pid to the log string
- */
-char *lf_host_tag_pid(char *dst, int format, const char *hostname, const char *log_tag, int pid, size_t size);
-
 
 #endif /* _PROTO_LOG_H */
 
diff --git a/include/types/global.h b/include/types/global.h
index ea5c387..ca96193 100644
--- a/include/types/global.h
+++ b/include/types/global.h
@@ -126,7 +126,7 @@ struct global {
 	char *chroot;
 	char *pidfile;
 	char *node, *desc;		/* node name & description */
-	char *log_tag;  /* name for syslog */
+	struct chunk log_tag;   /* name for syslog */
 	struct list logsrvs;
 	char *log_send_hostname;   /* set hostname in syslog header */
 	char *server_state_base;   /* path to a directory where server state files can be found */
diff --git a/include/types/log.h b/include/types/log.h
index 411ba8f..35c1228 100644
--- a/include/types/log.h
+++ b/include/types/log.h
@@ -30,7 +30,7 @@
 
 #define NB_LOG_FACILITIES   24
 #define NB_LOG_LEVELS   8
-#define NB_MSG_IOVEC_ELEMENTS   5
+#define NB_MSG_IOVEC_ELEMENTS   8
 #define SYSLOG_PORT 514
 #define UNIQUEID_LEN128
 
diff --git a/include/types/proxy.h b/include/types/proxy.h
index 49debc6..e18ae72 100644
--- a/include/types/proxy.h
+++ b/include/types/proxy.h
@@ -346,9 +346,7 @@ struct proxy {
 	struct list logsrvs;
 	struct list logformat; 			/* log_format linked list */
 	struct list logformat_sd;		/* log_format linked list for the RFC5424 structured-data part */
-	char *log_tag;  /* override default syslog tag */
-	struct chunk log_htp;			/* a syslog header part that contains hostname, log_tag and pid (RFC3164 format) */
-	struct chunk log_htp_rfc5424;		/* a syslog header part that contains hostname, log_tag and pid (RFC5424 format) */
+	struct chunk log_tag;   /* override default syslog tag */
 	char *header_unique_id; 		/* unique-id header */
 	struct list format_unique_id;		/* unique-id format */
 	int to_log;/* things to be logged (LW_*) */
diff --git a/src/cfgparse.c b/src/cfgparse.c
index 6958a1d..bc7cd94 100644
--- a/src/cfgparse.c
+++ b/src/cfgparse.c
@@ -1659,7 +1659,6 @@ int cfg_parse_global(const char *file, int linenum, char **args, int kwm)
 		else
 			name = hostname;
 
-		/* We'll add a space after the name to respect the log format */
 		free(global.log_send_hostname);
 		global.log_send_hostname = strdup(name);
 	}
@@ -1701,8 +1700,8 @@ int cfg_parse_global(const char *file, int linenum, char **args, int kwm)
 			err_code |= ERR_ALERT | ERR_FATAL;
 			goto out;
 		}
-		free(global.log_tag);
-		global.log_tag = strdup(args[1]);
+		

Re: segfault writing to log from Lua

[Michael Ezzell]

Thank you for the patch.

This does appear to resolve the issue.

On Thu, Oct 1, 2015 at 8:11 AM, Dragan Dosen  wrote:

> Hi all,
>
> On 29.09.2015 19:31, Willy Tarreau wrote:
> >>
> >> Maybe, we should build a defaults strings (one for each rfc) at the
> >> start of haproxy, and uses these default strings if the proxy "*p" is
> >> NULL in the function "__send_log()" ?
> >
> > Yes indeed we should have one of each, statically defined in log.c with
> > the global log tag I guess. In fact this would even allow not to allocate
> > one tag per proxy since we'd be able to reuse the global one when a proxy
> > defines no log-tag.
> >
>
> I've managed to fix this problem by using individual vectors instead of
> the pre-generated strings, log_htp and log_htp_rfc5424.
>
> This should also resolve another problem related to "pid" in
> log_htp(_rfc5424), when haproxy is started in daemon/systemd mode.
>
> The patch is in attachment.
>
>
> Best regards,
> Dragan Dosen
>
>

Re: segfault writing to log from Lua

[Willy Tarreau]

On Thu, Oct 01, 2015 at 11:29:38AM -0400, Michael Ezzell wrote:
> Thank you for the patch.
> 
> This does appear to resolve the issue.

Great, thanks for the quick patch and for testing! I've just merged it.
When I'm seeing how much cleaner the logging chain becomes with vectors,
I wish we'd down that change years ago!

Cheers,
willy

Re: segfault writing to log from Lua

[Dragan Dosen]

Hi,

Thank you for reporting this bug. I'll fix it as soon as possible.


Best regards,
Dragan Dosen


On 29.09.2015 14:01, Thierry FOURNIER wrote:
> Michael, thank you for the bug repport. I reproduce it.
> 
> It is introduced with the support of the RFC5424 for the logs format
> sublitted by dragan.
> 
> Hi Dragan, after your patch about the RFC5424, the funcion __send_log()
> no longer support NULL for the "*p" param. Can you fix this ?
> 
> It seems that the 'log_htp' and the 'log_htp_rfc5424' members of the
> "struct proxy" contains preformatted strings. There makeby the function 
> "lf_host_tag_pid()".
> 
> Maybe, we should build a defaults strings (one for each rfc) at the
> start of haproxy, and uses these default strings if the proxy "*p" is
> NULL in the function "__send_log()" ?
> 
> Thierry
> 
> 
> 
> 
> On Tue, 29 Sep 2015 07:37:12 -0400
> Michael Ezzell  wrote:
> 
>> Although I am seeing this in Lua, it does not appear (to me) to a the fault
>> in the Lua code... recent changes in __send_log() in log.c appear to assume
>> p is never null (there's a test for this condition earlier, then p is
>> referenced later), and that is not valid behavior in this case, because
>> there is no proxy associated:
>>
>> (gdb) run
>> Starting program: /home/ubuntu/haproxy-1.6-dev6/haproxy -f ./haproxy.cfg
>>
>> Program received signal SIGSEGV, Segmentation fault.
>> __send_log (p=p@entry=0x0, level=level@entry=1, message=,
>> size=10,
>> sd=sd@entry=0x711160  "- ",
>> sd_size=sd_size@entry=2) at src/log.c:1025
>> 1025if (unlikely(htp->len >= maxlen)) {
>> (gdb) print htp->len
>> Cannot access memory at address 0xda4
>> (gdb) print htp
>> $1 = (struct chunk *) 0xd98
>> (gdb) print >log_htp
>> $2 = (struct chunk *) 0xd98
>> (gdb) print p
>> $3 = (struct proxy *) 0x0
>> (gdb)
>>
>> This minimal test case can be replicated with the following two files:
>>
>> $ cat haproxy.cfg
>>
>> global
>> log 127.0.0.1 local0
>> lua-load crash.lua
>> user haproxy
>> group nogroup
>> daemon
>>
>> defaults
>> log global
>>
>> $ cat crash.lua
>>
>> core.Alert("hello.lua");
> 

Re: segfault writing to log from Lua

[Thierry FOURNIER]

ps: a temporary workaround waiting for the fix, is to add the following
line at the start of the first loaded lua script.

   core.Alert = function(msg) print(msg) end

Thierry


On Tue, 29 Sep 2015 07:37:12 -0400
Michael Ezzell  wrote:

> Although I am seeing this in Lua, it does not appear (to me) to a the fault
> in the Lua code... recent changes in __send_log() in log.c appear to assume
> p is never null (there's a test for this condition earlier, then p is
> referenced later), and that is not valid behavior in this case, because
> there is no proxy associated:
> 
> (gdb) run
> Starting program: /home/ubuntu/haproxy-1.6-dev6/haproxy -f ./haproxy.cfg
> 
> Program received signal SIGSEGV, Segmentation fault.
> __send_log (p=p@entry=0x0, level=level@entry=1, message=,
> size=10,
> sd=sd@entry=0x711160  "- ",
> sd_size=sd_size@entry=2) at src/log.c:1025
> 1025if (unlikely(htp->len >= maxlen)) {
> (gdb) print htp->len
> Cannot access memory at address 0xda4
> (gdb) print htp
> $1 = (struct chunk *) 0xd98
> (gdb) print >log_htp
> $2 = (struct chunk *) 0xd98
> (gdb) print p
> $3 = (struct proxy *) 0x0
> (gdb)
> 
> This minimal test case can be replicated with the following two files:
> 
> $ cat haproxy.cfg
> 
> global
> log 127.0.0.1 local0
> lua-load crash.lua
> user haproxy
> group nogroup
> daemon
> 
> defaults
> log global
> 
> $ cat crash.lua
> 
> core.Alert("hello.lua");

Re: segfault writing to log from Lua

[Michael Ezzell]

This a clean build, on both systems, using a freshly-extracted tarball of
1.6-dev6 downloaded from
http://www.haproxy.org/download/1.6/src/devel/haproxy-1.6-dev6.tar.gz.

I'll recheck and send files to replicate.
On Sep 29, 2015 4:47 AM, "Thierry FOURNIER" 
wrote:

> On Mon, 28 Sep 2015 20:50:44 -0400
> Michael Ezzell  wrote:
>
> > I fired up HA-Proxy version 1.6-dev6-e7ae656 2015/09/28 for testing, and
> > was greeted with...
> >
> > Segmentation fault (core dumped)
> >
> > Since I've been primarily testing Lua, I started by commenting out my Lua
> > config lines.  Startup succeeds.  Re-enabling the scripts, I find this to
> > be the offending line:
> >
> > core.Alert("hello.lua");
> >
> > I can't seem to write to syslog in any Lua context without a segfault.
> The
> > failure occurs even if this is the only line, in the only Lua script
> loaded
> > in global config.
> >
> > Behavior is observed on both 64-bit and 32-bit builds on Ubuntu 14.04.
> >
> > HA-Proxy version 1.6-dev6-e7ae656
>
>
> Hello,
>
> Thank you for the bug repport. I can't reproduce it.
>
> Are you sure, that you did a "make clean" before compiling your
> HAProxy ? Some structs are changed, and doesn't running a "make clean"
> is a common way for segfaults :)
>
> If it is the case, can you send me your test files ?
>
> Thierry
>

Re: segfault writing to log from Lua

[Thierry FOURNIER]

On Mon, 28 Sep 2015 20:50:44 -0400
Michael Ezzell  wrote:

> I fired up HA-Proxy version 1.6-dev6-e7ae656 2015/09/28 for testing, and
> was greeted with...
> 
> Segmentation fault (core dumped)
> 
> Since I've been primarily testing Lua, I started by commenting out my Lua
> config lines.  Startup succeeds.  Re-enabling the scripts, I find this to
> be the offending line:
> 
> core.Alert("hello.lua");
> 
> I can't seem to write to syslog in any Lua context without a segfault.  The
> failure occurs even if this is the only line, in the only Lua script loaded
> in global config.
> 
> Behavior is observed on both 64-bit and 32-bit builds on Ubuntu 14.04.
> 
> HA-Proxy version 1.6-dev6-e7ae656


Hello,

Thank you for the bug repport. I can't reproduce it.

Are you sure, that you did a "make clean" before compiling your
HAProxy ? Some structs are changed, and doesn't running a "make clean"
is a common way for segfaults :)

If it is the case, can you send me your test files ?

Thierry

Re: segfault writing to log from Lua

[Thierry FOURNIER]

Michael, thank you for the bug repport. I reproduce it.

It is introduced with the support of the RFC5424 for the logs format
sublitted by dragan.

Hi Dragan, after your patch about the RFC5424, the funcion __send_log()
no longer support NULL for the "*p" param. Can you fix this ?

It seems that the 'log_htp' and the 'log_htp_rfc5424' members of the
"struct proxy" contains preformatted strings. There makeby the function 
"lf_host_tag_pid()".

Maybe, we should build a defaults strings (one for each rfc) at the
start of haproxy, and uses these default strings if the proxy "*p" is
NULL in the function "__send_log()" ?

Thierry




On Tue, 29 Sep 2015 07:37:12 -0400
Michael Ezzell  wrote:

> Although I am seeing this in Lua, it does not appear (to me) to a the fault
> in the Lua code... recent changes in __send_log() in log.c appear to assume
> p is never null (there's a test for this condition earlier, then p is
> referenced later), and that is not valid behavior in this case, because
> there is no proxy associated:
> 
> (gdb) run
> Starting program: /home/ubuntu/haproxy-1.6-dev6/haproxy -f ./haproxy.cfg
> 
> Program received signal SIGSEGV, Segmentation fault.
> __send_log (p=p@entry=0x0, level=level@entry=1, message=,
> size=10,
> sd=sd@entry=0x711160  "- ",
> sd_size=sd_size@entry=2) at src/log.c:1025
> 1025if (unlikely(htp->len >= maxlen)) {
> (gdb) print htp->len
> Cannot access memory at address 0xda4
> (gdb) print htp
> $1 = (struct chunk *) 0xd98
> (gdb) print >log_htp
> $2 = (struct chunk *) 0xd98
> (gdb) print p
> $3 = (struct proxy *) 0x0
> (gdb)
> 
> This minimal test case can be replicated with the following two files:
> 
> $ cat haproxy.cfg
> 
> global
> log 127.0.0.1 local0
> lua-load crash.lua
> user haproxy
> group nogroup
> daemon
> 
> defaults
> log global
> 
> $ cat crash.lua
> 
> core.Alert("hello.lua");

Re: segfault writing to log from Lua

[Michael Ezzell]

Although I am seeing this in Lua, it does not appear (to me) to a the fault
in the Lua code... recent changes in __send_log() in log.c appear to assume
p is never null (there's a test for this condition earlier, then p is
referenced later), and that is not valid behavior in this case, because
there is no proxy associated:

(gdb) run
Starting program: /home/ubuntu/haproxy-1.6-dev6/haproxy -f ./haproxy.cfg

Program received signal SIGSEGV, Segmentation fault.
__send_log (p=p@entry=0x0, level=level@entry=1, message=,
size=10,
sd=sd@entry=0x711160  "- ",
sd_size=sd_size@entry=2) at src/log.c:1025
1025if (unlikely(htp->len >= maxlen)) {
(gdb) print htp->len
Cannot access memory at address 0xda4
(gdb) print htp
$1 = (struct chunk *) 0xd98
(gdb) print >log_htp
$2 = (struct chunk *) 0xd98
(gdb) print p
$3 = (struct proxy *) 0x0
(gdb)

This minimal test case can be replicated with the following two files:

$ cat haproxy.cfg

global
log 127.0.0.1 local0
lua-load crash.lua
user haproxy
group nogroup
daemon

defaults
log global

$ cat crash.lua

core.Alert("hello.lua");

Re: segfault writing to log from Lua

[Willy Tarreau]

On Tue, Sep 29, 2015 at 02:01:59PM +0200, Thierry FOURNIER wrote:
> Michael, thank you for the bug repport. I reproduce it.
> 
> It is introduced with the support of the RFC5424 for the logs format
> sublitted by dragan.
> 
> Hi Dragan, after your patch about the RFC5424, the funcion __send_log()
> no longer support NULL for the "*p" param. Can you fix this ?
> 
> It seems that the 'log_htp' and the 'log_htp_rfc5424' members of the
> "struct proxy" contains preformatted strings. There makeby the function 
> "lf_host_tag_pid()".
> 
> Maybe, we should build a defaults strings (one for each rfc) at the
> start of haproxy, and uses these default strings if the proxy "*p" is
> NULL in the function "__send_log()" ?

Yes indeed we should have one of each, statically defined in log.c with
the global log tag I guess. In fact this would even allow not to allocate
one tag per proxy since we'd be able to reuse the global one when a proxy
defines no log-tag.

Thanks Thierry for the diag.

Willy