Ghost icon indicating copy to clipboard operation
Ghost copied to clipboard

Ghost process die once a few days at midnight

Open HaziFlorinMarian opened this issue 3 years ago • 2 comments

Issue Summary

Hello!

We have been using Ghost for several months and it has happened to us several times (in random periods as can be seen in the screenshot below), that we do wake up in the morning with the blog inaccessible until the process is restarted.

Screenshot from 2022-07-22 09-54-00

Steps to Reproduce

None - it just happen.

Ghost Version

Ghost version: 5.2.3 (at /var/www/blog)

Node.js Version

v14.17.4

How did you install Ghost?

with command ghost install

Database type

MySQL 8

Browser & OS version

not relevant

Relevant log / error output

Jul 22 00:00:03 ghost-blog node[2301112]:       throw er; // Unhandled 'error' event
Jul 22 00:00:03 ghost-blog node[2301112]: Emitted 'error' event on RotatingFileStream instance at:
Jul 22 00:00:05 ghost-blog node[2301228]:       throw er; // Unhandled 'error' event
Jul 22 00:00:05 ghost-blog node[2301228]: Emitted 'error' event on RotatingFileStream instance at:
Jul 22 00:00:06 ghost-blog node[2301268]:       throw er; // Unhandled 'error' event
Jul 22 00:00:06 ghost-blog node[2301268]: Emitted 'error' event on RotatingFileStream instance at:
Jul 22 00:00:08 ghost-blog node[2301308]:       throw er; // Unhandled 'error' event
Jul 22 00:00:08 ghost-blog node[2301308]: Emitted 'error' event on RotatingFileStream instance at:
Jul 22 00:00:10 ghost-blog node[2301348]:       throw er; // Unhandled 'error' event
Jul 22 00:00:10 ghost-blog node[2301348]: Emitted 'error' event on RotatingFileStream instance at:
Jul 22 00:00:12 ghost-blog node[2301391]:       throw er; // Unhandled 'error' event
Jul 22 00:00:12 ghost-blog node[2301391]: Emitted 'error' event on RotatingFileStream instance at:
Jul 22 00:00:13 ghost-blog node[2301432]:       throw er; // Unhandled 'error' event
Jul 22 00:00:13 ghost-blog node[2301432]: Emitted 'error' event on RotatingFileStream instance at:
Jul 22 00:00:15 ghost-blog node[2301476]:       throw er; // Unhandled 'error' event
Jul 22 00:00:15 ghost-blog node[2301476]: Emitted 'error' event on RotatingFileStream instance at:
Jul 22 00:00:17 ghost-blog node[2301523]:       throw er; // Unhandled 'error' event
Jul 22 00:00:17 ghost-blog node[2301523]: Error: ENOENT: no such file or directory, rename '/var/www/blog/content/logs/https___blog_hidden-domain_com_production.error.log.8' -> '/var/www/blog/content/logs/https___blog_hidden-domain_com_production.error.log.9'
Jul 22 00:00:17 ghost-blog node[2301523]: Emitted 'error' event on RotatingFileStream instance at:
Jul 22 00:00:17 ghost-blog node[2301523]:   path: '/var/www/blog/content/logs/https___blog_hidden-domain_com_production.error.log.8',
Jul 22 00:00:17 ghost-blog node[2301523]:   dest: '/var/www/blog/content/logs/https___blog_hidden-domain_com_production.error.log.9'
Jul 22 00:00:19 ghost-blog node[2301567]:       throw er; // Unhandled 'error' event
Jul 22 00:00:19 ghost-blog node[2301567]: Error: ENOENT: no such file or directory, rename '/var/www/blog/content/logs/https___blog_hidden-domain_com_production.error.log' -> '/var/www/blog/content/logs/https___blog_hidden-domain_com_production.error.log.0'
Jul 22 00:00:19 ghost-blog node[2301567]: Emitted 'error' event on RotatingFileStream instance at:
Jul 22 00:00:19 ghost-blog node[2301567]:   path: '/var/www/blog/content/logs/https___blog_hidden-domain_com_production.error.log',
Jul 22 00:00:19 ghost-blog node[2301567]:   dest: '/var/www/blog/content/logs/https___blog_hidden-domain_com_production.error.log.0'

