Random Bottle terminates

[Ervin Hegedüs]

Hi,

I'm working on an application which uses Bottlepy. System is Debian 9, Python 3.5.3, Bottlepy installed from Debian repository, version is 0.12.13-1.

At this stage I just run the app in foreground mode:

bottle.debug(True)
bottle.run(host='0.0.0.0', port=8090, debug=True, reloader=True)

The problem is that the app sometimes terminates, but there isn't any exception, error, or any error sign, why does it happen.

The 8090 is allowed through a HTTP proxy (Apache), so I can see the requests at there too (and also I can see the requests in the console), and I just see the last success was request, and the next one is a server error - which means the Bottle terminated.

10.10.252.103 - - [14/Oct/2019:11:50:20 +0200] "GET /foo/LIST1.txt HTTP/1.1" 200 4589 "-" "-"
10.10.252.103 - - [14/Oct/2019:11:50:20 +0200] "GET /foo/LIST2.txt HTTP/1.1" 200 2783 "-" "-"
10.10.252.103 - - [14/Oct/2019:11:55:23 +0200] "GET /foo/LIST1.txt HTTP/1.1" 503 2563 "-" "-"

On the console, I just see this:

127.0.0.1 - - [14/Oct/2019 11:50:20] "GET /foo/LIST1.txt HTTP/1.1" 200 2393
127.0.0.1 - - [14/Oct/2019 11:50:20] "GET /foo/LIST2.txt HTTP/1.1" 200 617
/usr/lib/python3/dist-packages/bottle.py:3123: ResourceWarning: unclosed <socket.socket fd=3, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=0, laddr=('0.0.0.0', 8090)>
  server.run(app)

That's it - and that's all what I get from Bottle.

How can I catch the source of problem?

Thanks,

a.

[Marcel Hellkamp]

Hi there,

does the process actually terminate, or does it just stop accepting
requests?

The stdlib wsgi server is single-threaded and not optimized or hardened
at all. It simplifies debugging, but should NEVER be used in production.
It is easily confused by disconnecting or misbehaving clients and then
stops accepting requests until a long timeout occurs.

It could also be the reloading feature that misbehaves. Hard to tell
without any actual error. With reloading activated, run() actually
starts a second process that then accepts requests. If a module file
changes, it stops automatically with exit code 3 and is restarted by the
parent process. That is normal behavior. Try with disabled reloading.


Am 14.10.19 um 20:44 schrieb Ervin Hegedüs:

[Ervin Hegedüs]

Hi Marcel,

many thanks for your reply.

On Tue, Oct 15, 2019 at 01:04:59PM +0200, Marcel Hellkamp wrote:
> Hi there,
>
> does the process actually terminate, or does it just stop accepting
> requests?

no, the process termnated. I don't see that in the process list.

> The stdlib wsgi server is single-threaded and not optimized or hardened
> at all. It simplifies debugging, but should NEVER be used in production.

I don't want to use it in production environment, but I thought I
can use it in develop env without any problems like this.

> It is easily confused by disconnecting or misbehaving clients and then
> stops accepting requests until a long timeout occurs.

what do you mean about "long timeout"? As I atteched the logs,
the stopage occurs between two periods (there is a FW appliance
which asks the IP lists between 5 minutes; the last request group
(5 or 6 unique request) successed, but the next one got 5XX
error).

> It could also be the reloading feature that misbehaves. Hard to tell
> without any actual error.

yes, but I think the all issue is weird without any error
message.

> With reloading activated, run() actually
> starts a second process that then accepts requests. If a module file
> changes, it stops automatically with exit code 3 and is restarted by the
> parent process. That is normal behavior. Try with disabled reloading.

hmm... I agree and understand, but there isn't any changes in
files. The process terminates sometimes in middle of night...
There was a long period at summer, when it runs through 2 weeks
or more, and then it stopped at weekend night... So, I don't
belive that the reload is the reason of the problem.

What's the preferred way to run Bottle in production environment?


Thanks again,


a.

[Marcel Hellkamp]

The code for the reloading logic is not really complicated.

Here is the parent process (starting a child, and re-starting it if it
terminates with code 3):

https://github.com/bottlepy/bottle/blob/master/bottle.py#L3660

Here the child (running the actual server and also a file-checker thread
that terminates the process with code 3 on file changes):

https://github.com/bottlepy/bottle/blob/master/bottle.py#L3718


A wild guess: The parent creates a lockfile via tempfile.mkstemp(). If
that file is removed, both processes die. Are you deleting files from
/tmp/ manually, instead of just during server restarts?


Am 15.10.19 um 13:20 schrieb Ervin Hegedüs:

[Ervin Hegedüs]

Hi Marcel,

so, many thanks again for your quick help :).

