Intermittent operation: MySQL server has gone away, HTTP 500 and HTTP 502 errors with API calls

[Linkandzelda]

How Shlink is set-up

• Shlink Version: Docker latest
• How do you serve Shlink: Docker latest
• Database engine used: MariaDB docker latest

Current behavior

I have deployed shlink however I get extremely unstable results. Using the shlink-web-client docker image I get random 500 and 502 errors with all pages with random AJAX calls failing per pageload.

Expected behavior

No errors and smooth operation.

How to reproduce

Just a standard test deployment on docker, no redis.

[acelaya]

Can you try with docker stable tag and see if the same behavior happens? Trying with the roadrunner counterpart would also be interesting, as it should be transparent but it uses a different runtime internally.

Could you also check the logs (the container's output), and share some of the errors you mention?

Could you also check what is the response reaching the browser when those 500 and 502 errors happen and share some examples?

[Linkandzelda]

At first I did try with stable which had the same issues. I upgraded to latest and erased everything to see if that solved it but it didn't.

This is the access log of my reverse proxy when accessing the overview page of shlink-web-client, which then calls the urls on the shlink server instance. This is downstream status code + URL path:

  |   | 2022-11-12 12:27:58 | 200 /rest/health
  |   | 2022-11-12 12:27:51 | 200 /
  |   | 2022-11-12 12:27:18 | 200 /icons/icon-32x32.png
  |   | 2022-11-12 12:27:18 | 200 /favicon.ico
  |   | 2022-11-12 12:27:17 | 200 /icons/icon-144x144.png
  |   | 2022-11-12 12:27:17 | 200 /favicon.png
  |   | 2022-11-12 12:27:15 | 200 /static/js/main.33c1d7b6.js.map
  |   | 2022-11-12 12:27:13 | 502 /rest/v3/tags?withStats=true
  |   | 2022-11-12 12:27:13 | 502 /rest/v3/visits
  |   | 2022-11-12 12:27:13 | 502 /rest/v3/short-urls?itemsPerPage=5&orderBy=dateCreated-DESC
  |   | 2022-11-12 12:27:13 | 200 /rest/v3/tags?withStats=true

But, in the shlink logs there's nothing being reported for these 502 responses. Instead there's the rest health checks which go through perfectly ok:

2022-11-12 12:27:13 | [2022-11-12T18:27:13.351923+00:00] [c4bcb5db-f81b-4fc1-88e6-75d67e30c930] Access.INFO - - "GET /rest/v3/tags?withStats=true HTTP/1.1" 200 196
2022-11-12 12:27:13 | [2022-11-12T18:27:12.915546+00:00] [b27491f3-192f-43b1-968c-ad33c235009c] Access.INFO - - "GET /rest/v3/health HTTP/1.1" 200 121

The browser response for the 502 error's are the content Bad Gateway. I am still debugging the environment to identify the issue in more depth though I'm starting to think it's the proxy causing the issues.

[Linkandzelda]

It is worth noting that when I load in the browser directly the URL path /rest/v3/visits the browser reports invalid response, and in the shlink logs it shows 401 since no API key was given.

[Linkandzelda]

I made some configuration changes, now I'm back to these 500 errors:

{"title":"Internal Server Error","type":"https://shlink.io/api/error/internal-server-error","status":500,"detail":"An unknown error occurred."}

And on the shlink log side:
Next Doctrine\DBAL\Exception\ConnectionLost: An exception occurred while executing a query: SQLSTATE[HY000]: General error: 2006 MySQL server has gone away in /etc/shlink/vendor/doctrine/dbal/src/Driver/API/MySQL/ExceptionConverter.php:104

The next reload it worked, then the reload after that it didn't, etc etc.

[acelaya]

The first set of 502 errors was definitely a misconfiguration on the reverse proxy.

These new errors seem to be a misconfiguration on the database connection. How do you provide the database config env vars? (You can redact the credentials)

[Linkandzelda]

With the 502 errors it seems that it was caused by IS_HTTPS_ENABLED set to no which I did while trying to debug the 500 errors and "gone away" errors, just to see. Setting IS_HTTPS_ENABLED to yes resolved the 502 errors.

I supply the DB config as DB_HOST=IP and DB_PORT=PORT as environment config, pointing directly to a mariadb container with default config.

My suspicion without checking this at all is that the workers connections to the mysql DB are idling too long, especially since this is a test deployment it gets no activity. So when I leave it for a while and then load something up the errors show up and it's 500s until all workers have cycled and made new DB connections.

Interestingly, when I setup a simple bash loop to load one of my short URLs without any pause and then while that runs I check pages around shlink-web-client, there are no 500 errors reported. When I stop the script and wait some minutes, the issue shows up again in the web dashboard and the 500 errors are back. Since it's intermittent like almost 50/50 or even 30/70 that it works, it would indicate that each reload hits a different worker. And, if the workers didn't have a consistent connection across all of them then the error would be shown like this.

I have not looked deeper into how possible this is, but the behaviour seems to back up the theory at least.

[acelaya]

That kind of error could mean that the connection was lost, yes.

However, Shlink makes sure the connection gets closed at the end of the request, and a new one is open at the beginning of any subsequent request.

The only edge case that comes to my mind is that the database is closing connections very fast, so they get open at the beginning of the request, and they are already closed by the time they need to be used.

[tecnicosaime]

I've the same intermittent error 502...
Tested with Mysql and MariaDb container... Same intermittent error with shlink-web-client (sometimes 0 stats, sometimes "no url")...

[acelaya]

For anyone ending-up here, try using the roadrunner variation of Shlink docker image, as it seems to not be affected by this issue.

It's a drop-in replacement. Just append -roadrunner to the version tag. For example: shlinkio/shlink:3.5.3-roadrunner.

See #1669 (comment) for details.