I set a post to be scheduled today at 13:00 UTC. But the time came and went and the post wasn’t published. Not a big deal but I really like the scheduled post feature so would like to figure out what’s wrong with my setup.
What errors or information do you see in the console?
Possibly the following is relevant, it happened at the time the publish should’ve happened:
[2018-05-06 13:02:07] ERROR
NAME: InternalServerError
CODE: ETIMEDOUT
MESSAGE: The server has encountered an error.
level:critical
InternalServerError: The server has encountered an error.
at new GhostError (/var/lib/ghost/versions/1.22.5/core/server/lib/common/errors.js:9:26)
at /var/lib/ghost/versions/1.22.5/core/server/adapters/scheduling/SchedulingDefault.js:239:34
at Request.callback (/var/lib/ghost/versions/1.22.5/node_modules/superagent/lib/node/index.js:728:3)
at ClientRequest.req.once.err (/var/lib/ghost/versions/1.22.5/node_modules/superagent/lib/node/index.js:647:10)
at ClientRequest.g (events.js:292:16)
at emitOne (events.js:96:13)
at ClientRequest.emit (events.js:188:7)
at TLSSocket.socketErrorListener (_http_client.js:314:9)
at emitOne (events.js:96:13)
at TLSSocket.emit (events.js:188:7)
at emitErrorNT (net.js:1290:8)
at _combinedTickCallback (internal/process/next_tick.js:80:11)
at process._tickCallback (internal/process/next_tick.js:104:9)
Error: connect ETIMEDOUT 82.196.2.207:443
at Object.exports._errnoException (util.js:1020:11)
at exports._exceptionWithHostPort (util.js:1043:20)
at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1099:14)
What steps could someone else take to reproduce the issue you’re having?
Run the Ghost docker container. Schedule a post and wait for the scheduled time to be passed. In my case the post isn’t published.
In my case, the following was true:
In the admin console, “Stories” lists the story as “will be published today at 13:00”, but that time is already in the past.
The servertime was correct, as also shown in General > Site Timezone and also in the ssh session of the server (“date” shows the correct UTC time)
When I “reschedule” the post then, to a few minutes into the future, it immediatly gets published. The “Stories” then lists the post as “Published in 4 minutes”, and then later of course “Published x minutes ago”
So it looks like the publish is triggered, but an error occurs: “Error: connect ETIMEDOUT 82.196.2.207:443”. This is the correct IP address of my server. But I wonder if there’s a problem because this is happening inside a docker container?
I have a docker container for ghost and then a container for nginx. Nginx listens to the outside world on port 443 and is a reverse proxy. The connection between nginx and ghost is over HTTP (no https).
Does anyone have any pointers? Did I miss something with the setup in docker?
Note: our resident scheduling expert is on holiday for a bit, so you might get better answers in a couple of weeks.
In the meantime:
@lenoir_aaron To debug this, you’ll need to try talking to the API from inside your docker container. As @jasonbraganza’s logs show, Ghost publishes a post by making a call to its own API:
GET /ghost/api/v0.1/schedules/posts/5aefcb06eca0ca3d148873dd?client_id=ghost-scheduler&client_secret=9c7101614d10
If you can find these requests in the info log, it’s easy to copy, else you can get your post ID, and scheduler credentials from your database. If you are able to test making a call using curl inside the container, you should be able to determine if the ETIMEDOUT errors are definitely related and then start working through possible causes for why the requests are not allowed.
@jasonbraganza In your case the request to schedule the post 404s, meaning either the post wasn’t set to be scheduled anymore, or had already been scheduled. Everything otherwise looks like it’s probably working correctly. Do you have a cache in front of Ghost?
You can view your logs in full by looking in the content/logs folder inside of your Ghost folder. I recommend trying grep -r 'schedules/posts' . in that folder to find all the requests to the scheduler to see if there are more entries.
[2018-05-07 16:03:02] ERROR
NAME: InternalServerError
MESSAGE: Response code 405 (Method Not Allowed)
level: normal
The slack service was unable to send a ping request, your blog will continue to function.
If you get this error repeatedly, please seek help on http://docs.ghost.org.
InternalServerError: Response code 405 (Method Not Allowed)
at new GhostError (/var/www/mjb/versions/1.22.5/core/server/lib/common/errors.js:9:26)
at /var/www/mjb/versions/1.22.5/core/server/services/xmlrpc.js:75:38
at tryCatcher (/var/www/mjb/versions/1.22.5/node_modules/bluebird/js/release/util.js:16:23)
at Promise._settlePromiseFromHandler (/var/www/mjb/versions/1.22.5/node_modules/bluebird/js/release/promise.js:512:31)
at Promise._settlePromise (/var/www/mjb/versions/1.22.5/node_modules/bluebird/js/release/promise.js:569:18)
at Promise._settlePromise0 (/var/www/mjb/versions/1.22.5/node_modules/bluebird/js/release/promise.js:614:10)
at Promise._settlePromises (/var/www/mjb/versions/1.22.5/node_modules/bluebird/js/release/promise.js:689:18)
at Async._drainQueue (/var/www/mjb/versions/1.22.5/node_modules/bluebird/js/release/async.js:133:16)
at Async._drainQueues (/var/www/mjb/versions/1.22.5/node_modules/bluebird/js/release/async.js:143:10)
at Immediate.Async.drainQueues (/var/www/mjb/versions/1.22.5/node_modules/bluebird/js/release/async.js:17:14)
at runCallback (timers.js:672:20)
at tryOnImmediate (timers.js:645:5)
at processImmediate [as _immediateCallback] (timers.js:617:5)
tried deleting all my drafts
deleting all my scheduled posts
stopping my ghost instance
ghost doctor
ghost buster
starting it up again and trying with a brand new test post.
still doesn’t post.
similar error as before
[2018-05-07 16:19:59] INFO “GET /ghost/api/v0.1/schedules/posts/5af02e4e9d148d46881a71a6?client_id=ghost-scheduler&client_secret=9c7101614d10” 404 5ms
[2018-05-07 16:19:59] INFO “GET /ghost/api/v0.1/schedules/posts/5af02e4e9d148d46881a71a6?client_id=ghost-scheduler&client_secret=9c7101614d10” 404 5ms
have attached an image of the main screen after the post time has passed
will await further instructions.
I tried to look for any requests to the ghost api schedules/posts, but couldn’t find anything. I did figure out the secret (I think). I managed to run that URL from inside the docker container.
It works when I use localhost:2368 (the port Ghost is running on). But it doesn’t work when I use https://:443.
I don’t exactly know why there is a timeout though: I would think this would go to my docker container, come in via the nginx container and then go to the ghost container. But instead it just times out. I can ping the server from inside the docker container with the public IP address.
But why wouldn’t Ghost call it’s own API via the localhost? Is this something I can influence through configuration?
When I have some time, I may have a look in the code and try and understand what is happening. But maybe you know more, more quickly
Hello, I’ve been looking into this. And thought I’d post an update, never know who else has this issue.
I’m running on a Digital Ocean “droplet” (virtual private server) that has iptables preconfigured (using ufw).
I was able to connect to port 443 from inside my ghost container if I use the internal IP address of my server, but not if I use the public IP address. However, I was able to connect to SSH from inside the ghost container using the public IP.
Turns out, for https it was blocking incoming connections unless the destination was the internal IP address of my host. I could see this block happening in real-time by looking at the syslog while trying to connect: sudo tail -f /var/log/syslog
So I added a rule to the firewall: “if connections are coming from the local docker ip range, and going to my public ip address, plelase allow https anyway.” (ufw allow from 172.18.0.0/24 to 82.196.2.207 port 443)
I am now able to connect, using telnet, to my 443 port, using the public IP address.
Now the question is if this solves my scheduling problem! I’m betting it’ll solve the timeout error I saw ealier.
Hello, looks like the above solved my issue. My post gets published automatically.
I do still get the below error in the ghost log, but it doesn’t seem to hold back the publish.
But my solution: When running ghost in a container, make sure Ghost is able to connect to port 443 (https) on the public IP address of the host. On a Digital Ocean docker droplet, this is not allowed by the firewall (ufw). You can allow this:
ufw allow from 172.18.0.0/24 to <public-ip-address> port 443 (not, your IP address may be different)
Possible other solutions may be (but I haven’t tried):
Make the Ghost container resolve your blog hostname to the local IP address (if that is even possible)
Set the admin.url in the configuration to something that resolves to the internal IP address
But both seem more difficult.
Here’s the other error I see that happens exactly when the schedule post gets triggered. But the post gets published so I’m not going to worry about that one too much.
INFO [2018-05-09 23:20:00] "PUT /ghost/api/v0.1/schedules/posts/5af37fca9aa0b10001bdd492?client_id=ghost-scheduler&client_secret=..." 200 218ms
[2018-05-09 23:20:00] ERROR
NAME: InternalServerError
MESSAGE: Response code 405 (Method Not Allowed)
level:normal
The slack service was unable to send a ping request, your blog will continue to function.
If you get this error repeatedly, please seek help on http://docs.ghost.org.
InternalServerError: Response code 405 (Method Not Allowed)
at new GhostError (/var/lib/ghost/versions/1.22.6/core/server/lib/common/errors.js:9:26)
at /var/lib/ghost/versions/1.22.6/core/server/services/xmlrpc.js:75:38
at tryCatcher (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/util.js:16:23)
at Promise._settlePromiseFromHandler (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/promise.js:512:31)
at Promise._settlePromise (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/promise.js:569:18)
at Promise._settlePromise0 (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/promise.js:614:10)
at Promise._settlePromises (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/promise.js:689:18)
at Async._drainQueue (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/async.js:133:16)
at Async._drainQueues (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/async.js:143:10)
at Immediate.Async.drainQueues (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/async.js:17:14)
at runCallback (timers.js:672:20)
at tryOnImmediate (timers.js:645:5)
at processImmediate [as _immediateCallback] (timers.js:617:5)
HTTPError: Response code 405 (Method Not Allowed)
at StdError (/var/lib/ghost/versions/1.22.6/node_modules/got/index.js:410:3)
at /var/lib/ghost/versions/1.22.6/node_modules/got/index.js:454:3
at stream.catch.then.e (/var/lib/ghost/versions/1.22.6/node_modules/got/index.js:182:13)
at tryCatcher (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/util.js:16:23)
at Promise._settlePromiseFromHandler (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/promise.js:512:31)
at Promise._settlePromise (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/promise.js:569:18)
at Promise._settlePromise0 (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/promise.js:614:10)
at Promise._settlePromises (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/promise.js:693:18)
at Async._drainQueue (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/async.js:133:16)
at Async._drainQueues (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/async.js:143:10)
at Immediate.Async.drainQueues (/var/lib/ghost/versions/1.22.6/node_modules/bluebird/js/release/async.js:17:14)
at runCallback (timers.js:672:20)
at tryOnImmediate (timers.js:645:5)
at processImmediate [as _immediateCallback] (timers.js:617:5)
You will probably also see this error when you publish a post immediately rather than scheduling. The error is coming from the XML-RPC ping (the slack service mentioned is a bug in the error message ) that is made every time a post is published so that Google is immediately aware of your new post to speed up indexing.
I can’t reproduce the error locally which suggests that there maybe something else in your server setup that is preventing outgoing POST requests.
The body of the POST request contains some information about the new post in an XML format.
Both actually get an error response, but only google returns an HTTP 405. I captured this using tcpdump on my docker host.
I’m not sure how this is influenced by my environment, since I do get a response back from both servers. So I can talk to them and they can talk to me. They just don’t like what I’m saying to them. I would expect other Ghost instances to say the same thing, and I’m confused as to why it would not be giving these errors for other people.
If you need the pcap file, I can provide this to you.
Here’s the jist of the google conversation:
POST /ping/RPC2 HTTP/1.1^M
user-agent: got/7.1.0 (https://github.com/sindresorhus/got)^M
accept-encoding: gzip,deflate^M
content-length: 275^M
Host: blogsearch.google.com^M
Connection: close^M
^M
<?xml version="1.0" encoding="UTF-8"?><methodCall> <methodName>weblogUpdate.ping</methodName><params><param><value><string>Test Post</string></value></param><param><value><string>https://blog.aaronlenoir.com/2018/05/11/test-post/</string></value></param></params></methodCall>
...
HTTP/1.1 405 Method Not Allowed
Allow: GET, HEAD
Date: Fri, 11 May 2018 21:37:37 GMT
Content-Type: text/html; charset=UTF-8
Server: gws
Content-Length: 1598
X-XSS-Protection: 1; mode=block
X-Frame-Options: SAMEORIGIN
Connection: close
...
<p>The request method <code>POST</code> is inappropriate for the URL <code>/ping/RPC2</code>.
And the conversation with pingomatic:
POST / HTTP/1.1
user-agent: got/7.1.0 (https://github.com/sindresorhus/got)
accept-encoding: gzip,deflate
content-length: 275
Host: rpc.pingomatic.com
Connection: close
<?xml version="1.0" encoding="UTF-8"?><methodCall><methodName>weblogUpdate.ping</methodName><params><param><value><string>Test Post</string></value></param><param><value><string>https://blog.aaronlenoir.com/2018/05/11/test-post/</string></value></param></params></methodCall>
...
HTTP/1.1 200 OK
Server: nginx
Date: Fri, 11 May 2018 21:37:37 GMT
Content-Type: text/xml;charset=utf-8
Content-Length: 423
Connection: close
...
<value><string>server error. requested method weblogUpdate.ping does not exist.</string></value>
Ok @jasonbraganza let us know what you find. I’m not sure if we had the same problem since you didn’t see that connection timeout. But do check the connectivity over port 443 (if you run https) between your Ghost instance and the public IP address of your host.
Maybe you could try a wget to the public URL of your blog from the server (or docker container?) that is running Ghost and see if you can connect. Good luck!
@jasonbraganza I think the xmlrpc ping errors are red herrings. Yes they are failing, but they should not impact on the ability to schedule a post in any way. They have stopped working, but scheduling has not stopped working across the board.
The important thing for scheduling is that Ghost must be able to ping itself. To debug it you need to look specifically for the logs relating to scheduling, where Ghost makes requests to /ghost/api/v0.1/schedules/posts.
It could be that your reverse proxy doesn’t allow https requests, or something like that.
@John have raised an issue to remove the xmlrpc ping service:
Updated to 1.2.3 and tried again. have attached a pic of my log
relevant lines are at 12.44 and 12.49
me posting to publish for 5m later [2018-05-23 12:44:33] INFO "PUT /ghost/api/v0.1/posts/5a0fc6070223bc3593b44293/?include=authors,tags,authors.roles" 200 271ms [2018-05-23 12:44:33] INFO "PUT /ghost/api/v0.1/posts/5a0fc6070223bc3593b44293/?include=authors,tags,authors.roles" 200 271ms
5m later … [2018-05-23 12:49:00] INFO "GET /ghost/api/v0.1/schedules/posts/5a0fc6070223bc3593b44293?client_id=ghost-scheduler&client_secret=c7c0fd07a406" 404 5ms [2018-05-23 12:49:00] INFO "GET /ghost/api/v0.1/schedules/posts/5a0fc6070223bc3593b44293?client_id=ghost-scheduler&client_secret=c7c0fd07a406" 404 5ms
the blog runs on ssl (via certbot) so there is ssl access on port 443.
I don’t know where the issue lies.
I write and save drafts
I read the blog
everything works
except the scheduling
like I said, it’s only something I started using recently, but so if it doesn’t work, well c’est la vie
It’s definitely weird & confusing. However, the admin UI isn’t going to give us any hints here - it’s a separate system just showing the best thing it can with the data it has.
I can see 2 weird things. 1. the requests to the scheduler are 404ing, and 2. they’re all duplicated, which should not be the case.
If you look at the logs you posted above you can see absolutely every request is reported twice at the same time.
The logs for the blogs should each go to a separate file AND if you make a request to one of the blogs, it wouldn’t make the exact same request to the other blog at the same time.
It’s like you have the process running twice.
Two other points to debug:
What’s the output of ps -aux | grep ghost ?
Can you show me the contents of config.production.json, specifically the “logging” section?
) that is made every time a post is published so that Google is immediately aware of your new post to speed up indexing.
