Re: 1.8.1-fe66fd doesn't finish startup and doesn't listen to sockets

[Pavlos Parissis]

On 08/12/2017 10:38 πμ, Pavlos Parissis wrote:
> On 08/12/2017 10:21 πμ, Christopher Faulet wrote:
>> Le 08/12/2017 à 05:52, Willy Tarreau a écrit :
>>>
 pparissis at poseidonas in ~/repo/haproxy-1.8 on (master u=)
 sudo gdb ./haproxy
 GNU gdb (Debian 7.12-6) 7.12.0.20161007-git
 Copyright (C) 2016 Free Software Foundation, Inc.
 License GPLv3+: GNU GPL version 3 or later 
 
 This is free software: you are free to change and redistribute it.
 There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
 and "show warranty" for details.
 This GDB was configured as "x86_64-linux-gnu".
 Type "show configuration" for configuration details.
 For bug reporting instructions, please see:
 .
 Find the GDB manual and other documentation resources online at:
 .
 For help, type "help".
 Type "apropos word" to search for commands related to "word"...
 Reading symbols from ./haproxy...done.
 (gdb) run -f /etc/haproxy/haproxy-ams4-dc.cfg
 Starting program: /home/pparissis/repo/haproxy-1.8/haproxy -f
 /etc/haproxy/haproxy-ams4-dc.cfg
 [Thread debugging using libthread_db enabled]
 Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
 [WARNING] 340/221611 (13628) : parsing 
 [/etc/haproxy/haproxy-ams4-dc.cfg:103] : a
 'http-request' rule placed after a 'use_backend' rule will still be 
 processed before.
 ^C
 Program received signal SIGINT, Interrupt.
 0x5562e302 in register_name (name=0x558ee294 
 "selected_dc_backup",
 len=18, scope=scope@entry=0x7fffd83c,
  alloc=alloc@entry=1, err=0x7fffdb28) at src/vars.c:215
 215    HA_RWLOCK_WRLOCK(VARS_LOCK, _names_rwlock);
>>>
>>> Ah, this looks like a double-lock :-)
>>> CCing Christopher who knows better than me how to track them.
>>>
>> Hi,
>>
>> The problem is not a double-lock but an unlock on a free lock, leaving it in 
>> a bad state. This is
>> not obvious on this trace, but compiling HAProxy with the debug on threads 
>> it is easier to observe it.
>>
>> This patch is joined. It should fix the bug. Thanks Pavlos!
> 
> Applied to 1.8 repo and solved the issue as I can start haproxy.
> 

I meant to my local cloned repo:-)

Cheers,
Pavlos



signature.asc
Description: OpenPGP digital signature

Re: 1.8.1-fe66fd doesn't finish startup and doesn't listen to sockets

[Willy Tarreau]

On Fri, Dec 08, 2017 at 10:21:45AM +0100, Christopher Faulet wrote:
> The problem is not a double-lock but an unlock on a free lock, leaving it in
> a bad state. This is not obvious on this trace, but compiling HAProxy with
> the debug on threads it is easier to observe it.
> 
> This patch is joined. It should fix the bug. Thanks Pavlos!

thanks, applied now.

Willy

Re: 1.8.1-fe66fd doesn't finish startup and doesn't listen to sockets

[Christopher Faulet]

Le 08/12/2017 à 05:52, Willy Tarreau a écrit :



pparissis at poseidonas in ~/repo/haproxy-1.8 on (master u=)
sudo gdb ./haproxy
GNU gdb (Debian 7.12-6) 7.12.0.20161007-git
Copyright (C) 2016 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later 
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
.
Find the GDB manual and other documentation resources online at:
.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from ./haproxy...done.
(gdb) run -f /etc/haproxy/haproxy-ams4-dc.cfg
Starting program: /home/pparissis/repo/haproxy-1.8/haproxy -f
/etc/haproxy/haproxy-ams4-dc.cfg
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[WARNING] 340/221611 (13628) : parsing [/etc/haproxy/haproxy-ams4-dc.cfg:103] : 
a
'http-request' rule placed after a 'use_backend' rule will still be processed 
before.
^C
Program received signal SIGINT, Interrupt.
0x5562e302 in register_name (name=0x558ee294 "selected_dc_backup",
len=18, scope=scope@entry=0x7fffd83c,
 alloc=alloc@entry=1, err=0x7fffdb28) at src/vars.c:215