Other relevant information: In the folder /var/www/blog/content there were only these files on the night when the ghost process tried to move log number 8, as can be seen in the logs:

root@ghost-blog:/var/www/blog# ll /var/www/blog/content/logs/
total 18028
drwxrwxr-x  2 ghost ghost     4096 Jul 22 00:00 ./
drwxrwxr-x 10 ghost ghost     4096 Jun 28 07:25 ../
-rw-rw-r--  1 ghost ghost   118014 Aug 20  2021 http___blog_hidden-domain_com_production.error.log
-rw-rw-r--  1 ghost ghost 16652604 Aug 20  2021 http___blog_hidden-domain_com_production.log
-rw-r--r--  1 ghost ghost     4010 Jul 22 06:53 https___blog_hidden-domain_com_production.error.log
-rw-r--r--  1 ghost ghost    80183 Jul 21 23:47 https___blog_hidden-domain_com_production.error.log.0
-rw-r--r--  1 ghost ghost    63574 Jul 22 07:01 https___blog_hidden-domain_com_production.log
-rw-r--r--  1 ghost ghost  1507225 Jul 21 23:59 https___blog_hidden-domain_com_production.log.0

Code of Conduct

  • [X] I agree to be friendly and polite to people in this repository

HaziFlorinMarian avatar Jul 22 '22 07:07 HaziFlorinMarian

Do you have multiple Ghost instances running on the same server, or anything other than Ghost working with the log files? I've seen issues like this but only in those two cases.

You've had this happen multiple times as well, is it always failing with the same error?

ErisDS avatar Jul 26 '22 14:07 ErisDS

Note from our bot: The needs info label has been added to this issue. Updating your original issue with more details is great, but won't notify us, so please make sure you leave a comment so that we can see when you've updated us.

github-actions[bot] avatar Jul 26 '22 14:07 github-actions[bot]

Hi, I'm Florin's colleague.

We have only one ghost instance running on the server. We do have promtail on that server that collects logs and sends them to a grafana server, but it is not set to grab the logs from ghost /var/www/blog/content/logs/, only from /var/log/.

And yes, the ghost service has broke multiple times because of this error, including last night. Always with the same error, one for each log file from .0 to .9 and then ending with:

Aug 16 00:05:10 ghost-blog systemd[1]: ghost_blog-hidden-domain_com.service: Succeeded. Aug 16 00:05:10 ghost-blog systemd[1]: ghost_blog-hidden-domain_com.service: Scheduled restart job, restart counter is at 5. Aug 16 00:05:10 ghost-blog systemd[1]: Stopped Ghost systemd service for blog: blog-hidden-domain_com. Aug 16 00:05:11 ghost-blog systemd[1]: ghost_blog-hidden-domain_com.service: Start request repeated too quickly. Aug 16 00:05:11 ghost-blog systemd[1]: ghost_blog-hidden-domain_com.service: Failed with result 'start-limit-hit'. Aug 16 00:05:11 ghost-blog systemd[1]: Failed to start Ghost systemd service for blog: blog-hidden-domain_com.

Emi94 avatar Aug 16 '22 06:08 Emi94

Sorry for taking a while to come back here, perhaps by now you've figured something out?

Ghost's built-in log rotation is clearly not working for you, and I've not seen this in the 8-ish years we've had the same tool (bunyan) power rotation.

I don't see anything that looks like a permission issues although that's the most likely cause. Can't speak to anything OS related as that's not been shared.

The best suggestion I have at this point is to disable Ghost's log rotation and use logrotate or whatever is available on your OS. Docs for log rotation config are here.

This could well be related to an upstream bug but I don't se anything in the issues or the info available here to tie them together, given that it must be an extremely rare/specific issue.

For now I'm going to close this as a self-hosting issue, as I can't see anything that points to a reproducible bug in Ghost itself.

ErisDS avatar Aug 24 '22 17:08 ErisDS

Hey @HaziFlorinMarian 👋

We've reviewed your bug report and believe the issue is environment specific, rather than a bug. Many questions can be answered by reviewing our documentation. If you can't find an answer then our forum is a great place to get community support, plus it helps create a central location for searching problems/solutions.

github-actions[bot] avatar Aug 24 '22 17:08 github-actions[bot]