huginn background job stuck in running status no events output

I am having a similar issue to https://github.com/cantino/huginn/issues/864, except the job starts to run, and then gets stuck.
The system runs fine for a few weeks, and then will get stuck running a background job, which then causes a backlog in the queue. The only thing that fixes it is a restart of the application.
I am running a Ubuntu Rackspace Cloud server on the default settings (as per the user guide), and resource usage looks fine (8vCPU and 8GB RAM (maximum usage is 5GB).
What information do you need to help debug?

Hi @hughwi,
can you look through the logs of the background processors and see if there are any exceptions?

OK, This is what I get:
-rw-r--r-- 1 huginn huginn 563733 Jun  7 16:42 /home/huginn/huginn/log/dj2-1/current
-rw-r--r-- 1 huginn huginn 843095 Jun  7 18:29 /home/huginn/huginn/log/dj3-1/current
-rw-r--r-- 1 huginn huginn 495251 Jun  7 16:41 /home/huginn/huginn/log/dj4-1/current
-rw-r--r-- 1 huginn huginn 399437 Jun  7 16:45 /home/huginn/huginn/log/dj5-1/current
-rw-r--r-- 1 huginn huginn 311647 Jun 29 08:21 /home/huginn/huginn/log/jobs-1/current
-rw-r--r-- 1 huginn huginn      0 Jun  1 14:50 /home/huginn/huginn/log/web-1/current
There are a bunch of timeout errors, and 404s which are expected, then there are these:
Agent#43: Failed to fetch http://www.royalhaskoning.co.uk/en-GB/_layouts/rhkcorporate/rssfeed.ashx?scope=Current&language=English&type=News: #<Faraday::Response:0x007f8a99937878 @on_complete_callbacks=[], @env=#<Faraday::Env @method=:get @body="" @url=#<URI::HTTPS https://www.royalhaskoning.co.uk/en-GB/_layouts/rhkcorporate/rssfeed.ashx?language=English&scope=Current&type=News> @request=#<Faraday::RequestOptions (empty)> @request_headers={"User-Agent"=>"Huginn - https://github.com/cantino/huginn", "Accept-Encoding"=>"gzip,deflate"} @ssl=#<Faraday::SSLOptions verify=true> @response_headers={} @status=0>>
Agent#43: Failed to fetch http://www.khi.co.jp/english/news_atom/news.xml with message 'no implicit conversion of nil into String': ["/home/huginn/huginn/app/models/agents/rss_agent.rb:128:in digest'", "/home/huginn/huginn/app/models/agents/rss_agent.rb:128:in hexdigest'", "/home/huginn/huginn/app/models/agents/rss_agent.rb:128:in get_entry_id'", "/home/huginn/huginn/app/models/agents/rss_agent.rb:145:in block in feed_to_events'", "/home/huginn/huginn/app/models/agents/rss_agent.rb:143:in map'", "/home/huginn/huginn/app/models/agents/rss_agent.rb:143:in feed_to_events'", "/home/huginn/huginn/app/models/agents/rss_agent.rb:105:in block in check_urls'", "/home/huginn/huginn/app/models/agents/rss_agent.rb:99:in each'", "/home/huginn/huginn/app/models/agents/rss_agent.rb:99:in check_urls'", "/home/huginn/huginn/app/models/agents/rss_agent.rb:90:in check'", "/home/huginn/huginn/app/jobs/agent_check_job.rb:7:in perform'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activejob-<IP_ADDRESS>/lib/active_job/execution.rb:32:in block in perform_now'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:117:in call'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:555:in block (2 levels) in compile'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:505:in call'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:498:in block (2 levels) in around'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:343:in block (2 levels) in simple'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/i18n-0.7.0/lib/i18n.rb:257:in with_locale'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activejob-<IP_ADDRESS>/lib/active_job/translation.rb:7:in block (2 levels) in module:Translation'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:441:in instance_exec'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:441:in block in make_lambda'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:342:in block in simple'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:497:in block in around'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:505:in call'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:498:in block (2 levels) in around'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:343:in block (2 levels) in simple'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activejob-<IP_ADDRESS>/lib/active_job/logging.rb:23:in block (4 levels) in module:Logging'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/notifications.rb:164:in block in instrument'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/notifications/instrumenter.rb:20:in instrument'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/notifications.rb:164:in instrument'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activejob-<IP_ADDRESS>/lib/active_job/logging.rb:22:in block (3 levels) in module:Logging'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activejob-<IP_ADDRESS>/lib/active_job/logging.rb:43:in block in tag_logger'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/tagged_logging.rb:68:in block in tagged'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/tagged_logging.rb:26:in tagged'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/tagged_logging.rb:68:in tagged'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activejob-<IP_ADDRESS>/lib/active_job/logging.rb:43:in tag_logger'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activejob-<IP_ADDRESS>/lib/active_job/logging.rb:19:in block (2 levels) in module:Logging'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:441:in instance_exec'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:441:in block in make_lambda'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:342:in block in simple'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:497:in block in around'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:505:in call'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:92:in run_callbacks'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:778:in _run_perform_callbacks'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activesupport-<IP_ADDRESS>/lib/active_support/callbacks.rb:81:in run_callbacks'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activejob-<IP_ADDRESS>/lib/active_job/execution.rb:31:in perform_now'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activejob-<IP_ADDRESS>/lib/active_job/execution.rb:21:in execute'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/activejob-<IP_ADDRESS>/lib/active_job/queue_adapters/delayed_job_adapter.rb:34:in perform'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/backend/base.rb:100:in block in invoke_job'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:61:in block in initialize'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:66:in execute'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:40:in run_callbacks'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/backend/base.rb:97:in invoke_job'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:224:in block (2 levels) in run'", "/usr/local/lib/ruby/2.3.0/timeout.rb:91:in block in timeout'", "/usr/local/lib/ruby/2.3.0/timeout.rb:101:in timeout'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:224:in block in run'", "/usr/local/lib/ruby/2.3.0/benchmark.rb:308:in realtime'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:223:in run'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:300:in block in reserve_and_run_one_job'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:61:in block in initialize'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:66:in execute'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:40:in run_callbacks'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:300:in reserve_and_run_one_job'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:207:in block in work_off'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:206:in times'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:206:in work_off'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:169:in block (4 levels) in start'", "/usr/local/lib/ruby/2.3.0/benchmark.rb:308:in realtime'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:168:in block (3 levels) in start'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:61:in block in initialize'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:66:in execute'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:40:in run_callbacks'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:167:in block (2 levels) in start'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:166:in loop'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:166:in block in start'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/plugins/clear_locks.rb:7:in block (2 levels) in class:ClearLocks'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:79:in block (2 levels) in add'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:61:in block in initialize'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:79:in block in add'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:66:in execute'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/lifecycle.rb:40:in run_callbacks'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/worker.rb:165:in start'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/command.rb:131:in run'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/command.rb:119:in block in run_process'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/daemons-1.1.9/lib/daemons/application.rb:255:in block in start_proc'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/daemons-1.1.9/lib/daemons/application.rb:264:in start_proc'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/daemons-1.1.9/lib/daemons/application.rb:296:in start'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/daemons-1.1.9/lib/daemons/controller.rb:73:in run'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/daemons-1.1.9/lib/daemons.rb:197:in block in run_proc'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/daemons-1.1.9/lib/daemons/cmdline.rb:109:in catch_exceptions'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/daemons-1.1.9/lib/daemons.rb:196:in run_proc'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/command.rb:117:in run_process'", "/home/huginn/huginn/vendor/bundle/ruby/2.3.0/gems/delayed_job-4.1.1/lib/delayed/command.rb:93:in daemonize'", "script/delayed_job:5:in <top (required)>'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/lib/bundler/cli/exec.rb:63:in load'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/lib/bundler/cli/exec.rb:63:in kernel_load'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/lib/bundler/cli/exec.rb:24:in run'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/lib/bundler/cli.rb:304:in exec'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/lib/bundler/vendor/thor/lib/thor/command.rb:27:in run'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/lib/bundler/vendor/thor/lib/thor/invocation.rb:126:in invoke_command'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/lib/bundler/vendor/thor/lib/thor.rb:359:in dispatch'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/lib/bundler/vendor/thor/lib/thor/base.rb:440:in start'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/lib/bundler/cli.rb:11:in start'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/exe/bundle:27:in block in <top (required)>'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/lib/bundler/friendly_errors.rb:98:in with_friendly_errors'", "/usr/local/lib/ruby/gems/2.3.0/gems/bundler-1.12.5/exe/bundle:19:in <top (required)>'", "/usr/local/bin/bundle:23:in load'", "/usr/local/bin/bundle:23:in '"]`

Is there anyway to kill a current running agent process without restarting the application? Disabling the troublesome agent and deleting all of the jobs doesnt do anything.

Yes, go to /jobs on your Huginn instance.

@hughwi The backtrace you posted looks like a "normal" exception in an Agent, those should not take down the background processors.
When you run an Agent manually is the job processed?
What you could do to make the debugging easier is to switch your Procfile setup to the separate process version. This will create log files for each process and also restart the processors separately if one of them fails.

restarting services this time, gave me this:
/home/huginn/huginn# sudo bundle exec rake production:export Stopping huginn ... rake aborted! 'sv stop huginn-dj4-1' exited with a non-zero return value: timeout: run: huginn-dj4-1: (pid 11418) 1985772s, want down, got TERM /home/huginn/huginn/lib/tasks/production.rake:85:in run'
/home/huginn/huginn/lib/tasks/production.rake:77:in block (2 levels) in run_sv' /home/huginn/huginn/lib/tasks/production.rake:93:in with_retries'
/home/huginn/huginn/lib/tasks/production.rake:76:in block in run_sv' /home/huginn/huginn/lib/tasks/production.rake:75:in each'
/home/huginn/huginn/lib/tasks/production.rake:75:in run_sv' /home/huginn/huginn/lib/tasks/production.rake:33:in block (2 levels) in <top (required)>'
/home/huginn/huginn/lib/tasks/production.rake:57:in block (2 levels) in <top (required)>' /usr/local/bin/bundle:23:in load'
/usr/local/bin/bundle:23:in <main>' Tasks: TOP => production:export (See full trace by running task with --trace)

Hmm, does sudo bundle exec rake production:stop or sudo bundle exec rake production:force_stop work?

running the force_stop command worked, and it seems that the background workers are now outputting jobs again!
/home/huginn/huginn# sudo bundle exec rake production:stop Stopping huginn ... ok: down: huginn-dj4-1: 2072s, normally up ok: down: huginn-dj3-1: 388s, normally up ok: down: huginn-dj5-1: 299s, normally up rake aborted! 'sv stop huginn-jobs-1' exited with a non-zero return value: timeout: run: huginn-jobs-1: (pid 11420) 1988075s, want down, got TERM /home/huginn/huginn/lib/tasks/production.rake:85:in run'
/home/huginn/huginn/lib/tasks/production.rake:77:in block (2 levels) in run_sv' /home/huginn/huginn/lib/tasks/production.rake:93:in with_retries'
/home/huginn/huginn/lib/tasks/production.rake:76:in block in run_sv' /home/huginn/huginn/lib/tasks/production.rake:75:in each'
/home/huginn/huginn/lib/tasks/production.rake:75:in run_sv' /home/huginn/huginn/lib/tasks/production.rake:33:in block (2 levels) in <top (required)>'
/usr/local/bin/bundle:23:in load' /usr/local/bin/bundle:23:in '
Tasks: TOP => production:stop
(See full trace by running task with --trace)
root@mercator-huginn01:/home/huginn/huginn# sudo bundle exec rake production:force_stop
Force stopping huginn ...
ok: down: huginn-dj4-1: 2151s, normally up
ok: down: huginn-dj3-1: 467s, normally up
ok: down: huginn-dj5-1: 378s, normally up
ok: down: huginn-jobs-1: 1s, normally up
ok: down: huginn-web-1: 0s, normally up
ok: down: huginn-dj2-1: 0s, normally up
root@mercator-huginn01:/home/huginn/huginn# sudo bundle exec rake production:start
Startig huginn ...
ok: run: huginn-dj4-1: (pid 8145) 0s
ok: run: huginn-dj3-1: (pid 8154) 0s
ok: run: huginn-dj5-1: (pid 8163) 1s
ok: run: huginn-jobs-1: (pid 8172) 0s
ok: run: huginn-web-1: (pid 8183) 1s
ok: run: huginn-dj2-1: (pid 8207) 0s`

All looks good so far, would be good to try and work out why the job worker gets stuck though - anywhere i should be looking specifically? - it would also be a nice feature to be able to delete/cancel a currently running job from the /jobs screen - is this possible? (currently you can only delete waiting/queued jobs)

@hughwi I hope the next time Huginn stop processing jobs it will be easier to determine which part failed because everything is now running in its own process rather then in a combined, threaded one. You should now have logs for every process in /home/huginn/huginn/log/*/current
As far as I know there is no way to kill/stop a running job, which is a limitation of delayed_job, normally this is not a problem because jobs will be killed after DELAYED_JOB_MAX_RUNTIME. I think in your case the job stuck around because delayed_job died unexpectedly.

OK, I will keep an eye on this and update the thread if the issue reappears.

I have the same problem too, yet with Website Agent. Happen to find this just after opening another one #1579. I'll try what @dsander said to see if can find something useful when the problem reappear. Thanks.

This problem happened again last night. Unfortunately, there is still no trace  in log files.

Nothing in the logs dsander mentioned, or in the production.log?

Thanks for reminding, I forgot the production.log. I find the last job that stuck the queue there, yet not the one I mentioned in my upper post.( It seems that the log doesn't save records that long before, but lucky enough, it happened again just one hour ago : ) )
Here should be the last lines before the queue got stuck:
I, [2016-07-15T13:50:17.481009 #6982]  INFO -- : [ActiveJob] Enqueued AgentRunScheduleJob (Job ID: ff9f8ac3-bdc9-4a17-ac36-0d07172f21e0) to DelayedJob(default) with arguments: "every_30m"
I, [2016-07-15T13:50:21.387156 #6982]  INFO -- : [ActiveJob] Enqueued AgentRunScheduleJob (Job ID: 06a17e04-1935-44bc-bf73-429410462a14) to DelayedJob(default) with arguments: "every_10m"
I, [2016-07-15T13:50:24.205273 #6973]  INFO -- : 2016-07-15T13:50:24+0800: [Worker(delayed_job host:teainkLA01 pid:6973)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=2923) RUNNING
I, [2016-07-15T13:50:24.205617 #6973]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [ff9f8ac3-bdc9-4a17-ac36-0d07172f21e0] Performing AgentRunScheduleJob from DelayedJob(default) with arguments: "every_30m"
I, [2016-07-15T13:50:24.209348 #6973]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [ff9f8ac3-bdc9-4a17-ac36-0d07172f21e0] Enqueued AgentCheckJob (Job ID: e3a08a3a-89e0-4869-a33e-c3dca8c5b217) to DelayedJob(default) with arguments: 28
I, [2016-07-15T13:50:24.212193 #6973]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [ff9f8ac3-bdc9-4a17-ac36-0d07172f21e0] Enqueued AgentCheckJob (Job ID: 3b1a59b2-0d9c-4880-afb5-fff4b2c19d29) to DelayedJob(default) with arguments: 31
I, [2016-07-15T13:50:24.214647 #6973]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [ff9f8ac3-bdc9-4a17-ac36-0d07172f21e0] Enqueued AgentCheckJob (Job ID: e2cfbb20-0972-45f0-8763-9b0c4c03f2fe) to DelayedJob(default) with arguments: 32
I, [2016-07-15T13:50:24.214761 #6973]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [ff9f8ac3-bdc9-4a17-ac36-0d07172f21e0] Performed AgentRunScheduleJob from DelayedJob(default) in 9.07ms
I, [2016-07-15T13:50:24.216213 #6973]  INFO -- : 2016-07-15T13:50:24+0800: [Worker(delayed_job host:teainkLA01 pid:6973)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=2923) COMPLETED after 0.0108
I, [2016-07-15T13:50:24.219493 #6973]  INFO -- : 2016-07-15T13:50:24+0800: [Worker(delayed_job host:teainkLA01 pid:6973)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=2924) RUNNING
I, [2016-07-15T13:50:24.219846 #6973]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [06a17e04-1935-44bc-bf73-429410462a14] Performing AgentRunScheduleJob from DelayedJob(default) with arguments: "every_10m"
I, [2016-07-15T13:50:24.220641 #6973]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [06a17e04-1935-44bc-bf73-429410462a14] Performed AgentRunScheduleJob from DelayedJob(default) in 0.72ms
I, [2016-07-15T13:50:24.221773 #6973]  INFO -- : 2016-07-15T13:50:24+0800: [Worker(delayed_job host:teainkLA01 pid:6973)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=2924) COMPLETED after 0.0022
I, [2016-07-15T13:50:24.224838 #6973]  INFO -- : 2016-07-15T13:50:24+0800: [Worker(delayed_job host:teainkLA01 pid:6973)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=2925) RUNNING
I, [2016-07-15T13:50:24.225122 #6973]  INFO -- : [ActiveJob] [AgentCheckJob] [e3a08a3a-89e0-4869-a33e-c3dca8c5b217] Performing AgentCheckJob from DelayedJob(default) with arguments: 28
I, [2016-07-15T13:50:25.371297 #6973]  INFO -- : [ActiveJob] [AgentCheckJob] [e3a08a3a-89e0-4869-a33e-c3dca8c5b217] Performed AgentCheckJob from DelayedJob(default) in 1146.08ms
I, [2016-07-15T13:50:25.373028 #6973]  INFO -- : 2016-07-15T13:50:25+0800: [Worker(delayed_job host:teainkLA01 pid:6973)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=2925) COMPLETED after 1.1481
I, [2016-07-15T13:50:25.376762 #6973]  INFO -- : 2016-07-15T13:50:25+0800: [Worker(delayed_job host:teainkLA01 pid:6973)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=2926) RUNNING
I, [2016-07-15T13:50:25.377102 #6973]  INFO -- : [ActiveJob] [AgentCheckJob] [3b1a59b2-0d9c-4880-afb5-fff4b2c19d29] Performing AgentCheckJob from DelayedJob(default) with arguments: 31
I, [2016-07-15T13:50:26.069178 #6973]  INFO -- : [ActiveJob] [AgentCheckJob] [3b1a59b2-0d9c-4880-afb5-fff4b2c19d29] Performed AgentCheckJob from DelayedJob(default) in 691.98ms
I, [2016-07-15T13:50:26.071198 #6973]  INFO -- : 2016-07-15T13:50:26+0800: [Worker(delayed_job host:teainkLA01 pid:6973)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=2926) COMPLETED after 0.6943
I, [2016-07-15T13:50:26.074541 #6973]  INFO -- : 2016-07-15T13:50:26+0800: [Worker(delayed_job host:teainkLA01 pid:6973)] Job ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper (id=2927) RUNNING
I, [2016-07-15T13:50:26.074861 #6973]  INFO -- : [ActiveJob] [AgentCheckJob] [e2cfbb20-0972-45f0-8763-9b0c4c03f2fe] Performing AgentCheckJob from DelayedJob(default) with arguments: 32

The stuck job is a Website Agent with a schedule to run every 30 minutes.
However I can't exactly figure out what went wrong. Does it help identify the problem?
Thank you so much.

To debug and fix the problem we either need a backtrace or a way to reproduce the issue. Does this always happen with the same WebsiteAgent or is it random?
Can you check if the background worker is doing anything after it locked up?
# Get the PID
ps aux|grep threaded

huginn   31684  1.9 23.6<PHONE_NUMBER>76 ?       Sl   Jul06 249:58 bin/threaded.rb

# strace the main thread
sudo strace -p 31684 -f

# You should see output that looks like this:
futex(0x7f9b5a7ce794, FUTEX_WAIT_BITSET_PRIVATE, 6242125, {16932739, 665864126}, ffffffff) = -1 ETIMEDOUT (Connection timed out)
futex(0x7f9b5a7ce808, FUTEX_WAKE_PRIVATE, 1) = 0
clock_gettime(CLOCK_MONOTONIC, {16932739, 666291235}) = 0
clock_gettime(CLOCK_MONOTONIC, {16932739, 666401741}) = 0
clock_gettime(CLOCK_MONOTONIC, {16932739, 666478470}) = 0
futex(0x7f9b5a7ce794, FUTEX_WAIT_BITSET_PRIVATE, 6242127, {16932739, 916478470}, ffffffff) = -1 ETIMEDOUT (Connection timed out)
futex(0x7f9b5a7ce808, FUTEX_WAKE_PRIVATE, 1) = 0
clock_gettime(CLOCK_MONOTONIC, {16932739, 917375773}) = 0
clock_gettime(CLOCK_MONOTONIC, {16932739, 917568375}) = 0
clock_gettime(CLOCK_MONOTONIC, {16932739, 917736360}) = 0
futex(0x7f9b5a7ce794, FUTEX_WAIT_BITSET_PRIVATE, 6242129, {16932740, 167736360}, ffffffff) = -1 ETIMEDOUT (Connection timed out)
futex(0x7f9b5a7ce808, FUTEX_WAKE_PRIVATE, 1) = 0

# strace all threads of the background worker and filter out clock_gettime and futex calls
sudo strace -p 31684 -f -e 'trace=!clock_gettime,futex'

# This should still output a bunch of system calls like `write`, `read` etc.

Hi dsander, nice to see you again. In my cases, the problem always happens to website agents but not to the same one. And I can't see any regularity in it. It seems that I have to switch the Procfile back to threaded mode to follow your suggestion. I'll do it and see if can find out something the next time it appears. Thanks.

What is the nature of the websites that keep hanging up?  Are they APIs or are you pulling HTML/XML for parsing?

@vitorbaptista Great, the strace commands will also work in non-threaded mode it would actually be easier to track down which part of the background processing stopped working that way. I just assumed you were running in threaded mode :)
When running in non threaded mode run ps aux|grep huginn will give you all processes of the huginn user. Those are the ones we are interested in:
# process that schedules the agents to run:
huginn   16662 22.7 11.8<PHONE_NUMBER>12 ?       Rl   17:13   0:05 /usr/local/bin/ruby bin/rails runner bin/schedule.rb
# DelayedJob worker that executes the Agents
huginn   16667 22.8 12.7<PHONE_NUMBER>20 ?       Rl   17:13   0:05 ruby script/delayed_job run
# TwitterStream processing (probably not related to your problem)
huginn   16669 22.8 11.9<PHONE_NUMBER>12 ?       Rl   17:13   0:05 /usr/local/bin/ruby bin/rails runner bin/twitter_stream.rb

@virtadpt Hi, I have several website agents pulling HTML from different websites, and the problem happens randomly on them.

@dsander OK, I see. I'll keep it on non-threaded mode and keep an eye on it. Thanks!

Could DNS resolution be timing out?  Do you have IPv6 configured on the server?

No, I run it on VPS that only have ipv4. It is quite strange that there are thousands of people have huginn running on their servers but I have seen only two or three people have the same issue. So maybe the problem lies in my server's configurations?

No, I run it on VPS that only have ipv4. It is quite strange that there are thousands of people have huginn running on their servers but I have seen only two or three people have the same issue. So maybe the problem lies in my server's configurations?

Hi, dsander. Below is the output after a website agent locked up again. It's a bit long.
Here the first line in the output of ps aux|grep huginn indicates that there seems there's a lack of some log file.
~# ps aux|grep huginn
root      2732  0.0  0.0    140    28 ?        S    Jul15   0:01 runsvdir -P /etc/service log: ew: file does not exist runsv huginn-web-1: warning: unable to open log/supervise/pid.new: file does not exist runsv huginn-twitter-1: warning: unable to open log/supervise/pid.new: file does not exist runsv huginn-schedule-1: warning: unable to open log/supervise/pid.new: file does not exist .....................................................................................................
root     11135  0.0  0.0   7736   944 pts/1    S+   14:06   0:00 grep huginn
root     30293  0.0  0.0    116    24 ?        Ss   Jul18   0:00 runsv huginn-schedule-1
root     30294  0.0  0.0    116    20 ?        Ss   Jul18   0:00 runsv huginn-twitter-1
root     30295  0.0  0.0    116    20 ?        Ss   Jul18   0:00 runsv huginn-web-1
root     30296  0.0  0.0    116    20 ?        Ss   Jul18   0:00 runsv huginn-dj-1
huginn   30297  0.0  0.0    136    44 ?        S    Jul18   0:00 svlogd /home/huginn/huginn/log/dj-1
huginn   30298  0.1  4.5<PHONE_NUMBER>92 ?       Sl   Jul18   1:59 ruby script/delayed_job run
huginn   30299  0.0  0.0    136    44 ?        S    Jul18   0:00 svlogd /home/huginn/huginn/log/web-1
huginn   30300  0.0  3.0<PHONE_NUMBER>76 ?       Sl   Jul18   0:04 unicorn master -c config/unicorn.rb
huginn   30301  0.0  0.0    136    40 ?        S    Jul18   0:00 svlogd /home/huginn/huginn/log/twitter-1
huginn   30302  0.0  3.8<PHONE_NUMBER>24 ?       Sl   Jul18   0:46 bin/twitter_stream.rb
huginn   30304  0.0  0.0    136    40 ?        S    Jul18   0:00 svlogd /home/huginn/huginn/log/schedule-1
huginn   30305  0.1  4.1<PHONE_NUMBER>40 ?       Sl   Jul18   2:04 bin/schedule.rb
huginn   30441  0.0  4.0<PHONE_NUMBER>28 ?       Sl   Jul18   0:16 unicorn worker[0] -c config/unicorn.rb
huginn   30444  0.0  4.4<PHONE_NUMBER>56 ?       Sl   Jul18   0:18 unicorn worker[1] -c config/unicorn.rb

strace of bin/twitter_stream.rb
~# sudo strace -p 30302 -f -e 'trace=!clock_gettime,futex'
Process 30302 attached with 5 threads - interrupt to quit
[pid 30452] restart_syscall(<... resuming interrupted call ...> <unfinished ...>
[pid 30349] restart_syscall(<... resuming interrupted call ...> <unfinished ...>
[pid 30302] restart_syscall(<... resuming interrupted call ...> <unfinished ...>
[pid 30452] <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
[pid 30302] <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... restart_syscall resumed> ) = 1
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30452] write(6, "!", 1)            = 1
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1) = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!!", 1024)         = 2
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30465] sched_yield()               = 0
[pid 30349] <... poll resumed> )        = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid  3833] poll([{fd=7, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid  3833] write(7, "\1\0\0\0\16", 5)  = 5
[pid  3833] read(7, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11
[pid  3833] poll([{fd=7, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid  3833] write(7, "\223\0\0\0\3SELECT `agents`.* FROM `age"..., 151) = 151
[pid  3833] ppoll([{fd=7, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=7, revents=POLLIN}])
[pid  3833] read(7, "\1\0\0\1\0267\0\0\2\3def\21huginn_production\6"..., 16384) = 1707
[pid 30349] <... poll resumed> )        = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1) = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid  3833] sched_yield()               = 0
[pid 30349] <... poll resumed> )        = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30465] sched_yield( <unfinished ...>
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30465] <... sched_yield resumed> ) = 0
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30465] sched_yield()               = 0
[pid 30349] <... poll resumed> )        = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid  3833] sched_yield()               = 0
[pid 30349] <... poll resumed> )        = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1) = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid  3833] sched_yield()               = 0
[pid 30349] <... poll resumed> )        = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30465] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30465] sched_yield()               = 0
[pid 30465] poll([{fd=7, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid 30465] write(7, "\1\0\0\0\16", 5)  = 5
[pid 30465] read(7, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11
[pid 30465] poll([{fd=7, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid 30465] write(7, "\223\0\0\0\3SELECT `agents`.* FROM `age"..., 151) = 151
[pid 30465] ppoll([{fd=7, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=7, revents=POLLIN}])
[pid 30465] read(7, "\1\0\0\1\0267\0\0\2\3def\21huginn_production\6"..., 16384) = 1707
[pid 30349] <... poll resumed> )        = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  3833] write(6, "!", 1)            = 1
[pid 30349] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30349] read(3, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] read(5, "!", 1024)          = 1
[pid 30349] read(5, 0x7f68c44c4d00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30349] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30349] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>

strace of ruby script/delayed_job run
~# sudo strace -p 30298 -f -e 'trace=!clock_gettime,futex'
Process 30298 attached with 3 threads - interrupt to quit
[pid 30321] restart_syscall(<... resuming interrupted call ...> <unfinished ...>
[pid 30298] restart_syscall(<... resuming interrupted call ...> <unfinished ...>
[pid 30321] <... restart_syscall resumed> ) = 0
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] <... restart_syscall resumed> ) = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 865 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 765 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 665 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 565 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 464 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 364 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 264 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 164 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 63) = 0 (Timeout)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 1000 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 963 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 863 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 763 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 663 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 562 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 462 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 362 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 262 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 161 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 60) = 0 (Timeout)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 1000 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 960 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 860 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 760 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 660 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 559 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 459 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 359 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 259 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 158 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 57) = 0 (Timeout)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 1000 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 956 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 856 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 756 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 656 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 555 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 455 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 355 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 255 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 154 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 53) = 0 (Timeout)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 1000 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 953 <unfinished ...>
[pid 30321] <... poll resumed> )        = 0 (Timeout)
[pid 30321] tgkill(30298, 30298, SIGVTALRM) = 0
[pid 30298] <... poll resumed> )        = ? ERESTART_RESTARTBLOCK (To be restarted)
[pid 30321] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 30298] --- SIGVTALRM (Virtual timer expired) @ 0 (0) ---
[pid 30298] rt_sigreturn(0x1a)          = -1 EINTR (Interrupted system call)
[pid 30298] poll([{fd=9, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 853 <unfinished ...>

strace of bin/schedule.rb
~# sudo strace -p 30305 -f -e 'trace=!clock_gettime,futex'
Process 30305 attached with 9 threads - interrupt to quit
[pid 30453] restart_syscall(<... resuming interrupted call ...> <unfinished ...>
[pid 30350] restart_syscall(<... resuming interrupted call ...> <unfinished ...>
[pid 30305] restart_syscall(<... resuming interrupted call ...>) = -1 ETIMEDOUT (Connection timed out)
[pid 30453] <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
[pid 31168] write(6, "!", 1)            = 1
[pid 30350] <... restart_syscall resumed> ) = 1
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30466] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 31167] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  9667] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 31308] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 31168] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30466] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 31167] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  9667] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid  9667] poll([{fd=12, events=POLLIN|POLLPRI}], 1, 0 <unfinished ...>
[pid 31308] write(6, "!", 1)            = 1
[pid  9667] <... poll resumed> )        = 0 (Timeout)
[pid  9667] write(12, "\6\0\0\0\3BEGIN", 10) = 10
[pid  9667] ppoll([{fd=12, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=12, revents=POLLIN}])
[pid  9667] read(12, "\7\0\0\1\0\0\0\3\0\0\0", 16384) = 11
[pid  9667] poll([{fd=12, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid  9667] write(12, "\253\1\0\0\3INSERT INTO `delayed_jobs` "..., 431) = 431
[pid  9667] ppoll([{fd=12, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=12, revents=POLLIN}])
[pid  9667] read(12, "\t\0\0\1\0\1\374\205S\3\0\0\0", 16384) = 13
[pid  9667] poll([{fd=12, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid  9667] write(12, "\7\0\0\0\3COMMIT", 11) = 11
[pid  9667] ppoll([{fd=12, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=12, revents=POLLIN}])
[pid  9667] read(12, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11
[pid  9667] write(8, "I, [2016-07-19T14:17:19.853036 #"..., 188) = 188
[pid 31308] write(6, "!", 1)            = 1
[pid 31308] poll([{fd=9, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid 31308] write(9, "x\0\0\0\3SELECT COUNT(*) FROM `delay"..., 124) = 124
[pid 31308] ppoll([{fd=9, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=9, revents=POLLIN}])
[pid 31308] read(9, "\1\0\0\1\1\36\0\0\2\3def\0\0\0\10COUNT(*)\0\f?\0\25\0\0"..., 16384) = 63
[pid 31168] write(6, "!", 1)            = 1
[pid 31168] poll([{fd=11, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid 31168] write(11, "\6\0\0\0\3BEGIN", 10) = 10
[pid 31168] ppoll([{fd=11, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=11, revents=POLLIN}])
[pid 31168] read(11, "\7\0\0\1\0\0\0\3\0\0\0", 16384) = 11
[pid 31168] poll([{fd=11, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid 31168] write(11, "\253\1\0\0\3INSERT INTO `delayed_jobs` "..., 431) = 431
[pid 31168] ppoll([{fd=11, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=11, revents=POLLIN}])
[pid 31168] read(11, "\t\0\0\1\0\1\374\206S\3\0\0\0", 16384) = 13
[pid 31168] poll([{fd=11, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid 31168] write(11, "\7\0\0\0\3COMMIT", 11) = 11
[pid 31168] ppoll([{fd=11, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=11, revents=POLLIN}])
[pid 31168] read(11, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11
[pid 31168] write(8, "I, [2016-07-19T14:17:19.858950 #"..., 188) = 188
[pid 30350] <... poll resumed> )        = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1) = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!!!", 1024)        = 3
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 31167] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 31167] poll([{fd=7, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid 31167] write(7, "Q\0\0\0\3SELECT `agents`.* FROM `age"..., 85) = 85
[pid 31167] ppoll([{fd=7, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=7, revents=POLLIN}])
[pid 31167] read(7, "\1\0\0\1\0267\0\0\2\3def\21huginn_production\6"..., 16384) = 1707
[pid 30350] <... poll resumed> )        = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30466] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  9667] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid  9667] poll([{fd=12, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid  9667] write(12, "\6\0\0\0\3BEGIN", 10) = 10
[pid  9667] ppoll([{fd=12, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=12, revents=POLLIN}])
[pid  9667] read(12, "\7\0\0\1\0\0\0\3\0\0\0", 16384) = 11
[pid  9667] poll([{fd=12, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid  9667] write(12, "\254\1\0\0\3INSERT INTO `delayed_jobs` "..., 432) = 432
[pid  9667] ppoll([{fd=12, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=12, revents=POLLIN}])
[pid  9667] read(12, "\t\0\0\1\0\1\374\207S\3\0\0\0", 16384) = 13
[pid  9667] poll([{fd=12, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid  9667] write(12, "\7\0\0\0\3COMMIT", 11) = 11
[pid  9667] ppoll([{fd=12, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=12, revents=POLLIN}])
[pid  9667] read(12, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11
[pid  9667] write(8, "I, [2016-07-19T14:17:27.358114 #"..., 189) = 189
[pid 30350] <... poll resumed> )        = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 31308] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 31168] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 31167] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30466] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid  9667] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid  9667] poll([{fd=12, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid  9667] write(12, "\6\0\0\0\3BEGIN", 10) = 10
[pid  9667] ppoll([{fd=12, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=12, revents=POLLIN}])
[pid  9667] read(12, "\7\0\0\1\0\0\0\3\0\0\0", 16384) = 11
[pid  9667] poll([{fd=12, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid  9667] write(12, "\254\1\0\0\3INSERT INTO `delayed_jobs` "..., 432) = 432
[pid  9667] ppoll([{fd=12, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=12, revents=POLLIN}])
[pid  9667] read(12, "\t\0\0\1\0\1\374\210S\3\0\0\0", 16384) = 13
[pid  9667] poll([{fd=12, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid  9667] write(12, "\7\0\0\0\3COMMIT", 11) = 11
[pid  9667] ppoll([{fd=12, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=12, revents=POLLIN}])
[pid  9667] read(12, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11
[pid  9667] write(8, "I, [2016-07-19T14:17:46.893667 #"..., 189) = 189
[pid 30350] <... poll resumed> )        = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 31308] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid 31308] poll([{fd=9, events=POLLIN|POLLPRI}], 1, 0 <unfinished ...>
[pid 31168] write(6, "!", 1)            = 1
[pid 31308] <... poll resumed> )        = 0 (Timeout)
[pid 31308] write(9, "\6\0\0\0\3BEGIN", 10) = 10
[pid 31308] ppoll([{fd=9, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=9, revents=POLLIN}])
[pid 31308] read(9, "\7\0\0\1\0\0\0\3\0\0\0", 16384) = 11
[pid 31308] poll([{fd=9, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid 31308] write(9, "\253\1\0\0\3INSERT INTO `delayed_jobs` "..., 431) = 431
[pid 31308] ppoll([{fd=9, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=9, revents=POLLIN}])
[pid 31308] read(9, "\t\0\0\1\0\1\374\211S\3\0\0\0", 16384) = 13
[pid 31308] poll([{fd=9, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid 31308] write(9, "\7\0\0\0\3COMMIT", 11) = 11
[pid 31308] ppoll([{fd=9, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=9, revents=POLLIN}])
[pid 31308] read(9, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11
[pid 31308] write(8, "I, [2016-07-19T14:17:48.097081 #"..., 188) = 188
[pid 30350] <... poll resumed> )        = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1) = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 31167] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>
[pid 30466] write(6, "!", 1)            = 1
[pid 30350] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid 30350] read(3, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] read(5, "!", 1024)          = 1
[pid 30350] read(5, 0x7f4690a7bd00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid 30350] poll([{fd=3, events=POLLIN}], 1, 100) = 0 (Timeout)
[pid 30350] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1 <unfinished ...>

@vivagonna Thanks for the output, I was hoping for either no activity or some obvious errors in one of the processes but can't find anything suspicious either.
Can you restart the background services individually the next time they lock up?
First restart the scheduler and check if Huginn starts working again:
sudo sv restart huginn-schedule-1, if it doesnt also restart delayed job sudo sv restart huginn-dj-1.

Ok.
Thanks a lot. :）

@dsander Hi, I got the chance to try it today. It turned out that after restart huginn-dj-1, the queue began to move again. But It had to be force-stop  and than start .
root@teainkLA01:~# sudo sv restart huginn-schedule-1 ok: run: huginn-schedule-1: (pid 1964) 0s root@teainkLA01:~# sudo sv restart huginn-dj-1 timeout: run: huginn-dj-1: (pid 4286) 1593447s, got TERM root@teainkLA01:~# sudo sv restart huginn-dj-1 timeout: run: huginn-dj-1: (pid 4286) 1593472s, got TERM root@teainkLA01:~# sudo sv force-stop  huginn-dj-1 kill: run: huginn-dj-1: (pid 4286) 1593503s, want down, got TERM root@teainkLA01:~# sudo sv start  huginn-dj-1 ok: run: huginn-dj-1: (pid 2879) 1s root@teainkLA01:~#

@vitorbaptista Darn, that means it could be caused by any of your Agents, does the log for the dj-1 process contain anything suspicious before you did the restart?

@dsander I guess you're citing me here by mistake, right?

@vitorbaptista Yes, sorry! GitHub's auto complete suggestions are really strange.
@vivagonna Meant to mention you :)

@dsander Aha! I'm here. I'm sorry I didn't examine the log this time, I'll keep an eye on it next time ; )
This problem is like a ghost, and I'm not sure if it has anything to do with my server because there are some other services in the same box. What I plan to do is build another instance in a clean system from scratch to eliminate possible interference. But before that, I have to get my damned TOEFL exam done, sigh…

Having the same issue as well, website agent always gets stuck randomly.
Restarting huginn solves it. No error in log.

@WangQiru Have you had the chance to strace the background processes? (https://github.com/cantino/huginn/issues/1567#issuecomment-232947901)

@dsander See the following.
[pid  4983] write(6, "!", 1)            = 1
[pid  1036] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid  1036] read(3, 0x7feba9872e00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid  1036] read(5, "!", 1024)          = 1
[pid  1036] read(5, 0x7feba9872e00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid  1036] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid  4983] write(6, "!", 1)            = 1
[pid  1036] <... poll resumed> )        = 0 (Timeout)
[pid  1036] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2,<PHONE_NUMBER>) = 1 ([{fd=5, revents=POLLIN}])
[pid  1036] read(3, 0x7feba9872e00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid  1036] read(5, "!", 1024)          = 1
[pid  1036] read(5, 0x7feba9872e00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid  1036] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2,<PHONE_NUMBER> <unfinished ...>
[pid 23866] uname({sys="Linux", node="London", ...}) = 0
[pid 23866] write(8, "I, [2017-01-27T15:15:30.073651 #"..., 255) = 255
[pid 11200] write(6, "!", 1)            = 1
[pid  1036] <... poll resumed> )        = 1 ([{fd=5, revents=POLLIN}])
[pid  1036] read(3, 0x7feba9872e00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid  1036] read(5, "!", 1024)          = 1
[pid  1036] read(5, 0x7feba9872e00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid  1036] poll([{fd=3, events=POLLIN}], 1, 100 <unfinished ...>
[pid  1497] write(6, "!", 1)            = 1
[pid  1036] <... poll resumed> )        = 0 (Timeout)
[pid  1036] poll([{fd=3, events=POLLIN}, {fd=5, events=POLLIN}], 2,<PHONE_NUMBER>) = 1 ([{fd=5, revents=POLLIN}])
[pid  1036] read(3, 0x7feba9872e00, 1024) = -1 EAGAIN (Resource temporarily unavailable)
[pid  1036] read(5, "!", 1024)          = 1
[pid  1036] read(5, 0x7feba9872e00, 1024) = -1 EAGAIN (Resource temporarily unavailable)

I'm having 8 website agents to crawl data into a rss feed, and all of them will randomly get stuck. Slack agent is working fine.
Running with debian jessie 8.7 with 3.2.0-4-amd64 kernel, plenty of RAM and CPU available.

@WangQiru Thanks, it's still doing something, but without knowing where the file descriptors 3 and 5 came from I can't say what it is.
If it is happening regularly with your Agent configuration could you share that scenario so that I can run it on my own instance?

@dsander
exported-agents.json.zip
Tried increase database pooling size didn't help. Is it possible to relate the issue to RAM?

Thanks @WangQiru, I will run those Agents on my Huginn instance.

I'm also getting a job that hangs regularly and is preventing any other jobs from running.
I am running a docker-based huginn single-process instance.
json: https://huginn.bessereau.eu/scenarios/3/export.json
the job that hangs is Get Salesforce Help JS Payloads.
The job succeeds a few times before hanging. Based on 31 events generated per run (which is normal for this call) I have seen it hang after between 10 and 20 runs on average.
Restarting the huginn_threaded container solves the issue temporarily.
The logs returned to docker don't show anything super interesting sadly.
I will try to keep an eye on the process and catch the moment it hangs - most of my jobs run once a minute so LOTS of logs get generated fast.
Any help on how to make the agent not hang and prevent all other jobs from running is appreciated.

Adding a comment here: seems it's always the POST agent getting stuck and always at the same time; 4AM. Still trying to get logs of what is going on at that time.

How many delayed_job runners do you have?  Can you capture the output of them between 0300 and 0500 to see what's going down in there?  What exception is being thrown?

Hey, sorry for the delay, I was trying to get the logs.
1/ I just spun up huginn with docker - I didn't specify specifically how many runners there should be.
I used this docker-compose: https://github.com/huginn/huginn/blob/master/docker/single-process/postgresql.yml
2/ I tried fetching logs for only that time period but huginn_threaded seems to continue outputting logs, basically saying "enqueued job" - I have some 20 jobs, of which 4 run every minute, so taht's a lto of logs, which seems to exceed huginn's max capacity
3/ It's always the same agent that bugs out, and it seems to always be at 4AM for some reason.
4/ Despite trying, I ahven't been able to find a log of the exception. I would like it better if the container crashed - I could just view the tail of the logs - but as is i'm a bit lost on how to get the information I need, shy of staying up until 4AM and praying I see the error.
Any suggestions on how to move forward are welcome.

I just ran into this issue, it would be great if jobs had a max_run_time after which they are killed? Had a job running for 5 days that blocked all others.

Look in your .env file.
# Maximum runtime of background jobs in minutes
DELAYED_JOB_MAX_RUNTIME=2

If your delayed_job workers are hanging up there are a couple of other possible bugs you might be running into.  Do you have any stack traces?

I have set DELAYED_JOB_MAX_RUNTIME=2, I don't have any stack traces. I am running the docker version. I'll add a cron job to restart the container every 24 hours.

Yeah that's what I ended up doing.
It seems it's the HTTP Agent hanging, I still don't know why, and it's still not throwing logs.
So what I did is literally just:

spin up multiple instances of the background huginn containers, so one hangs but others continue processing
set up a daily restart script that restarts all the huginn containers once a day

Since a few months that's been stable. I know the bug is still there because I see the hanging job sometimes, but the restart script catches it before everything grinds to a halt.
tbh I find the passivity around "you have a breaking bug that seems complex enough to get logs about, and people literally asking if/how we can do a specific debug about it" somewhat weird, but I mean it's free software and it works, so I'm not bitching.

I really wish I knew.  I've dug into it a few times but haven't come up with anything conclusive.  I've never been able to deliberately replicate the problem, it just crops up once or twice a month on one of my nodes.  The stack trace basically says it's a timeout but doesn't give any other information that can be used to run it to ground.

I'm experiencing the same issue... Also running Huginn from a Docker container, no stack traces


Update TOC.yml

Old one(roadmap link) is not available now.
Need to change it.

@FuzziWumpus @akashdubey-ms
Can you review the proposed changes?
IMPORTANT: When the changes are ready for publication, adding a #sign-off comment is the best way to signal that the PR is ready for the review team to merge.
#label:"aq-pr-triaged"
@MicrosoftDocs/public-repo-pr-review-team


Dropdown menu doesn't work with fallback avatar

Describe the bug
A dropdown menu with an Avatar as the trigger works only if the Avatar was given a proper image and the fallback was not used. If the fallback is used, the dropdown menu no longer responds to being clicked on.
To Reproduce
Steps to reproduce the behavior:
def extract_initials_from_email(email):
    name = email.split("@")[0]
    initials = "".join(c[0] for c in name.split(".") if c.isalpha())
    return initials[:2].upper()

def account_drop_down() -> rx.Component:
    email =<EMAIL_ADDRESS>    initials = extract_initials_from_email(email)
    g = Gravatar(email)
    img = g.get_image(default="404")
    avatar = rx.avatar(src=img, fallback=initials, radius="full")

    return rx.menu.root(
        rx.menu.trigger(avatar),
        rx.menu.content(
            rx.menu.separator(),
            rx.menu.item("Logout", color="red", on_click=rx.console_log(img)),
        ),
        position="fixed",
        right="1.5em",
        top="1.5em",
    )

Expected behavior
The dropdown should appear regardless if the avatar has an image or if it has the fallback text
Screenshots
Here you can see clicking on the avatar brings up the drop down menu:

And here you can see when clicked on the avatar with the fallback text does not show the drop down menu:

Specifics (please complete the following information):

Python Version: 3.12.1
Reflex Version: 0.4.3
OS: OS: WSL on Windows 11 (Ubuntu 22.04.4 LTS (GNU/Linux <IP_ADDRESS>-microsoft-standard-WSL2 x86_64)
Browser (Optional):

Additional context
Add any other context about the problem here.

@bertbarabas till it is fixed, you can surround it with flex.
def extract_initials_from_email(email):
    name = email.split("@")[0]
    initials = "".join(c[0] for c in name.split(".") if c.isalpha())
    return initials[:2].upper()

def account_drop_down() -> rx.Component:
    email =<EMAIL_ADDRESS>    initials = extract_initials_from_email(email)
    g = Gravatar(email)
    img = g.get_image(default="404")
    avatar = rx.avatar(src=img, fallback=initials, radius="full")

    return rx.menu.root(
-       rx.menu.trigger(avatar),
+       rx.menu.trigger(rx.flex(avatar)),
        rx.menu.content(
            rx.menu.separator(),
            rx.menu.item("Logout", color="red", on_click=rx.console_log(img)),
        ),
        position="fixed",
        right="1.5em",
        top="1.5em",
    )


Introduce Authentication subsystem facade methods.

Closes #1408

This is pretty good. Thanks! I am however pretty sure that there are more places that could use the new API. Did you scan the codebase for all places that use the new support class? I bet there are more test cases that use utilize the "old" model.

I did the pretty thorough scan via IDEA. I think I got it all, but if for some reason something is missed that could be refactored later on "on the fly" ;-)

Kewl.

:+1:

I like the idea, I'm not fully convinced by the names. Could we have something more explicit like startTransactions, addTransaction and endTransactions?

But I did carefully think about the current names. We have 2 concepts here,
really - an authentication transaction - a single interaction with an
authentication source with given credentials and authentication attempt - a
summary of all the possible auth transactions in order to gain access,
create web SSO session, etc. Hence the very carefully chosen names to
expose an intention revealing interface.
D.
On Sun, Jan 10, 2016 at 08:11 LELEU Jérôme<EMAIL_ADDRESS>wrote:

I like the idea, I'm not fully convinced by the names. Could we have
something more explicit like startTransactions, addTransaction and
endTransactions?
—
Reply to this email directly or view it on GitHub
https://github.com/Jasig/cas/pull/1432#issuecomment-170343674.

I was not respectfully saying that names have not been properly devised. The attempt concept is something which has never been used before and which is not really clear not me. When I read attempt, I think: unfinished and (maybe failed.
Though, the idea here is when we have played all transactions, to finish the authentication process and generate an authentication context, right?

Yes, "attempt" is somewhat new concept here, but nevertheless we just
saying that someone is attempting to authenticate. A "finalized attempt" is
successful when all the necessary authentication transactions are executed
and final authentication context is built.
So if "attempt" does not represent a clear concept here, may be we could
refer to it (in the facade method names) as "authentication result". Or
even better - rename AuthenticationContext to AuthenticationResult!
On Mon, Jan 11, 2016 at 04:23 LELEU Jérôme<EMAIL_ADDRESS>wrote:

I was not respectfully saying that names have not been properly devised.
The attempt concept is something which has never been used before and
which is not really clear not me. When I read attempt, I think: unfinished
and (maybe failed.
Though, the idea here is when we have played all transactions, to finish
the authentication process and generate an authentication context, right?
—
Reply to this email directly or view it on GitHub
https://github.com/Jasig/cas/pull/1432#issuecomment-170481853.

I like AuthenticationResult.

Misagh, let's rename AuthenticationContext to AuthenticationResult
On Mon, Jan 11, 2016 at 06:41 LELEU Jérôme<EMAIL_ADDRESS>wrote:

I like AuthenticationResult.
—
Reply to this email directly or view it on GitHub
https://github.com/Jasig/cas/pull/1432#issuecomment-170516305.

Sure. Questions:
Is this something:

We should do in this pull?
I should do, in this pull?
I should do in a separate pull?

P.S: The name sounds good to me, if you want to make changes in the same pull, etc.

How about this - merge this pull and I'll do the refactoring from the
merged master and make a separate PR. Will be cleaner. Sounds good?
On Mon, Jan 11, 2016 at 07:14 Misagh Moayyed<EMAIL_ADDRESS>wrote:

P.S: The name sounds good to me, if you want to make changes in the same
pull, etc.
—
Reply to this email directly or view it on GitHub
https://github.com/Jasig/cas/pull/1432#issuecomment-170523531.

Copy that. @leleuj OK with you?

PS renamed the pull description to use the keyword "closes" as that would automatically close the issue when the PR is merged.

+1

And so with the refactored AuthenticationResult the new facade API would look like this (which IMHO very clear and intention revealing):
AuthenticationResultBuilder handleInitialAuthenticationTransaction(Credential... credential)

    AuthenticationResultBuilder handleAuthenticationTransaction(AuthenticationResultBuilder authenticationResultBuilder, Credential... credential)

    AuthenticationResult finalizeAllAuthenticationTransactions(AuthenticationResultBuilder authenticationResultBuilder, Service service)

    AuthenticationResult handleAndFinalizeSingleAuthenticationTransaction(Service service, Credential... credential)

Approx ETA for the new PR on this  -some time on (01/12/2016 or 01/13/2016)

I agree


isChainValid() Change

Thanks for the pull request!
I'm thinking a bit about it, and I think we should do it differently. The first block in the chain is the genesis block. That's hardcoded into the code so I guess we should leave the code as-is and instead check if the first block matches the hardcoded one.
What do you think?

Yeah, that'd work, too. Only if the first or second block is processed does
it still display valid.
That's your choice

I agree with @kofon95
This PR is more related to style and not to functionality. Not merging this for now.