On Tue, Oct 15, 2019 at 01:48:34PM +0200, Marcel Hellkamp wrote:
> The code for the reloading logic is not really complicated.
>
> Here is the parent process (starting a child, and re-starting it if it
> terminates with code 3):
>
> https://github.com/bottlepy/bottle/blob/master/bottle.py#L3660
>
> Here the child (running the actual server and also a file-checker thread
> that terminates the process with code 3 on file changes):
>
> https://github.com/bottlepy/bottle/blob/master/bottle.py#L3718

thanks,

> A wild guess: The parent creates a lockfile via tempfile.mkstemp(). If
> that file is removed, both processes die. Are you deleting files from
> /tmp/ manually, instead of just during server restarts?

hmm... it's interesting - at this time I didn't realized (and I
think there is still not important for me as an end-user), that
there is a lockfile.

Now I checked, and looks like the date and time of file is always
updated:

$ ls -la /tmp/bottle.mbfgvln8.lock
-rw------- 1 airween airween 0 Oct 15 15:11 /tmp/bottle.mbfgvln8.lock

but since I logged in to the system, it always refreshed...

Is that normally? But the Bottle still runs, and there wasn't any
reload since yesterday afternoon (14/Oct/2019 16:27:58 is the
time when the first request came).


What do you think?



Thanks,



a.

[Marcel Hellkamp]

Am 15.10.19 um 15:15 schrieb Ervin Hegedüs:

>
>> A wild guess: The parent creates a lockfile via tempfile.mkstemp(). If
>> that file is removed, both processes die. Are you deleting files from
>> /tmp/ manually, instead of just during server restarts?
> hmm... it's interesting - at this time I didn't realized (and I
> think there is still not important for me as an end-user), that
> there is a lockfile.
>
> Now I checked, and looks like the date and time of file is always
> updated:
>
> $ ls -la /tmp/bottle.mbfgvln8.lock
> -rw------- 1 airween airween 0 Oct 15 15:11 /tmp/bottle.mbfgvln8.lock
>
> but since I logged in to the system, it always refreshed...
>
> Is that normally? But the Bottle still runs, and there wasn't any
> reload since yesterday afternoon (14/Oct/2019 16:27:58 is the
> time when the first request came).

Yes that is normal. The file is used as a heartbeat and touched by the
parent process every X seconds so the child has a chance to detect if
the parent was killed.

[Ervin Hegedüs]

Hi Macel,

On Tue, Oct 15, 2019 at 03:32:50PM +0200, Marcel Hellkamp wrote:
>
> Am 15.10.19 um 15:15 schrieb Ervin Hegedüs:

> > Is that normally? But the Bottle still runs, and there wasn't any
> > reload since yesterday afternoon (14/Oct/2019 16:27:58 is the
> > time when the first request came).
>
> Yes that is normal. The file is used as a heartbeat and touched by the
> parent process every X seconds so the child has a chance to detect if
> the parent was killed.

thanks again - right, it's okay then.

But how can I catch the source of terminate event?

And what's the preferred way to run the app? Consider I'm ready,
and want to migrate it to the production environment...


Thanks,


a.

[Marcel Hellkamp]

Am 15.10.19 um 16:12 schrieb Ervin Hegedüs:

> Hi Macel,
>
> On Tue, Oct 15, 2019 at 03:32:50PM +0200, Marcel Hellkamp wrote:
>> Am 15.10.19 um 15:15 schrieb Ervin Hegedüs:
>>> Is that normally? But the Bottle still runs, and there wasn't any
>>> reload since yesterday afternoon (14/Oct/2019 16:27:58 is the
>>> time when the first request came).
>> Yes that is normal. The file is used as a heartbeat and touched by the
>> parent process every X seconds so the child has a chance to detect if
>> the parent was killed.
> thanks again - right, it's okay then.
>
> But how can I catch the source of terminate event?

As long as you cannot reproduce the error, we can only guess.

> And what's the preferred way to run the app? Consider I'm ready,
> and want to migrate it to the production environment...

There are many ways, but I'd suggest nginx with uwsgi. Bottle is a WSGI
framework, so anything hat works for django/flask/... also works for bottle.

[Glenn Linderman]

I too have experienced bottle.py sometimes simply disappearing. The above discussion is interesting, as a result of my experience, but unfortunately, not very enlightening.

I am running bottle along with the ThreadingMixIn from socketserver, which relieves me of the single-threaded limitation, and also with an SSL extension. It works well, until in vanishes. One situation in which I notice it vanishing is when I start  the bottle server, but don't send any requests for a while. And if I do, then sometimes if I leave it idle for a long time, it will vanish.

I find the comment about a long timeout interesting, and wonder if the long timeout is when waiting for a request? And if it doesn't get one, then it vanishes?  Where is the long timeout implemented, and how long is it?

I'm well aware that during development when I change source code and introduce a syntax error, that bottle vanishes... but that produces visible error messages.