215 HA_RWLOCK_WRLOCK(VARS_LOCK, _names_rwlock);


Ah, this looks like a double-lock :-)
CCing Christopher who knows better than me how to track them.


Hi,

The problem is not a double-lock but an unlock on a free lock, leaving 
it in a bad state. This is not obvious on this trace, but compiling 
HAProxy with the debug on threads it is easier to observe it.


This patch is joined. It should fix the bug. Thanks Pavlos!
--
Christopher Faulet
>From 023f995f5eba5e4c18cbbde0acc2225d3846bbc7 Mon Sep 17 00:00:00 2001
From: Christopher Faulet 
Date: Fri, 8 Dec 2017 09:17:39 +0100
Subject: [PATCH] BUG/MEDIUM: threads/vars: Fix deadlock in register_name

In register_name, before locking the var_names array, we check the variable name
validity. So if we try to register an invalid or empty name, we need to return
without unlocking it (because it was never locked).

This patch must be backported in 1.8.
---
 src/vars.c | 6 ++
 1 file changed, 2 insertions(+), 4 deletions(-)

diff --git a/src/vars.c b/src/vars.c
index c8aa5ac89..566ead6ec 100644
--- a/src/vars.c
+++ b/src/vars.c
@@ -174,8 +174,7 @@ static char *register_name(const char *name, int len, enum vars_scope *scope,
 	/* Check length. */
 	if (len == 0) {
 		memprintf(err, "Empty variable name cannot be accepted");
-		res = NULL;
-		goto end;
+		return res;
 	}
 
 	/* Check scope. */
@@ -207,8 +206,7 @@ static char *register_name(const char *name, int len, enum vars_scope *scope,
 	else {
 		memprintf(err, "invalid variable name '%s'. A variable name must be start by its scope. "
 		   "The scope can be 'proc', 'sess', 'txn', 'req' or 'res'", name);
-		res = NULL;
-		goto end;
+		return res;
 	}
 
 	if (alloc)
-- 
2.13.6

Re: 1.8.1-fe66fd doesn't finish startup and doesn't listen to sockets

[Willy Tarreau]

Hi Pavlos,

On Thu, Dec 07, 2017 at 10:18:02PM +0100, Pavlos Parissis wrote:
> On 07/12/2017 07:41 uu, Willy Tarreau wrote:
> > It looks like it doesn't finish to startup in fact. Are you seeing it spin
> > on the CPU maybe ?
> 
> Yes, it does. I am sorry but I didn't notice it

no pb.

> pparissis at poseidonas in ~/repo/haproxy-1.8 on (master u=)
> sudo gdb ./haproxy
> GNU gdb (Debian 7.12-6) 7.12.0.20161007-git
> Copyright (C) 2016 Free Software Foundation, Inc.
> License GPLv3+: GNU GPL version 3 or later 
> This is free software: you are free to change and redistribute it.
> There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
> and "show warranty" for details.
> This GDB was configured as "x86_64-linux-gnu".
> Type "show configuration" for configuration details.
> For bug reporting instructions, please see:
> .
> Find the GDB manual and other documentation resources online at:
> .
> For help, type "help".
> Type "apropos word" to search for commands related to "word"...
> Reading symbols from ./haproxy...done.
> (gdb) run -f /etc/haproxy/haproxy-ams4-dc.cfg
> Starting program: /home/pparissis/repo/haproxy-1.8/haproxy -f
> /etc/haproxy/haproxy-ams4-dc.cfg
> [Thread debugging using libthread_db enabled]
> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
> [WARNING] 340/221611 (13628) : parsing [/etc/haproxy/haproxy-ams4-dc.cfg:103] 
> : a
> 'http-request' rule placed after a 'use_backend' rule will still be processed 
> before.
> ^C
> Program received signal SIGINT, Interrupt.
> 0x5562e302 in register_name (name=0x558ee294 "selected_dc_backup",
> len=18, scope=scope@entry=0x7fffd83c,
> alloc=alloc@entry=1, err=0x7fffdb28) at src/vars.c:215
> 215   HA_RWLOCK_WRLOCK(VARS_LOCK, _names_rwlock);

Ah, this looks like a double-lock :-)
CCing Christopher who knows better than me how to track them.

> (gdb) bt full
> #0  0x5562e302 in register_name (name=0x558ee294 
> "selected_dc_backup",
> len=18, scope=scope@entry=0x7fffd83c,
> alloc=alloc@entry=1, err=0x7fffdb28) at src/vars.c:215
> i = 
> var_names2 = 
> tmp = 
> res = 0x0
> #1  0x5562f489 in vars_check_arg (arg=0x558ee600, err= out>)
> at src/vars.c:502
> name = 
> scope = SCOPE_REQ
> err = 
> arg = 0x558ee600
> #2  0x55609b94 in sample_parse_expr (str=str@entry=0x558ee598,
> idx=idx@entry=0x7fffd964,
> file=file@entry=0x558df420 "/etc/haproxy/haproxy-ams4-dc.cfg",
> line=line@entry=106, err_msg=err_msg@entry=0x7fffdb28,
> al=al@entry=0x558e85d8) at src/sample.c:901
> begw = 
> endw = 0x558df4c2 "req.selected_dc_backup)"
> endt = 0x558df4d8 ")"
> expr = 0x558ee5c0
> fetch = 0x558ade30 
> conv = 
> prev_type = 6
> fkw = 0x558ee2f0 "var"
> ckw = 0x0
> err_arg = 1
> #3  0x55630144 in parse_acl_expr (args=args@entry=0x558ee598,
> err=err@entry=0x7fffdb28, al=al@entry=0x558e85d8,
> file=file@entry=0x558df420 "/etc/haproxy/haproxy-ams4-dc.cfg", 
> line=106)
> at src/acl.c:351
> expr = 
> aclkw = 0x0
> refflags = 
> patflags = 
> arg = 
> smp = 0x0
> idx = 0
> ckw = 0x0
> begw = 
> endw = 
> endt = 
> cur_type = 
> nbargs = 
> operator = 2
> op = 
> contain_colon = 
> have_dot = 
> dot = 
> value = 3
> minor = 40
> buffer = "\000\000\000\000\000\000\000\000\003\000\000\000\060", 
> '\000'
> , "[\000\000\000n\000\000\000\000"
> is_loaded = 
> unique_id = 
> error = 0x50 
> ref = 
> pattern_expr = 
> load_as_map = 0
> acl_conv_found = 0
> #4  0x55630e50 in parse_acl (args=args@entry=0x558ee590,
> known_acl=known_acl@entry=0x558e6de8,
> err=err@entry=0x7fffdb28, al=al@entry=0x558e85d8,
> file=file@entry=0x558df420 "/etc/haproxy/haproxy-ams4-dc.cfg",
> line=line@entry=106) at src/acl.c:725
> cur_acl = 
> acl_expr = 
> name = 
> pos = 
> #5  0x55631293 in parse_acl_cond (args=0x7fffdc68,
> known_acl=0x558e6de8, pol=,
> err=err@entry=0x7fffdb28, al=al@entry=0x558e85d8,
> file=file@entry=0x558df420 "/etc/haproxy/haproxy-ams4-dc.cfg",
> line=106) at src/acl.c:976
> arg_end = 6
> args_new = 0x558ee590
> arg = 
> neg = 0
> word = 
> cur_acl = 
> cur_term = 
> cur_suite = 0x558ee450
> cond = 0x558ee400
> suite_val = 524287
> #6  0x55631611 in build_acl_cond 

