Problem with POP3 PollMailbox Job


(Miroslav Schlossberg) #1

Hi there,

I’m having problems on v1.3.0.beta2 +50 with Sidekiq Jobs::PollMailbox (aka “pop3 polling service”) - it is failing.

Pop3 in use is Gmail pop.gmail.com, port 995, using ssl, pop3 polling period is 10 mins (to prevent Google from blocking).

In the logs I can see Job exception: execution expired error with details as follows

Info tab:

Job exception: execution expired

Backtrace tab:

/usr/local/lib/ruby/2.0.0/net/pop.rb:544:in `initialize'
/usr/local/lib/ruby/2.0.0/net/pop.rb:544:in `open'
/usr/local/lib/ruby/2.0.0/net/pop.rb:544:in `block in do_start'
/usr/local/lib/ruby/2.0.0/net/pop.rb:543:in `do_start'
/usr/local/lib/ruby/2.0.0/net/pop.rb:530:in `start'
/var/www/discourse/app/jobs/scheduled/poll_mailbox.rb:85:in `poll_pop3'
/var/www/discourse/app/jobs/scheduled/poll_mailbox.rb:18:in `execute'
/var/www/discourse/app/jobs/base.rb:153:in `block (2 levels) in perform'

Env tab:

current_db: default
current_hostname: diskurs.open.hr
job: Jobs::PollMailbox
problem_db: default

opts:

Also tried if DigitalOcean is blocking my ports, but seems good:

Discourse:~$ telnet
telnet> open pop.gmail.com 995
Trying 74.125.136.108...
Connected to gmail-pop.l.google.com.
Escape character is '^]'.
Connection closed by foreign host.

Discourse:~$ openssl s_client -connect pop.gmail.com:995 -quiet
depth=2 C = US, O = GeoTrust Inc., CN = GeoTrust Global CA
verify error:num=20:unable to get local issuer certificate
verify return:0
+OK Gpop ready for requests from 188.226.244.180 a47mb54456318wen
user [redacted]
+OK send PASS
pass [redacted]
+OK Welcome.

Any ideas what might be wrong?


(Matthieu) #2

Same problem here, I have hundreds of `Job exception: execution expired’ errors in the logs.

Backtrace:

/usr/local/lib/ruby/2.0.0/net/pop.rb:544:in `initialize'
/usr/local/lib/ruby/2.0.0/net/pop.rb:544:in `open'
/usr/local/lib/ruby/2.0.0/net/pop.rb:544:in `block in do_start'
/usr/local/lib/ruby/2.0.0/net/pop.rb:543:in `do_start'
/usr/local/lib/ruby/2.0.0/net/pop.rb:530:in `start'
/var/www/discourse/app/jobs/scheduled/poll_mailbox.rb:85:in `poll_pop3'
/var/www/discourse/app/jobs/scheduled/poll_mailbox.rb:18:in `execute'
/var/www/discourse/app/jobs/base.rb:153:in `block (2 levels) in perform'

Env:

current_db: default
current_hostname: forum.poppy-project.org
job: Jobs::PollMailbox
problem_db: default

opts:

What is causing such error ? My discourse instance, the hosting server or the reptilian ?


(Jeff Atwood) #3

Can you log in to that Gmail account from a web browser?


(Miroslav Schlossberg) #4

Hi,
Yes I can login to Gmail account. I use Gmail only for polling, but problem occurs also on outgoing emails - I’m using mailgun.org.

Seems that something is happening with docker container. Because:

  • restarting discourse only is not solving problems
  • restaring docker, then starting discourse again is solving problems.

After restarting docker, discourse will work as expected for next aprox 2 days, after that these problems start to happen:

  • cant sent outgoing emails (digest, forgot password, event when I execute test email form admin web)
  • cant check for new version
  • cant poll for pop3 (gmail in my case)

See Sidekiq screenshots here:
https://qsnapnet.com/folders/imyknr81lrbmlso

In my 1st post I posted GMail logs (cant poll for pop3).

Below are logs for outgoing emails (can’t send emails):

  • backtrace
/var/www/discourse/app/jobs/base.rb:178:in `perform'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:75:in `execute_job'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:52:in `block (2 levels) in process'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `block in invoke'
/var/www/discourse/lib/sidekiq/pausable.rb:81:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/active_record.rb:6:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/retry_jobs.rb:74:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/logging.rb:24:in `with_context'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:7:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `invoke'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:51:in `block in process'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:98:in `stats'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:50:in `process'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
  • env
retry: true
queue: default
class: Jobs::UserEmail
jid: 54cd689e8586a0d84253b44d
enqueued_at: 1427473807.8786452
error_message: Wrapped Net::OpenTimeout: execution expired
error_class: Jobs::HandledExceptionWrapper
failed_at: 1427473848.151619
retry_count: 9
retried_at: 1427483788.9945796
args:
  0: [object Object]

(Jeff Atwood) #5

Sounds like something, after 2 days, is interfering with your internet traffic. Very strange. Did you follow the official install guide? Did you add any ‘extra’ steps on your install, or do anything custom?

Would anything upstream of you be throttling you?

Are you on the latest Docker version (I think 1.5)?


(Miroslav Schlossberg) #6

docker -v

Docker version 1.5.0, build a8a31ef

Yup, it might be throttling problem from CSF. I’ve disabled it now and will see how it behaves. Any recommendations for security/firewall alternatives? CSF seems cool, but it might be origin of my problems. Yet then, why it starts blocking after 2 days (not immediatley).


(Miroslav Schlossberg) #7

Yes, it’s confirmed. This was problem with Config Server Firewall (CSF) on Ubuntu. I’ve uninstalled it and I dont have anymore problems with failed scheduled jobs or outgoing emails. Seems CSF was killing processes that were executing too long.


(Matthieu) #8

Where is the official guide ?

I have the same error, I would like to be sure I do everything right before spamming this thread :slight_smile:


(Miroslav Schlossberg) #9

Not sure abt guide, but I solved problem by uninstalling csf.


(Miroslav Schlossberg) #10

@Matthieu try with Configure a firewall for Discourse


(Régis Hanol) #11