Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

No emails are being sent, nothing in logs #3424

Open
SeanOMik opened this issue Jun 27, 2024 · 1 comment
Open

No emails are being sent, nothing in logs #3424

SeanOMik opened this issue Jun 27, 2024 · 1 comment

Comments

@SeanOMik
Copy link

I'm running huginn using the multi-process image ghcr.io/huginn/huginn, which is not sending emails. I made sure to enable production mode by setting RAILS_ENV=production which made no change. I tried to set SEND_EMAIL_IN_DEVELOPMENT to true, which also made no change.

The email agent says its not working. I ran the agent with Actions > Run, then checked the logs of the agent, but its empty:
image

I checked the container logs but I'm not seeing any errors. I checked my SMTP relay logs and its not showing any incoming connections. Here's the logs after starting up and running the job a few times:

You are replacing the current local value of without, which is currently "test:development"
Fetching gem metadata from https://rubygems.org/......
Fetching pg 1.5.6
Installing pg 1.5.6 with native extensions
Bundle complete! 114 Gemfile dependencies, 227 gems now installed.
Gems in the groups 'test' and 'development' were not installed.
Bundled gems are installed into `./vendor/bundle`
2024-06-27 00:50:38,308 INFO Included extra file "/etc/supervisor/conf.d/bootstrap.conf" during parsing
2024-06-27 00:50:38,308 INFO Included extra file "/etc/supervisor/conf.d/foreman.conf" during parsing
2024-06-27 00:50:38,308 INFO Included extra file "/etc/supervisor/conf.d/mysqld.conf" during parsing
2024-06-27 00:50:38,314 INFO RPC interface 'supervisor' initialized
2024-06-27 00:50:38,314 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2024-06-27 00:50:38,314 INFO supervisord started with pid 1
2024-06-27 00:50:39,318 INFO spawned: 'stdout' with pid 599
2024-06-27 00:50:39,322 INFO spawned: 'bootstrap' with pid 600
2024-06-27 00:50:39,334 INFO success: bootstrap entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2024-06-27 00:50:39,565 INFO spawned: 'foreman' with pid 602
2024-06-27 00:50:39,566 INFO success: foreman entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2024-06-27 00:50:39,592 INFO exited: bootstrap (exit status 0; expected)
2024-06-27 00:50:40,594 INFO success: stdout entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
bootstrap stdout | DATABASE_HOST=postgresql.database
bootstrap stdout | 
foreman stderr | /app/vendor/bundle/ruby/3.2.0/gems/gmail_xoauth-0.4.2/lib/gmail_xoauth/imap_xoauth_authenticator.rb:31: warning: Net::IMAP.add_authenticator is deprecated.  Use Net::IMAP::SASL.add_authenticator instead.
foreman stderr | 
foreman stderr | /app/vendor/bundle/ruby/3.2.0/gems/gmail_xoauth-0.4.2/lib/gmail_xoauth/imap_xoauth2_authenticator.rb:24: warning: Net::IMAP.add_authenticator is deprecated.  Use Net::IMAP::SASL.add_authenticator instead.
foreman stderr | 
foreman stderr | Database 'huginn' already exists
foreman stderr | 
foreman stderr | /app/vendor/bundle/ruby/3.2.0/gems/gmail_xoauth-0.4.2/lib/gmail_xoauth/imap_xoauth_authenticator.rb:31: warning: Net::IMAP.add_authenticator is deprecated.  Use Net::IMAP::SASL.add_authenticator instead.
foreman stderr | 
foreman stderr | /app/vendor/bundle/ruby/3.2.0/gems/gmail_xoauth-0.4.2/lib/gmail_xoauth/imap_xoauth2_authenticator.rb:24: warning: Net::IMAP.add_authenticator is deprecated.  Use Net::IMAP::SASL.add_authenticator instead.
foreman stderr | 
foreman stderr | /app/vendor/bundle/ruby/3.2.0/gems/gmail_xoauth-0.4.2/lib/gmail_xoauth/imap_xoauth_authenticator.rb:31: warning: Net::IMAP.add_authenticator is deprecated.  Use Net::IMAP::SASL.add_authenticator instead.
foreman stderr | 
foreman stderr | /app/vendor/bundle/ruby/3.2.0/gems/gmail_xoauth-0.4.2/lib/gmail_xoauth/imap_xoauth2_authenticator.rb:24: warning: Net::IMAP.add_authenticator is deprecated.  Use Net::IMAP::SASL.add_authenticator instead.
foreman stderr | 
foreman stdout | At least one User already exists, not seeding.
foreman stdout | 
foreman stdout | 00:50:53 web.1  | started with pid 609
foreman stdout | 
foreman stdout | 00:50:53 jobs.1 | started with pid 610
foreman stdout | 
foreman stdout | 00:50:56 web.1  | /app/vendor/bundle/ruby/3.2.0/gems/gmail_xoauth-0.4.2/lib/gmail_xoauth/imap_xoauth_authenticator.rb:31: warning: Net::IMAP.add_authenticator is deprecated.  Use Net::IMAP::SASL.add_authenticator instead.
foreman stdout | 
foreman stdout | 00:50:56 web.1  | /app/vendor/bundle/ruby/3.2.0/gems/gmail_xoauth-0.4.2/lib/gmail_xoauth/imap_xoauth2_authenticator.rb:24: warning: Net::IMAP.add_authenticator is deprecated.  Use Net::IMAP::SASL.add_authenticator instead.
foreman stdout | 
foreman stdout | 00:50:56 jobs.1 | /app/vendor/bundle/ruby/3.2.0/gems/gmail_xoauth-0.4.2/lib/gmail_xoauth/imap_xoauth_authenticator.rb:31: warning: Net::IMAP.add_authenticator is deprecated.  Use Net::IMAP::SASL.add_authenticator instead.
foreman stdout | 
foreman stdout | 00:50:56 jobs.1 | /app/vendor/bundle/ruby/3.2.0/gems/gmail_xoauth-0.4.2/lib/gmail_xoauth/imap_xoauth2_authenticator.rb:24: warning: Net::IMAP.add_authenticator is deprecated.  Use Net::IMAP::SASL.add_authenticator instead.
foreman stdout | 
foreman stdout | 00:50:57 web.1  | => Booting Unicorn
foreman stdout | 00:50:57 web.1  | => Rails 6.1.7.7 application starting in production http://0.0.0.0:3000
foreman stdout | 
foreman stdout | 00:50:57 web.1  | => Run `bin/rails server --help` for more startup options
foreman stdout | 
foreman stdout | 00:50:58 web.1  | I, [2024-06-26T17:50:58.816548 #609]  INFO -- : listening on addr=0.0.0.0:3000 fd=7
foreman stdout | 
foreman stdout | 00:50:58 web.1  | I, [2024-06-26T17:50:58.858416 #624]  INFO -- : worker=0 ready
foreman stdout | 
foreman stdout | 00:50:58 web.1  | I, [2024-06-26T17:50:58.859552 #609]  INFO -- : master process ready
foreman stdout | 
foreman stdout | 00:50:58 web.1  | I, [2024-06-26T17:50:58.863665 #626]  INFO -- : worker=1 ready
foreman stdout | 
foreman stdout | 00:50:58 jobs.1 | Starting HuginnScheduler
foreman stdout | 
foreman stdout | 00:50:59 jobs.1 | Starting DelayedJobWorker
foreman stdout | 
foreman stdout | 00:50:59 jobs.1 | I, [2024-06-26T17:50:59.081058 #610]  INFO -- : 2024-06-26T17:50:59-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Starting job worker
foreman stdout | 
foreman stdout | 00:51:00 jobs.1 | Queuing schedule for every_1m
foreman stdout | 
foreman stdout | 00:51:00 jobs.1 | I, [2024-06-26T17:51:00.212090 #610]  INFO -- : [ActiveJob] Enqueued AgentRunScheduleJob (Job ID: 7773011d-6318-4c4d-97ca-749912b289a3) to DelayedJob(default) with arguments: "every_1m"
foreman stdout | 
foreman stdout | 00:51:09 jobs.1 | I, [2024-06-26T17:51:09.116948 #610]  INFO -- : 2024-06-26T17:51:09-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentRunScheduleJob [7773011d-6318-4c4d-97ca-749912b289a3] from DelayedJob(default) with arguments: ["every_1m"] (id=91541) (queue=default) RUNNING
foreman stdout | 
foreman stdout | 00:51:09 jobs.1 | I, [2024-06-26T17:51:09.121464 #610]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [7773011d-6318-4c4d-97ca-749912b289a3] Performing AgentRunScheduleJob (Job ID: 7773011d-6318-4c4d-97ca-749912b289a3) from DelayedJob(default) enqueued at 2024-06-27T00:51:00Z with arguments: "every_1m"
foreman stdout | 
foreman stdout | 00:51:09 jobs.1 | I, [2024-06-26T17:51:09.124905 #610]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [7773011d-6318-4c4d-97ca-749912b289a3] Performed AgentRunScheduleJob (Job ID: 7773011d-6318-4c4d-97ca-749912b289a3) from DelayedJob(default) in 3.23ms
foreman stdout | 
foreman stdout | 00:51:09 jobs.1 | I, [2024-06-26T17:51:09.136320 #610]  INFO -- : 2024-06-26T17:51:09-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentRunScheduleJob [7773011d-6318-4c4d-97ca-749912b289a3] from DelayedJob(default) with arguments: ["every_1m"] (id=91541) (queue=default) COMPLETED after 0.0192
foreman stdout | 
foreman stdout | 00:51:09 jobs.1 | I, [2024-06-26T17:51:09.138023 #610]  INFO -- : 2024-06-26T17:51:09-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] 1 jobs processed at 20.6231 j/s, 0 failed
foreman stdout | 
foreman stdout | 00:51:20 web.1  | I, [2024-06-26T17:51:20.140558 #624]  INFO -- : [0d767920-b2f1-4ac8-ac86-da9fa6f2c3f0] Started GET "/agents" for 10.0.0.61 at 2024-06-26 17:51:20 -0700
foreman stdout | 
foreman stdout | 00:51:20 web.1  | I, [2024-06-26T17:51:20.150041 #624]  INFO -- : [0d767920-b2f1-4ac8-ac86-da9fa6f2c3f0] Processing by AgentsController#index as HTML
foreman stdout | 
foreman stdout | 00:51:20 web.1  | I, [2024-06-26T17:51:20.593051 #624]  INFO -- : [0d767920-b2f1-4ac8-ac86-da9fa6f2c3f0]   Rendered agents/index.html.erb within layouts/application (Duration: 245.8ms | Allocations: 65507)
foreman stdout | 
foreman stdout | 00:51:20 web.1  | I, [2024-06-26T17:51:20.607978 #624]  INFO -- : [0d767920-b2f1-4ac8-ac86-da9fa6f2c3f0]   Rendered layout layouts/application.html.erb (Duration: 261.0ms | Allocations: 71121)
foreman stdout | 
foreman stdout | 00:51:20 web.1  | I, [2024-06-26T17:51:20.608547 #624]  INFO -- : [0d767920-b2f1-4ac8-ac86-da9fa6f2c3f0] Completed 200 OK in 458ms (Views: 249.3ms | ActiveRecord: 36.8ms | Allocations: 93407)
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.161319 #624]  INFO -- : [c6f992cc-cbf8-4d3a-ba0a-ff5803a36049] Started POST "/agents/17/run?return=%2Fagents" for 10.0.0.61 at 2024-06-26 17:51:24 -0700
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.162414 #624]  INFO -- : [c6f992cc-cbf8-4d3a-ba0a-ff5803a36049] Processing by AgentsController#run as HTML
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.162534 #624]  INFO -- : [c6f992cc-cbf8-4d3a-ba0a-ff5803a36049]   Parameters: {"authenticity_token"=>"[FILTERED]", "return"=>"/agents", "id"=>"17"}
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.214983 #624]  INFO -- : [c6f992cc-cbf8-4d3a-ba0a-ff5803a36049] [ActiveJob] Enqueued AgentCheckJob (Job ID: ed8d248f-d280-4b4e-9151-8c37e0ac238a) to DelayedJob(default) with arguments: 17
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.216039 #624]  INFO -- : [c6f992cc-cbf8-4d3a-ba0a-ff5803a36049] Redirected to https://huginn.seanomik.net/agents
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.216245 #624]  INFO -- : [c6f992cc-cbf8-4d3a-ba0a-ff5803a36049] Completed 302 Found in 54ms (ActiveRecord: 29.1ms | Allocations: 7692)
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.382756 #624]  INFO -- : [c5869971-201c-4ae7-82d6-2e3d8784793a] Started GET "/agents" for 10.0.0.61 at 2024-06-26 17:51:24 -0700
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.384034 #624]  INFO -- : [c5869971-201c-4ae7-82d6-2e3d8784793a] Processing by AgentsController#index as HTML
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.419442 #624]  INFO -- : [c5869971-201c-4ae7-82d6-2e3d8784793a]   Rendered agents/index.html.erb within layouts/application (Duration: 29.0ms | Allocations: 10084)
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.425859 #624]  INFO -- : [c5869971-201c-4ae7-82d6-2e3d8784793a]   Rendered layout layouts/application.html.erb (Duration: 35.4ms | Allocations: 12240)
foreman stdout | 
foreman stdout | 00:51:24 web.1  | I, [2024-06-26T17:51:24.426242 #624]  INFO -- : [c5869971-201c-4ae7-82d6-2e3d8784793a] Completed 200 OK in 42ms (Views: 31.3ms | ActiveRecord: 5.3ms | Allocations: 13337)
foreman stdout | 
foreman stdout | 00:51:29 jobs.1 | I, [2024-06-26T17:51:29.164777 #610]  INFO -- : 2024-06-26T17:51:29-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentCheckJob [ed8d248f-d280-4b4e-9151-8c37e0ac238a] from DelayedJob(default) with arguments: [17] (id=91542) (queue=default) RUNNING
foreman stdout | 
foreman stdout | 00:51:29 jobs.1 | I, [2024-06-26T17:51:29.165478 #610]  INFO -- : [ActiveJob] [AgentCheckJob] [ed8d248f-d280-4b4e-9151-8c37e0ac238a] Performing AgentCheckJob (Job ID: ed8d248f-d280-4b4e-9151-8c37e0ac238a) from DelayedJob(default) enqueued at 2024-06-27T00:51:24Z with arguments: 17
foreman stdout | 
foreman stdout | 00:51:29 jobs.1 | I, [2024-06-26T17:51:29.324987 #610]  INFO -- : [ActiveJob] [AgentCheckJob] [ed8d248f-d280-4b4e-9151-8c37e0ac238a] Performed AgentCheckJob (Job ID: ed8d248f-d280-4b4e-9151-8c37e0ac238a) from DelayedJob(default) in 159.15ms
foreman stdout | 
foreman stdout | 00:51:29 jobs.1 | I, [2024-06-26T17:51:29.338051 #610]  INFO -- : 2024-06-26T17:51:29-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentCheckJob [ed8d248f-d280-4b4e-9151-8c37e0ac238a] from DelayedJob(default) with arguments: [17] (id=91542) (queue=default) COMPLETED after 0.1731
foreman stdout | 
foreman stdout | 00:51:29 jobs.1 | I, [2024-06-26T17:51:29.340146 #610]  INFO -- : 2024-06-26T17:51:29-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] 1 jobs processed at 5.0717 j/s, 0 failed
foreman stdout | 
foreman stdout | 00:51:39 web.1  | I, [2024-06-26T17:51:39.161785 #624]  INFO -- : [c88b5de3-a7d7-4d49-a2df-242841d9f959] Started GET "/agents" for 10.0.0.61 at 2024-06-26 17:51:39 -0700
foreman stdout | 
foreman stdout | 00:51:39 web.1  | I, [2024-06-26T17:51:39.162771 #624]  INFO -- : [c88b5de3-a7d7-4d49-a2df-242841d9f959] Processing by AgentsController#index as HTML
foreman stdout | 
foreman stdout | 00:51:39 web.1  | I, [2024-06-26T17:51:39.193871 #624]  INFO -- : [c88b5de3-a7d7-4d49-a2df-242841d9f959]   Rendered agents/index.html.erb within layouts/application (Duration: 26.3ms | Allocations: 10078)
foreman stdout | 
foreman stdout | 00:51:39 web.1  | I, [2024-06-26T17:51:39.199655 #624]  INFO -- : [c88b5de3-a7d7-4d49-a2df-242841d9f959]   Rendered layout layouts/application.html.erb (Duration: 32.1ms | Allocations: 12198)
foreman stdout | 
foreman stdout | 00:51:39 web.1  | I, [2024-06-26T17:51:39.200024 #624]  INFO -- : [c88b5de3-a7d7-4d49-a2df-242841d9f959] Completed 200 OK in 37ms (Views: 28.0ms | ActiveRecord: 5.1ms | Allocations: 13256)
foreman stdout | 
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.079756 #624]  INFO -- : [ef96d5a3-c3c0-41a4-9778-144a15926c9c] Started POST "/agents/17/run?return=%2Fagents" for 10.0.0.61 at 2024-06-26 17:51:46 -0700
foreman stdout | 
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.081068 #624]  INFO -- : [ef96d5a3-c3c0-41a4-9778-144a15926c9c] Processing by AgentsController#run as HTML
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.081149 #624]  INFO -- : [ef96d5a3-c3c0-41a4-9778-144a15926c9c]   Parameters: {"authenticity_token"=>"[FILTERED]", "return"=>"/agents", "id"=>"17"}
foreman stdout | 
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.115596 #624]  INFO -- : [ef96d5a3-c3c0-41a4-9778-144a15926c9c] [ActiveJob] Enqueued AgentCheckJob (Job ID: 01ded24d-88d7-44cf-99d0-aa28aa0085d0) to DelayedJob(default) with arguments: 17
foreman stdout | 
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.116399 #624]  INFO -- : [ef96d5a3-c3c0-41a4-9778-144a15926c9c] Redirected to https://huginn.seanomik.net/agents
foreman stdout | 
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.116687 #624]  INFO -- : [ef96d5a3-c3c0-41a4-9778-144a15926c9c] Completed 302 Found in 35ms (ActiveRecord: 26.2ms | Allocations: 1737)
foreman stdout | 
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.278307 #624]  INFO -- : [a55cc65c-75ff-450d-837c-8887a2f28823] Started GET "/agents" for 10.0.0.61 at 2024-06-26 17:51:46 -0700
foreman stdout | 
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.278892 #624]  INFO -- : [a55cc65c-75ff-450d-837c-8887a2f28823] Processing by AgentsController#index as HTML
foreman stdout | 
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.307789 #624]  INFO -- : [a55cc65c-75ff-450d-837c-8887a2f28823]   Rendered agents/index.html.erb within layouts/application (Duration: 25.4ms | Allocations: 10074)
foreman stdout | 
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.313140 #624]  INFO -- : [a55cc65c-75ff-450d-837c-8887a2f28823]   Rendered layout layouts/application.html.erb (Duration: 30.9ms | Allocations: 12221)
foreman stdout | 
foreman stdout | 00:51:46 web.1  | I, [2024-06-26T17:51:46.313419 #624]  INFO -- : [a55cc65c-75ff-450d-837c-8887a2f28823] Completed 200 OK in 34ms (Views: 26.4ms | ActiveRecord: 5.3ms | Allocations: 13285)
foreman stdout | 
foreman stdout | 00:51:49 jobs.1 | I, [2024-06-26T17:51:49.370603 #610]  INFO -- : 2024-06-26T17:51:49-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentCheckJob [01ded24d-88d7-44cf-99d0-aa28aa0085d0] from DelayedJob(default) with arguments: [17] (id=91543) (queue=default) RUNNING
foreman stdout | 
foreman stdout | 00:51:49 jobs.1 | I, [2024-06-26T17:51:49.371257 #610]  INFO -- : [ActiveJob] [AgentCheckJob] [01ded24d-88d7-44cf-99d0-aa28aa0085d0] Performing AgentCheckJob (Job ID: 01ded24d-88d7-44cf-99d0-aa28aa0085d0) from DelayedJob(default) enqueued at 2024-06-27T00:51:46Z with arguments: 17
foreman stdout | 
foreman stdout | 00:51:49 jobs.1 | I, [2024-06-26T17:51:49.397001 #610]  INFO -- : [ActiveJob] [AgentCheckJob] [01ded24d-88d7-44cf-99d0-aa28aa0085d0] Performed AgentCheckJob (Job ID: 01ded24d-88d7-44cf-99d0-aa28aa0085d0) from DelayedJob(default) in 25.5ms
foreman stdout | 
foreman stdout | 00:51:49 jobs.1 | I, [2024-06-26T17:51:49.408382 #610]  INFO -- : 2024-06-26T17:51:49-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentCheckJob [01ded24d-88d7-44cf-99d0-aa28aa0085d0] from DelayedJob(default) with arguments: [17] (id=91543) (queue=default) COMPLETED after 0.0377
foreman stdout | 
foreman stdout | 00:51:49 jobs.1 | I, [2024-06-26T17:51:49.409909 #610]  INFO -- : 2024-06-26T17:51:49-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] 1 jobs processed at 15.6123 j/s, 0 failed
foreman stdout | 
foreman stdout | 00:51:59 jobs.1 | Queuing event propagation
foreman stdout | 
foreman stdout | 00:51:59 jobs.1 | I, [2024-06-26T17:51:59.107071 #610]  INFO -- : [ActiveJob] Enqueued AgentPropagateJob (Job ID: 2e20dfa5-2fef-4f12-b514-b73e769b1687) to DelayedJob(propagation)
foreman stdout | 
foreman stdout | 00:51:59 jobs.1 | I, [2024-06-26T17:51:59.427367 #610]  INFO -- : 2024-06-26T17:51:59-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentPropagateJob [2e20dfa5-2fef-4f12-b514-b73e769b1687] from DelayedJob(propagation) with arguments: [] (id=91544) (queue=propagation) RUNNING
foreman stdout | 
foreman stdout | 00:51:59 jobs.1 | I, [2024-06-26T17:51:59.428051 #610]  INFO -- : [ActiveJob] [AgentPropagateJob] [2e20dfa5-2fef-4f12-b514-b73e769b1687] Performing AgentPropagateJob (Job ID: 2e20dfa5-2fef-4f12-b514-b73e769b1687) from DelayedJob(propagation) enqueued at 2024-06-27T00:51:59Z
foreman stdout | 
foreman stdout | 00:51:59 jobs.1 | I, [2024-06-26T17:51:59.432847 #610]  INFO -- : [ActiveJob] [AgentPropagateJob] [2e20dfa5-2fef-4f12-b514-b73e769b1687] Performed AgentPropagateJob (Job ID: 2e20dfa5-2fef-4f12-b514-b73e769b1687) from DelayedJob(propagation) in 4.52ms
foreman stdout | 
foreman stdout | 00:51:59 jobs.1 | I, [2024-06-26T17:51:59.443288 #610]  INFO -- : 2024-06-26T17:51:59-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentPropagateJob [2e20dfa5-2fef-4f12-b514-b73e769b1687] from DelayedJob(propagation) with arguments: [] (id=91544) (queue=propagation) COMPLETED after 0.0158
foreman stdout | 
foreman stdout | 00:51:59 jobs.1 | I, [2024-06-26T17:51:59.445259 #610]  INFO -- : 2024-06-26T17:51:59-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] 1 jobs processed at 29.7324 j/s, 0 failed
foreman stdout | 
foreman stdout | 00:52:00 jobs.1 | Queuing schedule for every_2m
foreman stdout | 
foreman stdout | 00:52:00 jobs.1 | I, [2024-06-26T17:52:00.267553 #610]  INFO -- : [ActiveJob] Enqueued AgentRunScheduleJob (Job ID: 1fbf8a9f-3cc9-40b6-b7ba-faaa75af2097) to DelayedJob(default) with arguments: "every_2m"
foreman stdout | 
foreman stdout | 00:52:00 jobs.1 | Queuing schedule for every_1m
foreman stdout | 
foreman stdout | 00:52:00 jobs.1 | I, [2024-06-26T17:52:00.288914 #610]  INFO -- : [ActiveJob] Enqueued AgentRunScheduleJob (Job ID: 5d9f5df2-2440-4efe-b21d-228cac9bf837) to DelayedJob(default) with arguments: "every_1m"
foreman stdout | 
foreman stdout | 00:52:09 jobs.1 | I, [2024-06-26T17:52:09.465445 #610]  INFO -- : 2024-06-26T17:52:09-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentRunScheduleJob [1fbf8a9f-3cc9-40b6-b7ba-faaa75af2097] from DelayedJob(default) with arguments: ["every_2m"] (id=91545) (queue=default) RUNNING
foreman stdout | 
foreman stdout | 00:52:09 jobs.1 | I, [2024-06-26T17:52:09.466038 #610]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [1fbf8a9f-3cc9-40b6-b7ba-faaa75af2097] Performing AgentRunScheduleJob (Job ID: 1fbf8a9f-3cc9-40b6-b7ba-faaa75af2097) from DelayedJob(default) enqueued at 2024-06-27T00:52:00Z with arguments: "every_2m"
foreman stdout | 
foreman stdout | 00:52:09 jobs.1 | I, [2024-06-26T17:52:09.467436 #610]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [1fbf8a9f-3cc9-40b6-b7ba-faaa75af2097] Performed AgentRunScheduleJob (Job ID: 1fbf8a9f-3cc9-40b6-b7ba-faaa75af2097) from DelayedJob(default) in 1.25ms
foreman stdout | 
foreman stdout | 00:52:09 jobs.1 | I, [2024-06-26T17:52:09.480014 #610]  INFO -- : 2024-06-26T17:52:09-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentRunScheduleJob [1fbf8a9f-3cc9-40b6-b7ba-faaa75af2097] from DelayedJob(default) with arguments: ["every_2m"] (id=91545) (queue=default) COMPLETED after 0.0144
foreman stdout | 
foreman stdout | 00:52:09 jobs.1 | I, [2024-06-26T17:52:09.491329 #610]  INFO -- : 2024-06-26T17:52:09-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentRunScheduleJob [5d9f5df2-2440-4efe-b21d-228cac9bf837] from DelayedJob(default) with arguments: ["every_1m"] (id=91546) (queue=default) RUNNING
foreman stdout | 
foreman stdout | 00:52:09 jobs.1 | I, [2024-06-26T17:52:09.491673 #610]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [5d9f5df2-2440-4efe-b21d-228cac9bf837] Performing AgentRunScheduleJob (Job ID: 5d9f5df2-2440-4efe-b21d-228cac9bf837) from DelayedJob(default) enqueued at 2024-06-27T00:52:00Z with arguments: "every_1m"
foreman stdout | 
foreman stdout | 00:52:09 jobs.1 | I, [2024-06-26T17:52:09.492773 #610]  INFO -- : [ActiveJob] [AgentRunScheduleJob] [5d9f5df2-2440-4efe-b21d-228cac9bf837] Performed AgentRunScheduleJob (Job ID: 5d9f5df2-2440-4efe-b21d-228cac9bf837) from DelayedJob(default) in 0.88ms
foreman stdout | 
foreman stdout | 00:52:09 jobs.1 | I, [2024-06-26T17:52:09.505010 #610]  INFO -- : 2024-06-26T17:52:09-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentRunScheduleJob [5d9f5df2-2440-4efe-b21d-228cac9bf837] from DelayedJob(default) with arguments: ["every_1m"] (id=91546) (queue=default) COMPLETED after 0.0136
foreman stdout | 
foreman stdout | 00:52:09 jobs.1 | I, [2024-06-26T17:52:09.506547 #610]  INFO -- : 2024-06-26T17:52:09-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] 2 jobs processed at 34.0508 j/s, 0 failed
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.599958 #624]  INFO -- : [5a9a2b49-4335-4fef-a5d6-2213873cb21b] Started POST "/agents/17/run?return=%2Fagents" for 10.0.0.61 at 2024-06-26 17:52:40 -0700
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.601028 #624]  INFO -- : [5a9a2b49-4335-4fef-a5d6-2213873cb21b] Processing by AgentsController#run as HTML
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.601119 #624]  INFO -- : [5a9a2b49-4335-4fef-a5d6-2213873cb21b]   Parameters: {"authenticity_token"=>"[FILTERED]", "return"=>"/agents", "id"=>"17"}
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.635373 #624]  INFO -- : [5a9a2b49-4335-4fef-a5d6-2213873cb21b] [ActiveJob] Enqueued AgentCheckJob (Job ID: e73f4689-5b6e-4857-bc2b-3c10980fe5a6) to DelayedJob(default) with arguments: 17
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.635994 #624]  INFO -- : [5a9a2b49-4335-4fef-a5d6-2213873cb21b] Redirected to https://huginn.seanomik.net/agents
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.636171 #624]  INFO -- : [5a9a2b49-4335-4fef-a5d6-2213873cb21b] Completed 302 Found in 35ms (ActiveRecord: 27.5ms | Allocations: 1739)
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.802997 #624]  INFO -- : [48633bad-87ad-4683-b926-3c4608d10fa2] Started GET "/agents" for 10.0.0.61 at 2024-06-26 17:52:40 -0700
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.803993 #624]  INFO -- : [48633bad-87ad-4683-b926-3c4608d10fa2] Processing by AgentsController#index as HTML
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.836130 #624]  INFO -- : [48633bad-87ad-4683-b926-3c4608d10fa2]   Rendered agents/index.html.erb within layouts/application (Duration: 27.8ms | Allocations: 10074)
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.841678 #624]  INFO -- : [48633bad-87ad-4683-b926-3c4608d10fa2]   Rendered layout layouts/application.html.erb (Duration: 33.4ms | Allocations: 12225)
foreman stdout | 
foreman stdout | 00:52:40 web.1  | I, [2024-06-26T17:52:40.842023 #624]  INFO -- : [48633bad-87ad-4683-b926-3c4608d10fa2] Completed 200 OK in 38ms (Views: 28.8ms | ActiveRecord: 5.5ms | Allocations: 13300)
foreman stdout | 
foreman stdout | 00:52:49 jobs.1 | I, [2024-06-26T17:52:49.532889 #610]  INFO -- : 2024-06-26T17:52:49-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentCheckJob [e73f4689-5b6e-4857-bc2b-3c10980fe5a6] from DelayedJob(default) with arguments: [17] (id=91547) (queue=default) RUNNING
foreman stdout | 
foreman stdout | 00:52:49 jobs.1 | I, [2024-06-26T17:52:49.533602 #610]  INFO -- : [ActiveJob] [AgentCheckJob] [e73f4689-5b6e-4857-bc2b-3c10980fe5a6] Performing AgentCheckJob (Job ID: e73f4689-5b6e-4857-bc2b-3c10980fe5a6) from DelayedJob(default) enqueued at 2024-06-27T00:52:40Z with arguments: 17
foreman stdout | 
foreman stdout | 00:52:49 jobs.1 | I, [2024-06-26T17:52:49.568591 #610]  INFO -- : [ActiveJob] [AgentCheckJob] [e73f4689-5b6e-4857-bc2b-3c10980fe5a6] Performed AgentCheckJob (Job ID: e73f4689-5b6e-4857-bc2b-3c10980fe5a6) from DelayedJob(default) in 34.67ms
foreman stdout | 
foreman stdout | 00:52:49 jobs.1 | I, [2024-06-26T17:52:49.581178 #610]  INFO -- : 2024-06-26T17:52:49-0700: [Worker(host:huginn-77d4b4bf6-h7f4h pid:610)] Job AgentCheckJob [e73f4689-5b6e-4857-bc2b-3c10980fe5a6] from DelayedJob(default) with arguments: [17] (id=91547) (queue=default) COMPLETED after 0.0481

I'm pretty stumped on this, not sure what else to look at. If there's a way to enable debug logs, maybe those could help.

@pawelabrams
Copy link

Sorry to bump old threads, but I really like this software and would like to help in any way:
did you manage to work this out? Maybe the e-mail agent doesn't receive any events it can use as the e-mail contents? Do you see any queue of events to send before you click Action > Run?

Mind you, a successful run will empty the queue, so if the agent thinks it succeeded, you may not have anything to send immediately after a silently-failed run.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants