Multiple “Server unhealthy” and restarts, then failure

1

I have been trying to migrate a service from Heroku for a few days now. It deploys successfully and works for a few minutes (answering Render’s health checks and answering my test requests from my local browser) but then stops and restarts. Considering my application log, everything seems fine until it stops, at which point it just says “(Shutdown thread) diet stopped in 0.734s” (it’s a Java app built on Quarkus and Quarkus is sending this log). As a result, I have no clue what makes it stop. I suppose that Render makes it stop, as the same app does not stop when running on Heroku or locally (I know that this observation is of limited help but I suppose it can be useful to know anyway).

Eventually the application stops restarting, stops answering HTTP requests, and Render marks it as failed. (Other things sometimes happen such as the app not being restarted and not working any more but being shown as Live by Render, or being restarted but Render not showing the logs any more…)

The Render event logs sometimes (but not always) shows: “Server unhealthy — Exited with status 1 while running your code”. For example I have 11 such events showing up today between 1:47 PM and 3:30 PM, at irregular frequency. I have received a single email from Render today at 1:47 PM Paris time saying that my web service had failed.

My most important question is the following. If Render is making my app restart, or killing my app (for example because of an out of memory issue), will it tell me that it chose to do so? How? Knowing this would help me exclude some possible causes for this problem.

Also: can I disable auto-restart? I understand that this may be useful when availability is most important, but currently (in the testing phase) I want to know whether my service stopped and being able to investigate it by having logs which stop when the service stopped, not having the problem buried in the middle of an apparently working flow of logs.

More generally: how can I investigate this further?

2

Hi Olivier,

Thanks for reaching out.

The logs will usually be the best place to start, look back through the logs to correlate with times of the “Server Unhealthy” events, often there will be something to show what’s happening at those points.

When an app is deployed, it is expected to keep running, so if it exits/crashes the platform will try to restart it. This behavior cannot be disabled, but you can “suspend” the service from the Settings section if you want to turn off the service while investigating.

If you could share some specific examples of the issue you are experiencing that may help us troubleshoot it with you, e.g. any logs/errors/output, specific URLs, service name/ID, reproduction steps, etc. If you don’t want to share these details on the community forum, please feel free to raise a ticket with support@render.com

Alan

3

Thanks for the answer. That’s the point: my app shows no sign of problem, no log of anything, when the Server Unhealty events happen.

I can share details, no secret here. The app id is diet-server.

If Render is making my app restart, or killing my app (for example because of an out of memory issue), will it tell me that it chose to do so? How?

4

Thanks for the service name. Looking at the logs they’re consistently showing an error on each boot:

Nov 12 02:30:03 PM 2022-11-12 14:30:03,002 ERROR [org.hib.eng.jdb.spi.SqlExceptionHelper] (main) ERROR: invalid name syntaxNov 12 02:30:03 PM Position: 16Nov 12 02:30:04 PM 2022-11-12 14:30:04,416 ERROR [io.qua.run.Application] (main) Failed to start application (with profile prod): org.postgresql.util.PSQLException: ERROR: invalid name syntaxNov 12 02:30:04 PM Position: 16

As I mentioned before, the platform will attempt to restart a Web Service when it crashes, this behavior cannot be disabled. If you’re having crash issues, you can suspend the app on the settings page until you’re ready to retry deploying.

Alan

5

This log event is a consequence of the problem, not a cause. Indeed when my app is shut down and immediately restarts, it sometimes encounters a problem connecting to the DB (I suspect that some previous connection is not properly closed in such a scenario). This is a problem that I can’t reproduce locally and can’t investigate currently, but anyway, not the problem I am referring to. I would rather like to understand why the application shuts down in the first place.

(Note that the fact that you thought that this log was causing the shutdown in the first place and didn’t see that the shut down happened before — and that that log entry follows it — illustrates the related problem that I was referring to, namely, that because of these automated restarts, the root problem gets buried in a pile of mess and becomes harder to investigate. But anyway, that’s not the main issue.)

Sorry for the lack of clarity of my question that I paste again here.

I understand that the automated restart behavior can’t be disabled, but I rather meant to ask whether Render will let me know when it kills my application, for example, in case Render decides to kill it because of it consumes too much memory, or because the server on which the app runs gets rebooted. In other words, I’d like to know if my app stops because Render makes it stop (and, if so, why did Render stop it) or if my app stops for some unknown cause related to the app itself.

To illustrate, you can have a look at the logs now. I triggered a new manual deploy at end of day yesterday. Here are the Render logs.

Deploy started 11:06 PM
Deploy live 11:11 PM
Server unhealthy 11:26 PM

Now if you look at the app logs, you will observe that it works flawlessly for 14 minutes, answering Render’s health check every few seconds (I put a related log at WARN level for easier spotting), and then it suddenly stops. Here are the last two log entries before it restarts.

Nov 16 11:25:24 PM 2022-11-16 22:25:24,535 WARN [io.git.oli.die.res.TestResource] (executor-thread-0) Time for one simple query: 12 ms.
Nov 16 11:25:55 PM 2022-11-16 22:25:55,278 INFO [io.quarkus] (Shutdown thread) diet stopped in 0.712s

The question is: what makes the app stop at 11:25:55 PM? I have a very strong suspicion that Render makes it stop, as the app has no reason to suddenly stop long after it has successfully started, and there is absolutely no “anticipated shut down” logic in my code, and it doesn’t do that locally or on Heroku. In any case, I am stuck as to how to investigate further. Any help would be appreciated.

6

Your service is on the free plan, which will be spun down after 15 minutes of no requests (our health checks don’t count). From the timings you shared, that sounds like the behavior you’re seeing. When a free service is spun down a SIGTERM signal is sent to the app. There is a grace period of 30 seconds to shut everything down. If your app is still up after 30 seconds, it is shut down via a SIGKILL signal. Maybe your service isn’t shutting down gracefully in 30 seconds and/or exiting with a status of 1, like the events show?

Alan

7

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.