Re: 1.8.8 & 1.9dev, lua, xref_get_peer_and_lock hang / 100% cpu usage after restarting haproxy a few times

[PiBa-NL]

Hi Thierry,

Okay found a simple reproduction with tcploop with a 6 second delay in 
there and a short sleep before calling kqueue.

./tcploop 81 L W N20 A R S:"response1\r\n" R P6000 S:"response2\r\n" R [ 
F K ]

     gettimeofday(&before_poll, NULL);
+    usleep(100);
     status = kevent(kqueue_fd[tid], // int kq

Together with the attached config the issue is reproduced every time the 
/myapplet url is requested.

Output as below:
00000000:stats.clihdr[0007:ffffffff]: Accept-Language: 
nl-NL,nl;q=0.9,en-US;q=0.8,en;q=0.7
[info] 130/195936 (76770) : Wait for it..
[info] 130/195937 (76770) : Wait response 2..
  xref_get_peer_and_lock xref->peer == 1

Hope this helps to come up with a solution..

Thanks in advance,
PiBa-NL (Pieter)

Op 9-5-2018 om 19:47 schreef PiBa-NL:
Hi Thierry,

Op 9-5-2018 om 18:30 schreef Thierry Fournier:
It seems a dead lock, but you observe a loop. 
Effectively it is a deadlock, it keeps looping over these few lines of 
code below from xref.h 
<http://git.haproxy.org/?p=haproxy.git;a=blob_plain;f=include/common/xref.h;hb=29d698040d6bb56b29c036aeba05f0d52d8ce94b>.. 
The XCHG just swaps the 2 values (both are '1') and continues on, then 
the local==BUSY check is true it loops and swaps 1 and 1 again, and 
the circle continues..

Thanks for looking into it :) Ill try and get 'simpler' reproduction 
with some well placed sleep() as you suggest.
Regards,
PiBa-NL

http://git.haproxy.org/?p=haproxy.git;a=blob;f=include/common/xref.h;h=6dfa7b62758dfaebe12d25f66aaa858dc873a060;hb=29d698040d6bb56b29c036aeba05f0d52d8ce94b 


function myapplet(applet)

  core.Info("Wait for it..")
  core.sleep(1)

  local result = ""
    con = core.tcp()
    con:settimeout(1)
    con:connect("127.0.0.1",81)
    con:send("Test1\r\n")
    r = con:receive("*l")
    result = result .. tostring(r)
    con:send("Test\r\n")
  core.Info("Wait response 2..")
    r2 = con:receive("*l")
    result = result .. tostring(r2)
  core.Info("close..")
    con:close()
  core.Info("DONE")

        response = "Finished"
        applet:add_header("Server", "haproxy/webstats")
        applet:add_header("Content-Type", "text/html")
        applet:start_response()
        applet:send(response)

end

core.register_service("myapplet", "http", myapplet)
global
  lua-load /root/haproxytest/hang_timeout_close.lua

defaults
        mode http
        timeout connect 5s
        timeout client 30s
        timeout server 60s
  
frontend stats
        bind *:80
        stats enable
        stats admin if TRUE
        stats refresh 1s

  acl myapplet path -m beg /myapplet
  http-request use-service lua.myapplet if myapplet

 include/common/xref.h | 4 ++++
 src/ev_kqueue.c       | 1 +
 2 files changed, 5 insertions(+)

diff --git a/include/common/xref.h b/include/common/xref.h
index 6dfa7b6..e6905a1 100644
--- a/include/common/xref.h
+++ b/include/common/xref.h
@@ -25,6 +25,10 @@ static inline void xref_create(struct xref *xref_a, struct 
xref *xref_b)
 
 static inline struct xref *xref_get_peer_and_lock(struct xref *xref)
 {
+       if (xref->peer == 1) {
+               printf("  xref_get_peer_and_lock xref->peer == 1 \n");
+       }
+
        struct xref *local;
        struct xref *remote;
 
diff --git a/src/ev_kqueue.c b/src/ev_kqueue.c
index bf7f666..732f20d 100644
--- a/src/ev_kqueue.c
+++ b/src/ev_kqueue.c
@@ -145,6 +145,7 @@ REGPRM2 static void _do_poll(struct poller *p, int exp)
 
        fd = global.tune.maxpollevents;
        gettimeofday(&before_poll, NULL);
+       usleep(100);
        status = kevent(kqueue_fd[tid], // int kq
                        NULL,      // const struct kevent *changelist
                        0,         // int nchanges