Re: 1.8.1-fe66fd doesn't finish startup and doesn't listen to sockets

[Pavlos Parissis]

On 07/12/2017 10:18 μμ, Pavlos Parissis wrote:
> On 07/12/2017 07:41 μμ, Willy Tarreau wrote:
>> Hi Pavlos!
>>
>> On Thu, Dec 07, 2017 at 07:16:54PM +0100, Pavlos Parissis wrote:
>>> Hi,
>>>
>>> OK, I haven't read the ML for ~2 weeks and a quick scan didn't reveal 
>>> anything.
>>> So, here I am asking something that may have been addressed already.
>>>
>>> Today, I decided to switch my dev env to haproxy-1.8 using current master 
>>> and I
>>> started haproxy in the same way as I have been doing with older releases:
>>>
>>> sudo ./haproxy -f /etc/haproxy/haproxy-ams4-dc.cfg
>>> [WARNING] 340/173007 (3104) : parsing 
>>> [/etc/haproxy/haproxy-ams4-dc.cfg:103] : a
>>> 'http-request' rule placed after a 'use_backend' rule will still be 
>>> processed before.
>>>
>>> above it didn't return and wasn't printing, expect the warning. I curled 
>>> against
>>> the IPs and got back connection error, see attached file for process 
>>> output, lsof
>>> info, build verion and haproxy.cfg.
>>>
>>> I also started in the way it is mentioned in section 3 of management 
>>> document:
>>> sudo ./haproxy  -f /etc/haproxy/haproxy-ams4-dc.cfg -D -p 
>>> /run/haproxy-ams4.pid
>>> -sf $(cat /run/haproxy-ams4.pid)
>>> cat: /run/haproxy-ams4.pid: No such file or directory
>>> [WARNING] 340/173007 (3104) : parsing 
>>> [/etc/haproxy/haproxy-ams4-dc.cfg:103] : a
>>> 'http-request' rule placed after a 'use_backend' rule will still be 
>>> processed before.
>>>
>>> but same result, haproxy didn't return and I had to CTRL-C it.
>>>
>>> I am pretty sure I am doing something stupid but I can't find it.
>>>
>>> Any ideas?
>>
>> It looks like it doesn't finish to startup in fact. Are you seeing it spin
>> on the CPU maybe ?
> 
> Yes, it does. I am sorry but I didn't notice it
> 


