Debugging two http_server inside docker containers

Help!
1

I’m using: SWI-Prolog (threaded, 64 bits, version 10.0.2)

I try to debug two containers running http_server, where one functions as a proxy calling the other using http_post.

Every 30 requests or so I get such an error on the proxy: (the browser gets HTTP-500)
url `‘http://akrido:8081/analinioj’’ does not exist (status(503,Service Unavailable))

This is coming back as fast as the valid answers (150ms). So it seems there is no timeout involved. Could some kind of network issue. The fast return hints on a client (i.e. proxy) side issue. I do not use the connection(keep_alive) option in the http_post - not sure what would be the best approach in this proxy scenario.

I tried to debug the http requests using the containers log (stdout) but I don’t see the output. Where it is going to? I tried those two commands:

[swipl,-s,analizo-servo.pl,-g,debug(http(request)),-g,daemon,-t,halt(1),--,--workers=10,--port=8081,--no-fork]
% Started server at http://localhost:8081/

[swipl,-s,analizo-servo.pl,-g,daemon,-t,halt(1),--,--workers=10,--port=8081,--no-fork,--debug='http(request)']
% Started server at http://localhost:8081/

How I would debug this issue? Any hint where to look specifically would help me.

Thank you,
Wolfram.

2

503 is a resource error, no?

  ?- [library(http/http_error)].

This should cause a backtrace to be printed on HTTP server errors.

3

Ah thank you, this helps a bit further. Now I get this in the browser:

~~~
url `‘http://akrido:8081/analinioj’’ does not exist (status(503,Service Unavailable))\nIn:\n
[25] throw(error(existence_error(url,‘http://akrido:8081/analinioj’),context(_39148,…)))\n
[23] http_open:try_http_proxy(direct,[uri(‘http://akrido:8081/analinioj’),…|…],_39184,[headers(_39212),…])
at /usr/lib/swipl/library/ext/http/http/http_open.pl:512\n
[21] http_client:http_get(‘http://akrido:8081/analinioj’,_39250,[post(…)])
at /usr/lib/swipl/library/ext/http/http/http_client.pl:145\n
[19] redakt…:565\n
[6] httpd_wrapper:handler_with_output_to(http_unix_daemon:http_dispatch,101,[pool(…),…|…],current_output,_39620)
at /usr/lib/swipl/library/ext/http/http/http_wrapper.pl:312\n
[5] httpd_wrapper:handler_with_output_to(http_unix_daemon:http_dispatch,101,[pool(…),…|…],(0x55d58555a400),_39680)
at /usr/lib/swipl/library/ext/http/http/http_wrapper.pl:322\n\n
Note: some frames are missing due to last-call optimization.\n
Re-run your program in debug mode (:- debug.) to get more detail.
~~~

Method=direct means “don’t use a proxy”, right? This would be ok so far. Not fully sure, but this could be the place where the error is catched in http_open:try_http_proxy

~~~

catch(send_rec_header(StreamPair, Stream, HostPort,
RequestURI, Parts, Options),
error(E,_),
keep_alive_error(E))

~~~

Seems I have to dig a bit deeper at this place tomorrow.

Regards,
Wolfram.

4

But, this is the client that gets a 503 from the other side. It is that other side that is broken. 503 means resource error. That can mean the server is overloaded or, in particular if it is also a Prolog server, it runs out of stack. If the server is also Prolog, load http_error into that one as well.

5

Hi Jan,

I could not get debug output into the container log using the --debug command line option so far, but adding a hook for user:exception I now see random crashes of the worker threads:

thread: httpd@8081_9, exc: undefined_predicate, ctx: thread:same_length/2,
thread: httpd@8081_7, exc: undefined_predicate, ctx: thread:must_be/2,
thread: <thread>(17,0x562c09d9e280), exc: undefined_predicate, ctx: analizilo:maplist/3,
thread: <thread>(17,0x562c09d9e280), exc: undefined_global_variable, ctx: $inprint_message,
thread: <thread>(17,0x562c09d9e280), exc: undefined_predicate, ctx: gramatiko:aggregate/3,
thread: <thread>(17,0x562c09d9e280), exc: undefined_global_variable, ctx: $autoload_disabling,
...

It appears that there are workers added until the resources in my container are exhausted around 30 workers and than workers start crashing. I did not see those http-503 errors before (last year) and apparantly dead workers not always cause the http-503 on the client side. So I suppose the equilibrium between resources, load average, workers, timing was different some months back.

I see there is a max_workers option hidden here: SWI-Prolog -- library(http/http_dyn_workers): Dynamically schedule HTTP workers.
I could not find it with the usual search, and it is not here as well:
SWI-Prolog -- http_daemon/0
but using Google I finally found it :slight_smile:

What is the proper way to set this to a lower value? I tried both:

:- set_setting(http:max_workers, 10).

:- multifile http:max_workers/1.
:- dynamic   http:max_workers/1.
http:max_workers(10).

but with htop I still see more workers being created under load, and the exceptions keep being raised. What am I missing?

Kind regards,
Wolfram.

6

That is not relevant. What you are seeing are traps that trigger the autoloader. If you define it, make sure it fails, so the system default does its work.

That is ok when loaded after loading http_dyn_workers.pl. You can also use

:- set_setting_default(http:max_workers, 10).

Which you can load before loading the code. In any case, use setting/2 to verify the effective value.

I think you should still load http_errors.pl into the server. That causes the server to include the stack trace in the 503 message. Now, this is by default just mapped to an existence_error (should be a resource_error). If you use the status_code(Code) option of http_open/3 on the client side, it will report 503 and you can read the document the normal way. The content is JSON if the request asks for application/json or HTML if text/html or nothing is specified.

Note there is also a notion of worker pools for the HTTP server. You can assign a handler to a pool and next define the pool properties, such as its maximum number of threads and max stack size. Finally, you can specify what to do if the pool is full: reply with 503 or wait.

7

Hi Jan,

If you use the status_code(Code) option of [http_open/3](plweb
doc_for?object=http_open/3 “Open the data at the HTTP server as a Prolog stream.”) on the client side, it will report 503 and you can read the document the normal way.

This brought the issue into light now. Seems I do not handle a call_with_inference_limit properly at some place in my code:

In:<br>
    [41] system:'$inference_limit'(1000000, _686)<br>
    [40] '$syspreds':call_with_inference_limit(&lt;compound (:)/2&gt;, 1000000, _714)<br>
    [39] gramatiko:analyze_pt([length:9], _746, _748, _750)<br>
    [38] system:'&lt;meta-call&gt;'(&lt;compound (:)/2&gt;)<br>
    [37] solution_sequences:distinct_gen(&lt;trie&gt;(0x5622bd0f5810), &lt;compound (:)/2&gt;, &lt;compound v/3&gt;)<br>

Thank you for your support. I think I now got a better understanding of the http worker handling as well.

Kind regards,
Wolfram.