Re: Stick table counter not working after upgrade to 2.2.11
On Tue, Mar 23, 2021 at 11:39:32PM +0100, Lukas Tribus wrote: > Hello, > > > just a heads-up, this was also reported for 1.8: > > https://discourse.haproxy.org/t/counter-issues-on-1-8-29/6381/ Thank you Lukas! Willy
stable-bot: Bugfixes waiting for a release 2.3 (6), 2.2 (3)
Hi, This is a friendly bot that watches fixes pending for the next haproxy-stable release! One such e-mail is sent periodically once patches are waiting in the last maintenance branch, and an ideal release date is computed based on the severity of these fixes and their merge date. Responses to this mail must be sent to the mailing list. Last release 2.3.7 was issued on 2021-03-16. There are currently 6 patches in the queue cut down this way: - 1 BUG, first one merged on 2021-03-23 - 3 MEDIUM, first one merged on 2021-03-22 - 2 MINOR, first one merged on 2021-03-18 Thus the computed ideal release date for 2.3.8 would be 2021-04-15, which is in three weeks or less. Last release 2.2.11 was issued on 2021-03-18. There are currently 3 patches in the queue cut down this way: - 1 BUG, first one merged on 2021-03-23 - 2 MEDIUM, first one merged on 2021-03-23 Thus the computed ideal release date for 2.2.12 would be 2021-04-20, which is in four weeks or less. The current list of patches in the queue is: - 2.2, 2.3 - BUG : mworker/cli: do not use the unix_bind prefix for the master CLI socket - 2.3 - MEDIUM : mux-fcgi: Fix locking of idle_conns lock in the FCGI I/O callback - 2.2, 2.3 - MEDIUM : debug/lua: Don't dump the lua stack if not dumpable - 2.2, 2.3 - MEDIUM : freq_ctr/threads: use the global_now_ms variable - 2.3 - MINOR : protocol: add missing support of dgram unix socket. - 2.3 - MINOR : freq_ctr/threads: make use of the last updated global time -- The haproxy stable-bot is freely provided by HAProxy Technologies to help improve the quality of each HAProxy release. If you have any issue with these emails or if you want to suggest some improvements, please post them on the list so that the solutions suiting the most users can be found.
Re: Stick table counter not working after upgrade to 2.2.11
Hello, just a heads-up, this was also reported for 1.8: https://discourse.haproxy.org/t/counter-issues-on-1-8-29/6381/ Lukas On Tue, 23 Mar 2021 at 09:32, Willy Tarreau wrote: > > Guys, > > These two patches address it for me, and I could verify that they apply > on top of 2.2.11 and work there as well. This time I tested with two > counters at different periods 500 and 2000ms. > > Thanks, > Willy
Re: [ANNOUNCE] haproxy-1.6.16
Hi Tim, On Tue, Mar 23, 2021 at 08:46:31PM +0100, Tim Düsterhus wrote: > Willy, > > On 3/19/21 6:32 PM, Willy Tarreau wrote: > >> Am 19.03.21 um 18:29 schrieb Willy Tarreau: > >>> [...] I know Christopher will harrass me if I > >>> forget anyway :-) > >> > >> Be assured, I will as well :-) > > > > No doubt :-) And that offloads my brain quite a lot! > > > > After the update haproxy.org shows a stray '>' above the table. This is > caused by an additional '>' after the '' element for the 1.8 row. > You might want to remove that. Wow, good catch, I didn't notice it and even with the indications it took me a moment to locate it! Now fixed, thanks! Willy
Re: [ANNOUNCE] haproxy-1.6.16
Willy, On 3/19/21 6:32 PM, Willy Tarreau wrote: >> Am 19.03.21 um 18:29 schrieb Willy Tarreau: >>> [...] I know Christopher will harrass me if I >>> forget anyway :-) >> >> Be assured, I will as well :-) > > No doubt :-) And that offloads my brain quite a lot! > After the update haproxy.org shows a stray '>' above the table. This is caused by an additional '>' after the '' element for the 1.8 row. You might want to remove that. Best regards Tim Düsterhus
Re: [2.2.9] 100% CPU usage
On Tue, Mar 23, 2021 at 04:12:41PM +0100, Christopher Faulet wrote: > Le 23/03/2021 à 11:14, Maciej Zdeb a écrit : > > Hi Christopher, > > > > Bad news, patches didn't help. Attaching stacktraces, now it looks that > > spoe that executes lua scripts (free_thread_spue_lua.txt) tried to > > malloc twice. :( > > > > It is most probably because of compiler optimizations. Some compiler > barriers are necessary to avoid instructions reordering. It is the purpose > of attached patches. Sorry to ask you it again, but could you make some > tests ? I don't believe in it at all. free(), malloc() etc are free to manipulate global variables so the compiler cannot reorder these operations around them. We're probably facing other corner cases (or the same but not totally addressed maybe). Willy
Re: is it possible to rotate TLS keys in scheduled way ?
On Fri, Mar 19, 2021 at 09:50:29PM +0500, Илья Шипицин wrote: > Hello, > > can we have the following ? > > 1) TLS tickets are persistent, i.e. they survive reload There is no mecanism at the moment to pass memory from a process to another one, it's a much larger problem that you have with statistics, certificates, server state file etc. The correct way to achieve this in the current state is to dump the file from the CLI before reloading. > 2) we can specify ttl of tickets Hm that's an interesting idea but you can only store 3 tickets by default a new ticket will need to be pushed each time a ticket expired. -- William Lallemand
Re: [2.2.9] 100% CPU usage
Le 23/03/2021 à 11:14, Maciej Zdeb a écrit :
Hi Christopher,
Bad news, patches didn't help. Attaching stacktraces, now it looks that spoe
that executes lua scripts (free_thread_spue_lua.txt) tried to malloc twice. :(
It is most probably because of compiler optimizations. Some compiler barriers
are necessary to avoid instructions reordering. It is the purpose of attached
patches. Sorry to ask you it again, but could you make some tests ?
Thanks !
--
Christopher Faulet
>From b4f55500b514e5bfcdaba938cbd2b0ba3cfb2f62 Mon Sep 17 00:00:00 2001
From: Christopher Faulet
Date: Tue, 23 Mar 2021 15:17:22 +0100
Subject: [PATCH] BUG/MEDIUM: hlua: Use compiler barrier to protect
hlua_not_dumpable increments
In hlua_alloc() function, the hlua_not_dumpable variable is incremented
before any call to realloc() and decremented just after. To be sure it
really works, we must prevent any instruction reordering. Thus compiler
barriers have been added to do so.
The patch fixes a bug in the commit a61789a1d ("MEDIUM: lua: Use a
per-thread counter to track some non-reentrant parts of lua"). It must be
backported as far as 2.0.
---
src/hlua.c | 6 ++
1 file changed, 6 insertions(+)
diff --git a/src/hlua.c b/src/hlua.c
index 5bef67a48b..9fc30336f1 100644
--- a/src/hlua.c
+++ b/src/hlua.c
@@ -8196,7 +8196,9 @@ static void *hlua_alloc(void *ud, void *ptr, size_t osize, size_t nsize)
if (ptr)
zone->allocated -= osize;
hlua_not_dumpable++;
+ __ha_compiler_barrier();
free(ptr);
+ __ha_compiler_barrier();
hlua_not_dumpable--;
return NULL;
}
@@ -8207,7 +8209,9 @@ static void *hlua_alloc(void *ud, void *ptr, size_t osize, size_t nsize)
return NULL;
hlua_not_dumpable++;
+ __ha_compiler_barrier();
ptr = malloc(nsize);
+ __ha_compiler_barrier();
hlua_not_dumpable--;
if (ptr)
zone->allocated += nsize;
@@ -8219,7 +8223,9 @@ static void *hlua_alloc(void *ud, void *ptr, size_t osize, size_t nsize)
return NULL;
hlua_not_dumpable++;
+ __ha_compiler_barrier();
ptr = realloc(ptr, nsize);
+ __ha_compiler_barrier();
hlua_not_dumpable--;
if (ptr)
zone->allocated += nsize - osize;
--
2.30.2
>From 8eee5c4ba6eb92ceece0414b716c075c81d689ab Mon Sep 17 00:00:00 2001
From: Christopher Faulet
Date: Tue, 23 Mar 2021 15:16:52 +0100
Subject: [PATCH] BUG/MEDIUM: hlua: Use compiler barrier to protect
hlua_not_dumpable increments
In hlua_alloc() function, the hlua_not_dumpable variable is incremented
before any call to realloc() and decremented just after. To be sure it
really works, we must prevent any instruction reordering. Thus compiler
barriers have been added to do so.
The patch fixes a bug in the commit a61789a1d ("MEDIUM: lua: Use a
per-thread counter to track some non-reentrant parts of lua"). It must be
backported as far as 2.0.
---
src/hlua.c | 6 ++
1 file changed, 6 insertions(+)
diff --git a/src/hlua.c b/src/hlua.c
index 990080b8c..ba7f93a99 100644
--- a/src/hlua.c
+++ b/src/hlua.c
@@ -8245,7 +8245,9 @@ static void *hlua_alloc(void *ud, void *ptr, size_t osize, size_t nsize)
if (ptr)
zone->allocated -= osize;
hlua_not_dumpable++;
+ __ha_compiler_barrier();
free(ptr);
+ __ha_compiler_barrier();
hlua_not_dumpable--;
return NULL;
}
@@ -8256,7 +8258,9 @@ static void *hlua_alloc(void *ud, void *ptr, size_t osize, size_t nsize)
return NULL;
hlua_not_dumpable++;
+ __ha_compiler_barrier();
ptr = malloc(nsize);
+ __ha_compiler_barrier();
hlua_not_dumpable--;
if (ptr)
zone->allocated += nsize;
@@ -8268,7 +8272,9 @@ static void *hlua_alloc(void *ud, void *ptr, size_t osize, size_t nsize)
return NULL;
hlua_not_dumpable++;
+ __ha_compiler_barrier();
ptr = realloc(ptr, nsize);
+ __ha_compiler_barrier();
hlua_not_dumpable--;
if (ptr)
zone->allocated += nsize - osize;
--
2.30.2
>From 35c1b30ef2d725a37a82f0a293b2bd0bd7c473e2 Mon Sep 17 00:00:00 2001
From: Christopher Faulet
Date: Tue, 23 Mar 2021 15:10:46 +0100
Subject: [PATCH] BUG/MEDIUM: hlua: Use compiler barrier to protect
hlua_not_dumpable increments
In hlua_alloc() function, the hlua_not_dumpable variable is incremented
before any call to realloc() and decremented just after. To be sure it
really works, we must prevent any instruction reordering. Thus compiler
barriers have been added to do so.
The patch fixes a bug in the commit a61789a1d ("MEDIUM: lua: Use a
per-thread counter to track some non-reentrant parts of lua"). It must be
backported as far as 2.0.
---
src/hlua.c | 4
1 file changed, 4 insertions(+)
diff --git a/src/hlua.c b/src/hlua.c
index 962195a60..d47973dcf 100644
--- a/src/hlua.c
+++ b/src/hlua.c
@@ -8639,7 +8639,9 @@ static void *hlua_alloc(void *ud, void *ptr, size_t osize, size_t nsize)
*/
if (likely(~zone->limit == 0)) {
hlua_not_dumpable++;
+ __ha_compiler_barrier();
ptr = realloc(ptr, nsize);
+ __ha_compiler_barrier();
hlua_not_dumpable--;
return ptr;
}
@@ -8657,7 +8659,9 @@ static void
Re: [2.2.9] 100% CPU usage
Hi Christopher, Bad news, patches didn't help. Attaching stacktraces, now it looks that spoe that executes lua scripts (free_thread_spue_lua.txt) tried to malloc twice. :( Kind regards, pon., 22 mar 2021 o 08:39 Maciej Zdeb napisał(a): > Hi Christopher, > > Thanks! I'm building a patched version and will return with feedback! > > Kind regards, > > pt., 19 mar 2021 o 16:40 Christopher Faulet > napisał(a): > >> Le 16/03/2021 à 13:46, Maciej Zdeb a écrit : >> > Sorry for spam. In the last message I said that the old process (after >> reload) >> > is consuming cpu for lua processing and that's not true, it is >> processing other >> > things also. >> > >> > I'll take a break. ;) Then I'll verify if the issue exists on 2.3 and >> maybe 2.4 >> > branch. For each version I need a week or two to be sure the issue does >> not >> > occur. :( >> > >> > If 2.3 and 2.4 behaves the same way the 2.2 does, I'll try to confirm >> if there >> > is any relation between infinite loops and custom configuration: >> > - lua scripts (mainly used for header generation/manipulation), >> > - spoe (used for sending metadata about each request to external >> service), >> > - peers (we have a cluster of 12 HAProxy servers connected to each >> other). >> > >> Hi Maciej, >> >> I've read more carefully your backtraces, and indeed, it seems to be >> related to >> lua processing. I don't know if the watchdog is triggered because of the >> lua or >> if it is just a side-effect. But the lua execution is interrupted inside >> the >> memory allocator. And malloc/realloc are not async-signal-safe. >> Unfortunately, >> when the lua stack is dumped, the same allocator is also used. At this >> stage, >> because a lock was not properly released, HAProxy enter in a deadlock. >> >> On other threads, we loop in the watchdog, waiting for the hand to dump >> the >> thread information and that explains the 100% CPU usage you observe. >> >> So, to prevent this situation, the lua stack must not be dumped if it was >> interrupted inside an unsafe part. It is the easiest way we found to >> workaround >> this bug. And because it is pretty rare, it should be good enough. >> >> However, I'm unable to reproduce the bug. Could you test attached patches >> please >> ? I attached patched for the 2.4, 2.3 and 2.2. Because you experienced >> this bug >> on the 2.2, it is probably easier to test patches for this version. >> >> If fixed, it could be good to figure out why the watchdog is triggered on >> your >> old processes. >> >> -- >> Christopher Faulet >> > [Switching to thread 10 (Thread 0x7f5246c9d700 (LWP 15807))] #0 __lll_lock_wait_private () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:95 95 ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S: No such file or directory. (gdb) bt full #0 __lll_lock_wait_private () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:95 No locals. #1 0x7f52fb16c34b in __GI___libc_malloc (bytes=bytes@entry=41) at malloc.c:3063 ignore1 = ignore2 = ignore3 = ar_ptr = 0x7f523420 victim = hook = tbytes = tc_idx = __x = ignore1 = ignore2 = ignore3 = ignore = #2 0x55d94949e9a9 in hlua_alloc (ud=0x55d9498e90d0 , ptr=, osize=4, nsize=41) at src/hlua.c:8210 zone = 0x55d9498e90d0 #3 0x55d949622271 in luaM_realloc_ () No symbol table info available. #4 0x55d949621dbe in luaC_newobj () No symbol table info available. #5 0x55d949626f4d in internshrstr () No symbol table info available. #6 0x55d9496271fc in luaS_new () No symbol table info available. #7 0x55d94961bd03 in lua_pushstring () No symbol table info available. #8 0x55d94962d48a in luaL_traceback () No symbol table info available. #9 0x55d9495a1b62 in ha_task_dump (buf=buf@entry=0x7f5247c7f628, task=0x7f5234057ba0, pfx=pfx@entry=0x55d949672f19 ' ' ) at src/debug.c:227 s = appctx = hlua = 0x7f52341bdc60 #10 0x55d9495a1fd7 in ha_thread_dump (buf=0x7f5247c7f628, thr=, calling_tid=7) at src/debug.c:91 thr_bit = 512 p = 74138721 n = stuck = 0 #11 0x55d9495a2236 in debug_handler (sig=, si=, arg=) at src/debug.c:847 sig = ---Type to continue, or q to quit--- si = arg = #12 No locals. #13 _int_malloc (av=av@entry=0x7f523420, bytes=bytes@entry=56) at malloc.c:4100 p = iters = nb = 64 idx = 5 bin = victim = 0x7f52341cbff0 size = victim_index = remainder = 0x7f52341cc030 remainder_size = block = bit = map = fwd = bck = tcache_unsorted_count = 0 tcache_nb = 64 tc_idx = 2 return_cached = 0 __PRETTY_FUNCTION__ = "_int_malloc" #14 0x7f52fb16c35d in __GI___libc_malloc (bytes=bytes@entry=56) at malloc.c:3065 ar_ptr =
Re: Stick table counter not working after upgrade to 2.2.11
On 2021-03-23 09:32, Willy Tarreau wrote: Guys, These two patches address it for me, and I could verify that they apply on top of 2.2.11 and work there as well. This time I tested with two counters at different periods 500 and 2000ms. I've just applied your patches and tested. It seems to work now. Thanks. Sander
Re: Stick table counter not working after upgrade to 2.2.11
Guys,
These two patches address it for me, and I could verify that they apply
on top of 2.2.11 and work there as well. This time I tested with two
counters at different periods 500 and 2000ms.
Thanks,
Willy
>From 6064b34be0e761de881a5bfca287d01f69122602 Mon Sep 17 00:00:00 2001
From: Willy Tarreau
Date: Tue, 23 Mar 2021 08:45:42 +0100
Subject: MINOR: time: also provide a global, monotonic global_now_ms timer
The period-based freq counters need the global date in milliseconds,
so better calculate it and expose it rather than letting all call
places incorrectly retrieve it.
Here what we do is that we maintain a new globally monotonic timer,
global_now_ms, which ought to be very close to the global_now one,
but maintains the monotonic approach of now_ms between all threads
in that global_now_ms is always ahead of any now_ms.
This patch is made simple to ease backporting (it will be needed for
a subsequent fix), but it also opens the way to some simplifications
on the time handling: instead of computing the local time and trying
to force it to the global one, we should soon be able to proceed in
the opposite way, that is computing the new global time an making the
local one just the latest snapshot of it. This will bring the benefit
of making sure that the global time is always ahead of the local one.
---
include/haproxy/time.h | 1 +
src/time.c | 12
2 files changed, 13 insertions(+)
diff --git a/include/haproxy/time.h b/include/haproxy/time.h
index 87bc3655a..93dd84080 100644
--- a/include/haproxy/time.h
+++ b/include/haproxy/time.h
@@ -61,6 +61,7 @@ extern struct timeval start_date; /* the process's
start date */
extern THREAD_LOCAL struct timeval before_poll; /* system date before
calling poll() */
extern THREAD_LOCAL struct timeval after_poll; /* system date after
leaving poll() */
extern volatile unsigned long long global_now;
+extern volatile unsigned int global_now_ms;
/ exported functions */
diff --git a/src/time.c b/src/time.c
index d5344d26f..0cfc9bf3c 100644
--- a/src/time.c
+++ b/src/time.c
@@ -15,6 +15,7 @@
#include
#include
+#include
#include
THREAD_LOCAL unsigned int ms_left_scaled; /* milliseconds left for current
second (0..2^32-1) */
@@ -29,6 +30,7 @@ THREAD_LOCAL struct timeval after_poll; /* system date
after leaving poll()
static THREAD_LOCAL struct timeval tv_offset; /* per-thread time ofsset
relative to global time */
volatile unsigned long long global_now; /* common date between all
threads (32:32) */
+volatile unsigned int global_now_ms; /* common date in milliseconds
(may wrap) */
static THREAD_LOCAL unsigned int iso_time_sec; /* last iso time value for
this thread */
static THREAD_LOCAL char iso_time_str[34]; /* ISO time representation
of gettimeofday() */
@@ -177,6 +179,7 @@ void tv_update_date(int max_wait, int interrupted)
{
struct timeval adjusted, deadline, tmp_now, tmp_adj;
unsigned int curr_sec_ms; /* millisecond of current second
(0..999) */
+ unsigned int old_now_ms, new_now_ms;
unsigned long long old_now;
unsigned long long new_now;
@@ -260,6 +263,15 @@ void tv_update_date(int max_wait, int interrupted)
*/
ms_left_scaled = (999U - curr_sec_ms) * 4294967U;
now_ms = now.tv_sec * 1000 + curr_sec_ms;
+
+ /* update the global current millisecond */
+ old_now_ms = global_now_ms;
+ do {
+ new_now_ms = old_now_ms;
+ if (tick_is_lt(new_now_ms, now_ms))
+ new_now_ms = now_ms;
+ } while (!_HA_ATOMIC_CAS(_now_ms, _now_ms, new_now_ms));
+
return;
}
--
2.28.0
>From 8cc586c73fefd96f4be1f7820e38a1263f6252ca Mon Sep 17 00:00:00 2001
From: Willy Tarreau
Date: Tue, 23 Mar 2021 08:58:22 +0100
Subject: BUG/MEDIUM: freq_ctr/threads: use the global_now_ms variable
In commit a1ecbca0a ("BUG/MINOR: freq_ctr/threads: make use of the last
updated global time"), for period-based counters, the millisecond part
of the global_now variable was used as the date for the new period. But
it's wrong, it only works with sub-second periods as it wraps every
second, and for other periods the counters never rotate anymore.
Let's make use of the newly introduced global_now_ms variable instead,
which contains the global monotonic time expressed in milliseconds.
This patch needs to be backported wherever the patch above is backported.
It depends on previous commit "MINOR: time: also provide a global,
monotonic global_now_ms timer".
---
include/haproxy/freq_ctr.h | 2 +-
src/freq_ctr.c | 4 ++--
2 files changed, 3 insertions(+), 3 deletions(-)
diff --git a/include/haproxy/freq_ctr.h b/include/haproxy/freq_ctr.h
index d5cea414e..b1db43ef6 100644
--- a/include/haproxy/freq_ctr.h
+++ b/include/haproxy/freq_ctr.h
@@ -88,7 +88,7 @@ static inline unsigned int
Re: Stick table counter not working after upgrade to 2.2.11
On Tue, Mar 23, 2021 at 08:08:16AM +0100, Willy Tarreau wrote: > Hi guys, > > On Mon, Mar 22, 2021 at 10:08:01PM +, Bren wrote: > > > I have upgraded to haproxy 2.2.11 today and it seems like my stick table > > > counter is not working anymore. > > > > I was going to upgrade to 2.2.11 soon so I tested this quick and can > > confirm that counters no longer decrement over time. Tested this using the > > haproxy:2.2.11 Docker image and a standard stick table: > > > > fe-test > > http-request track-sc0 src table be-test > > > > be-test > > stick-table type ipv6 size 1m expire 24h store http_req_rate(2s) > > I'll have a look at it. I fixed a problem affecting the counters > that was occasionally causing livelocks in multi-threaded > environments and causing the counters to be randomly reset when > switching to the next second, I could confirm that it did address > the problem for me (i.e. no more zeroes nor livelocks) but I have not > seen this corner case yet. I'll keep you updated. I understand now. My logic for the periods was flawed because I assumed that now_ms only represented the millisecond within the current second while it contains the current tick. And given that my test was run with sub-second period to make sure not to mess up on this one, I failed the other ones that are >1s :-( I'll introduce a global_now_ms for the monotonic tick counter, it will be easier and safer than having to perform the operation at various call places. In the mean time, if anyone has a good idea how to write a regtest for freq_ctrs, I'd be very interested in smart suggestions. Last time I was quite frustrated not being able to test these ones because they're too timing-dependent for an automated test and ended up using obviously incomplete tests :-/ Thanks, Willy
Re: Stick table counter not working after upgrade to 2.2.11
Hi guys, On Mon, Mar 22, 2021 at 10:08:01PM +, Bren wrote: > > I have upgraded to haproxy 2.2.11 today and it seems like my stick table > > counter is not working anymore. > > I was going to upgrade to 2.2.11 soon so I tested this quick and can confirm > that counters no longer decrement over time. Tested this using the > haproxy:2.2.11 Docker image and a standard stick table: > > fe-test > http-request track-sc0 src table be-test > > be-test > stick-table type ipv6 size 1m expire 24h store http_req_rate(2s) I'll have a look at it. I fixed a problem affecting the counters that was occasionally causing livelocks in multi-threaded environments and causing the counters to be randomly reset when switching to the next second, I could confirm that it did address the problem for me (i.e. no more zeroes nor livelocks) but I have not seen this corner case yet. I'll keep you updated. Thanks! Willy