Found the issue. If I remove all set-var and var(req.) statements from the
config then haproxy loads.

Cheers,
Pavlos



signature.asc
Description: OpenPGP digital signature

Re: 1.8.1-fe66fd doesn't finish startup and doesn't listen to sockets

[Pavlos Parissis]

On 07/12/2017 07:41 μμ, Willy Tarreau wrote:
> Hi Pavlos!
> 
> On Thu, Dec 07, 2017 at 07:16:54PM +0100, Pavlos Parissis wrote:
>> Hi,
>>
>> OK, I haven't read the ML for ~2 weeks and a quick scan didn't reveal 
>> anything.
>> So, here I am asking something that may have been addressed already.
>>
>> Today, I decided to switch my dev env to haproxy-1.8 using current master 
>> and I
>> started haproxy in the same way as I have been doing with older releases:
>>
>> sudo ./haproxy -f /etc/haproxy/haproxy-ams4-dc.cfg
>> [WARNING] 340/173007 (3104) : parsing [/etc/haproxy/haproxy-ams4-dc.cfg:103] 
>> : a
>> 'http-request' rule placed after a 'use_backend' rule will still be 
>> processed before.
>>
>> above it didn't return and wasn't printing, expect the warning. I curled 
>> against
>> the IPs and got back connection error, see attached file for process output, 
>> lsof
>> info, build verion and haproxy.cfg.
>>
>> I also started in the way it is mentioned in section 3 of management 
>> document:
>> sudo ./haproxy  -f /etc/haproxy/haproxy-ams4-dc.cfg -D -p 
>> /run/haproxy-ams4.pid
>> -sf $(cat /run/haproxy-ams4.pid)
>> cat: /run/haproxy-ams4.pid: No such file or directory
>> [WARNING] 340/173007 (3104) : parsing [/etc/haproxy/haproxy-ams4-dc.cfg:103] 
>> : a
>> 'http-request' rule placed after a 'use_backend' rule will still be 
>> processed before.
>>
>> but same result, haproxy didn't return and I had to CTRL-C it.
>>
>> I am pretty sure I am doing something stupid but I can't find it.
>>
>> Any ideas?
> 
> It looks like it doesn't finish to startup in fact. Are you seeing it spin
> on the CPU maybe ?

Yes, it does. I am sorry but I didn't notice it

> Otherwise probably that starting it by hand in gdb and
> stopping it to see what it's doing will help.
>


pparissis at poseidonas in ~/repo/haproxy-1.8 on (master u=)
sudo gdb ./haproxy
GNU gdb (Debian 7.12-6) 7.12.0.20161007-git
Copyright (C) 2016 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later 
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
.
Find the GDB manual and other documentation resources online at:
.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from ./haproxy...done.
(gdb) run -f /etc/haproxy/haproxy-ams4-dc.cfg
Starting program: /home/pparissis/repo/haproxy-1.8/haproxy -f
/etc/haproxy/haproxy-ams4-dc.cfg
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[WARNING] 340/221611 (13628) : parsing [/etc/haproxy/haproxy-ams4-dc.cfg:103] : 
a
'http-request' rule placed after a 'use_backend' rule will still be processed 
before.
^C
Program received signal SIGINT, Interrupt.
0x5562e302 in register_name (name=0x558ee294 "selected_dc_backup",
len=18, scope=scope@entry=0x7fffd83c,
alloc=alloc@entry=1, err=0x7fffdb28) at src/vars.c:215
215 HA_RWLOCK_WRLOCK(VARS_LOCK, _names_rwlock);
(gdb) bt full
#0  0x5562e302 in register_name (name=0x558ee294 
"selected_dc_backup",
len=18, scope=scope@entry=0x7fffd83c,
alloc=alloc@entry=1, err=0x7fffdb28) at src/vars.c:215
i = 
var_names2 = 
tmp = 
res = 0x0
#1  0x5562f489 in vars_check_arg (arg=0x558ee600, err=)
at src/vars.c:502
name = 
scope = SCOPE_REQ
err = 
arg = 0x558ee600
#2  0x55609b94 in sample_parse_expr (str=str@entry=0x558ee598,
idx=idx@entry=0x7fffd964,
file=file@entry=0x558df420 "/etc/haproxy/haproxy-ams4-dc.cfg",
line=line@entry=106, err_msg=err_msg@entry=0x7fffdb28,
al=al@entry=0x558e85d8) at src/sample.c:901
begw = 
endw = 0x558df4c2 "req.selected_dc_backup)"
endt = 0x558df4d8 ")"
expr = 0x558ee5c0
fetch = 0x558ade30 
conv = 
prev_type = 6
fkw = 0x558ee2f0 "var"
ckw = 0x0
err_arg = 1
#3  0x55630144 in parse_acl_expr (args=args@entry=0x558ee598,
err=err@entry=0x7fffdb28, al=al@entry=0x558e85d8,
file=file@entry=0x558df420 "/etc/haproxy/haproxy-ams4-dc.cfg", line=106)
at src/acl.c:351
expr = 
aclkw = 0x0
refflags = 
patflags = 
arg = 
smp = 0x0
idx = 0
ckw = 0x0
begw = 
endw = 
endt = 
cur_type = 
nbargs = 
operator = 2
op = 
contain_colon = 
have_dot = 
dot = 
value = 3
minor = 40
 

Re: 1.8.1-fe66fd doesn't finish startup and doesn't listen to sockets

[Willy Tarreau]

Hi Pavlos!

On Thu, Dec 07, 2017 at 07:16:54PM +0100, Pavlos Parissis wrote:
> Hi,
> 
> OK, I haven't read the ML for ~2 weeks and a quick scan didn't reveal 
> anything.
> So, here I am asking something that may have been addressed already.
> 
> Today, I decided to switch my dev env to haproxy-1.8 using current master and 
> I
> started haproxy in the same way as I have been doing with older releases:
> 
> sudo ./haproxy -f /etc/haproxy/haproxy-ams4-dc.cfg
> [WARNING] 340/173007 (3104) : parsing [/etc/haproxy/haproxy-ams4-dc.cfg:103] 
> : a
> 'http-request' rule placed after a 'use_backend' rule will still be processed 
> before.
> 
> above it didn't return and wasn't printing, expect the warning. I curled 
> against
> the IPs and got back connection error, see attached file for process output, 
> lsof
> info, build verion and haproxy.cfg.
> 
> I also started in the way it is mentioned in section 3 of management document:
> sudo ./haproxy  -f /etc/haproxy/haproxy-ams4-dc.cfg -D -p 
> /run/haproxy-ams4.pid
> -sf $(cat /run/haproxy-ams4.pid)
> cat: /run/haproxy-ams4.pid: No such file or directory
> [WARNING] 340/173007 (3104) : parsing [/etc/haproxy/haproxy-ams4-dc.cfg:103] 
> : a
> 'http-request' rule placed after a 'use_backend' rule will still be processed 
> before.
> 
> but same result, haproxy didn't return and I had to CTRL-C it.
> 
> I am pretty sure I am doing something stupid but I can't find it.
> 
> Any ideas?

It looks like it doesn't finish to startup in fact. Are you seeing it spin
on the CPU maybe ? Otherwise probably that starting it by hand in gdb and
stopping it to see what it's doing will help.

Cheers,
Willy