Hi,
> On 24 Apr 2018, at 21:46, PiBa-NL <[email protected]> wrote: > > Hi Tim, > > Op 24-4-2018 om 14:36 schreef Tim Düsterhus: >> Hi >> >> Am 23.04.2018 um 22:36 schrieb PiBa-NL: >>> Is there a bug in my script, or is it more likely that 'something' needs >>> fixing in the lua api / interaction? >> I poked around a bit: The cause in this case is the Content-Length >> header. It causes that haproxy does not use chunked encoding for the output. >> >> My suspicion is some kind of "race condition". It looks like that the >> applet function does not get scheduled any more, once all data is sent >> over the wire and thus the output to stdout is not printed in all cases. It makes sense. Lua processing is regularly interrupted. The interrupt condition is a number of instructions of Lua executes (this is for preserving fast processing for other HAProxy task - We don’t want to be blocked anytime in heavy processing Lua function). Maybe the script is interrupted during the dump ? The print_r function doesn’t use HAProxy things. It just write data on stdout with classic Lua function. So, we don’t have buffer problem or something like that. Note: +1 for your usage of the print_r() function :-) >> I could not reproduce the issue if I added another `applet:send()` below >> the second print_r. I also could not reproduce the issue if the >> Content-Length header specifies a length *greater* than the actual >> length of the content. I could however reproduce it, if the >> Content-Length header specifies a length *smaller* than the actual >> length of the content. >> >> Best regards >> Tim Düsterhus > > Thanks for investigating, i did a little more of my own also :) and got some > results (also a crash..). > As you say found i do string.len(response)+1 and then another send("1") in > the end it suddenly runs fine. > > Running from gdb directly allowed me to get a readable backtrace of the crash > that seems to happen due to the print_r of the core.get_info() .. > Requesting the stats page from 1 and the coreinfo from 3 browserwindows. I extracted the part which dumps the ‘core.get_info()’, and I can’t reproduce the segfault. I attach the extracted code. I use le lastest master branch. Note that I do not have the date of this email because my email server is broken and it date is stick in 2002 (if i set the hour the servers stops…) :-(
bug29.conf
Description: Binary data
bug29.lua
Description: Binary data
> When just requesting the core.get_info() and NOT printing it to core.Info()
> it runs fine for a long time.
> Somehow this output method seems related to some serous issue at least when
> combined with large output from lua.. Perhaps there is a deeper issue?.?
> Technically its probably not advisable to dump such large output's on the
> console.. But still to crash on that, i didn't expect it, and dumping info on
> console is the only way i can easily 'debug' the scripts interaction with
> haproxy..
>
> Anyhow hoping it can be fixed or even maybe just some string can be truncated
> at its maximum buffer length.?.
>
> Regards,
>
> PiBa-NL (Pieter)
>
> global
> nbthread 1
> lua-load /root/haproxytest/print_r.lua
> lua-load /root/haproxytest/smtpmailqueue/smtpmailqueue.lua
> lua-load /root/haproxytest/serverhealthchecker/serverhealthchecker.lua
> lua-load /root/haproxytest/serverhealth_smtpmail.lua
>
> defaults
> mode http
> timeout connect 5s
> timeout client 30s
> timeout server 60s
>
> frontend TestSite
> bind *:80
>
> acl webrequest path -m beg /webrequest
> http-request use-service lua.testitweb-webrequest if webrequest
>
> stats enable
> stats admin if TRUE
> stats refresh 1s
>
> # prevent overloading yourself with loopback requests..
> acl isloopback src 127.0.0.0/8
> http-request deny if isloopback
>
> default_backend myservers
>
> backend myservers
> server localSRVa 127.0.0.1:80 check
> server localSRVb 127.0.0.1:81 check inter 20s
> server localSRVc 127.0.0.1:82 check
>
> ##### serverhealth_smtpmail.lua ######
>
> local smtpmailer = Smtpmailqueue("luamailer",5)
> smtpmailer:setserver("127.0.0.1","25")
>
> local checknotifier = function(subject, message, serverstatecounters,
> allstates)
> smtpmailer:addmail("[email protected]","[email protected]","[srv-checker]"..subject,
> message.."\r\n"..serverstatecounters.."\r\n\r\n"..allstates)
> end
> local mychecker = Serverhealthchecker("hapchecker",3,2,checknotifier)
>
> testitweb = {}
> testitweb.webrequest = function(applet)
> if string.match(applet['path'],"/webrequest/mailstat") then
> return smtpmailer:webstats(applet)
> end
>
> if string.match(applet['path'],"/webrequest/coreinfo") then
> core.Info("################# CORE 1")
> local cor = core.get_info()
> print_r(cor)
> core.Info("################# CORE 1 ^")
>
> local resp = ""
> print_r(core.get_info(),false,function(x)
> resp=resp..string.gsub(x,"\n","<br/>")
> end
> )
> response = "CoreInfo:"..resp
>
> applet:add_header("Server", "haproxy/webstats")
> applet:add_header("Content-Length", string.len(response))
> applet:add_header("Content-Type", "text/html")
> applet:add_header("Refresh", "1")
> applet:start_response()
> applet:send(response)
>
> core.Info("################# CORE 2")
> local cor = core.get_info()
> print_r(cor)
> core.Info("################# CORE 2 ^")
> end
> end
> core.register_service("testitweb-webrequest", "http", testitweb.webrequest)
>
>
> [info] 113/212806 (10702) : ################# CORE 1 ^
> [info] 113/212806 (10702) : ################# CORE 2
> (table) table: 0x8022d4900 [
> "Memmax_MB": (number) 0
> "Pid": (number) 10702
> "Uptime_sec": (number) 9
> "PipesUsed": (number) 0
> "Uptime": (string) "0d 0h00m09s"
> "SslFrontendMaxKeyRate": (number) 0
> "CumConns": (number) 14
> "PoolAlloc_MB": (number) 0
> "SslFrontendKeyRate": (number) 0
> "node": (string) "freebsd11"
> "Idle_pct": (number) 100
> "Run_queue": (number) 1
> "ConnRate": (number) 1
> "Maxpipes": (number) 0
> "Nbproc": (number) 1
> "CompressBpsOut": (number) 0
> "Version": (string) "1.9-dev0-564d15-357"
> "MaxSslConns": (number) 0
> Program received signal SIGSEGV, Segmentation fault.
> eb32sc_next_with_parent (start=0x0, scope=1) at eb32sctree.h:121
> 121 start = (eb_untag(start, EB_LEFT))->b[EB_RGHT];
> Current language: auto; currently minimal
> (gdb) bt full
> #0 eb32sc_next_with_parent (start=0x0, scope=1) at eb32sctree.h:121
> No locals.
> #1 0x00000000005929d1 in eb32sc_next (eb32=0x80222b360, scope=1) at
> eb32sctree.h:131
> No locals.
> #2 0x000000000059213e in process_runnable_tasks () at src/task.c:218
> t = (struct task *) 0x80222b360
> i = 32767
> max_processed = 199
> rq_next = (struct eb32sc_node *) 0x80222b360
> local_tasks = 0x7fffffffe4f0
> local_tasks_count = 0
> final_tasks_count = 0
> #3 0x0000000000510aab in run_poll_loop () at src/haproxy.c:2401
> next = -115303713
> exp = -115304019
> #4 0x000000000050e3b0 in run_thread_poll_loop (data=0x802242088) at
> src/haproxy.c:2463
> start_lock = 0
> ptif = (struct per_thread_init_fct *) 0x82a878
> ptdf = (struct per_thread_deinit_fct *) 0x202
> #5 0x000000000050afb9 in main (argc=3, argv=0x7fffffffea60) at
> src/haproxy.c:3053
> tids = (unsigned int *) 0x802242088
> threads = (pthread_t *) 0x802242090
> i = 1
> err = 0
> retry = 200
> limit = {rlim_cur = 4014, rlim_max = 4014}
> errmsg = 0x7fffffffe970 ""
> pidfd = -1
> (gdb)
>
