Discourse Automation Plugin failing with an 'internal server error'

[gassim (Al-Gassim Sharaf Addin)]

Before the latest update, there was an automation using the Automation Plugin that does the following (which was tested and it was working successfully without any changes):

• Script: Send pms
• When: “User added to group”
• Tracked group: “a group that requires group owner to ‘approve requests’ first”
• Script Options: one PM (tested and it worked successfully).

Currently, on version: 3.5.0.beta3-dev(231e9ca99a) it now shows “internal server error” when attempting to approve the users.

The following is the error that appears:

PG::NotNullViolation (ERROR:  null value in column "total_time" of relation "discourse_automation_stats" violates not-null constraint
DETAIL:  Failing row contains (18, 8, 2025-04-10, 2025-04-10 07:34:42.740189, null, null, null, null, 1).
)
lib/mini_sql_multisite_connection.rb:109:in `run'
lib/plugin/instance.rb:609:in `block in on'
lib/discourse_event.rb:12:in `block in trigger'
lib/discourse_event.rb:12:in `trigger'
app/models/group.rb:869:in `trigger_user_added_event'
app/models/group.rb:838:in `add'
app/controllers/groups_controller.rb:502:in `block in handle_membership_request'
app/controllers/groups_controller.rb:500:in `handle_membership_request'
app/controllers/application_controller.rb:427:in `block in with_resolved_locale'
app/controllers/application_controller.rb:427:in `with_resolved_locale'
lib/middleware/omniauth_bypass_middleware.rb:35:in `call'
lib/content_security_policy/middleware.rb:12:in `call'
lib/middleware/anonymous_cache.rb:410:in `call'
lib/middleware/csp_script_nonce_injector.rb:12:in `call'
config/initializers/008-rack-cors.rb:26:in `call'
lib/middleware/default_headers.rb:13:in `call'
config/initializers/100-quiet_logger.rb:20:in `call'
config/initializers/100-silence_logger.rb:29:in `call'
lib/middleware/enforce_hostname.rb:24:in `call'
lib/middleware/processing_request.rb:12:in `call'
lib/middleware/request_tracker.rb:385:in `call'

I suspect this has to do with the new changes to the discourse_automation_stats table mentioned here:

@sam

@sam
FEATURE: Add automation statistics tracking to Automation by SamSaffron · Pull Request #31921 · discourse/discourse · GitHub

Thanks!

[joffreyjaffeux]

Thanks for the report. I think you have an other error, but the stat code we added is hiding it.

That should fix it:

FIX: logs time even when automation raises

And then we should be able to see the actual error.

[gassim (Al-Gassim Sharaf Addin)]

Thanks!

@joffreyjaffeux

And then we should be able to see the actual error.

Does this mean after the update, I need to get the actual error?

[joffreyjaffeux]

Yes please, even though I suspect from here, you might be able to fix it yourself.

[gassim (Al-Gassim Sharaf Addin)]

Thank you for your patience!

I’m getting another generic issue {"status":422,"error":"Unprocessable Entity"}. Please see screenshot after I click on ‘approve’:

The payload is form data (application/x-www-form-urlencoded; charset=UTF-8):
user_id=10127&accept=true

@joffreyjaffeux

I suspect from here, you might be able to fix it yourself.

Thanks! Though I’m not sure why it’s saying ‘unprocessable entity’, any tip?

[joffreyjaffeux]

Im sorry but that doesnt look like automation.

Can you click on response in the first screenshot please?

[gassim (Al-Gassim Sharaf Addin)]

Hey
Thanks! It’s the same response…

@gassim

{“status”:422,“error”:“Unprocessable Entity”}

I did further investigation and realized that…

Two things have already changed:

1. The user is being added to the group successfully
2. The automated message is being sent
3. This error “unprocessable entity” doesn’t appear when the admin account is used to accept the group request, but it’s appearing to a non-admin group owner user (even with 1 and 2 happening successfully now for both admin/non-admin).

It seems now we are talking about a new issue (given those above are now working but only that the result isn’t clear when it’s blocked with this new issue)…

even the server error logs changed:

info log

ActiveRecord::RecordNotSaved (Something has gone wrong. Perhaps this topic was closed or deleted while you were looking at it?)
lib/post_creator.rb:238:in `create!'
app/controllers/groups_controller.rb:523:in `handle_membership_request'
app/controllers/application_controller.rb:427:in `block in with_resolved_locale'
app/controllers/application_controller.rb:427:in `with_resolved_locale'
lib/middleware/omniauth_bypass_middleware.rb:35:in `call'
lib/content_security_policy/middleware.rb:12:in `call'
lib/middleware/anonymous_cache.rb:410:in `call'
lib/middleware/csp_script_nonce_injector.rb:12:in `call'
config/initializers/008-rack-cors.rb:26:in `call'
lib/middleware/default_headers.rb:13:in `call'
config/initializers/100-quiet_logger.rb:20:in `call'
config/initializers/100-silence_logger.rb:29:in `call'
lib/middleware/enforce_hostname.rb:24:in `call'
lib/middleware/processing_request.rb:12:in `call'
lib/middleware/request_tracker.rb:385:in `call'

backtrace log

lib/post_creator.rb:238:in `create!'
app/controllers/groups_controller.rb:523:in `handle_membership_request'
actionpack (7.2.2.1) lib/action_controller/metal/basic_implicit_render.rb:8:in `send_action'
actionpack (7.2.2.1) lib/abstract_controller/base.rb:226:in `process_action'
actionpack (7.2.2.1) lib/action_controller/metal/rendering.rb:193:in `process_action'
actionpack (7.2.2.1) lib/abstract_controller/callbacks.rb:261:in `block in process_action'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:121:in `block in run_callbacks'
app/controllers/application_controller.rb:427:in `block in with_resolved_locale'
i18n (1.14.7) lib/i18n.rb:353:in `with_locale'
app/controllers/application_controller.rb:427:in `with_resolved_locale'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:130:in `block in run_callbacks'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:141:in `run_callbacks'
actionpack (7.2.2.1) lib/abstract_controller/callbacks.rb:260:in `process_action'
actionpack (7.2.2.1) lib/action_controller/metal/rescue.rb:27:in `process_action'
actionpack (7.2.2.1) lib/action_controller/metal/instrumentation.rb:77:in `block in process_action'
activesupport (7.2.2.1) lib/active_support/notifications.rb:210:in `block in instrument'
activesupport (7.2.2.1) lib/active_support/notifications/instrumenter.rb:58:in `instrument'
activesupport (7.2.2.1) lib/active_support/notifications.rb:210:in `instrument'
actionpack (7.2.2.1) lib/action_controller/metal/instrumentation.rb:76:in `process_action'
actionpack (7.2.2.1) lib/action_controller/metal/params_wrapper.rb:259:in `process_action'
activerecord (7.2.2.1) lib/active_record/railties/controller_runtime.rb:39:in `process_action'
actionpack (7.2.2.1) lib/abstract_controller/base.rb:163:in `process'
actionview (7.2.2.1) lib/action_view/rendering.rb:40:in `process'
rack-mini-profiler (3.3.1) lib/mini_profiler/profiling_methods.rb:89:in `block in profile_method' 
actionpack (7.2.2.1) lib/action_controller/metal.rb:252:in `dispatch'
actionpack (7.2.2.1) lib/action_controller/metal.rb:335:in `dispatch'
actionpack (7.2.2.1) lib/action_dispatch/routing/route_set.rb:67:in `dispatch'
actionpack (7.2.2.1) lib/action_dispatch/routing/route_set.rb:50:in `serve'
actionpack (7.2.2.1) lib/action_dispatch/journey/router.rb:53:in `block in serve'
actionpack (7.2.2.1) lib/action_dispatch/journey/router.rb:133:in `block in find_routes'
actionpack (7.2.2.1) lib/action_dispatch/journey/router.rb:126:in `each'
actionpack (7.2.2.1) lib/action_dispatch/journey/router.rb:126:in `find_routes'
actionpack (7.2.2.1) lib/action_dispatch/journey/router.rb:34:in `serve'
actionpack (7.2.2.1) lib/action_dispatch/routing/route_set.rb:896:in `call'
lib/middleware/omniauth_bypass_middleware.rb:35:in `call'
rack (2.2.13) lib/rack/tempfile_reaper.rb:15:in `call'
rack (2.2.13) lib/rack/conditional_get.rb:40:in `call'
rack (2.2.13) lib/rack/head.rb:12:in `call'
actionpack (7.2.2.1) lib/action_dispatch/http/permissions_policy.rb:38:in `call'
lib/content_security_policy/middleware.rb:12:in `call'
lib/middleware/anonymous_cache.rb:410:in `call'
lib/middleware/csp_script_nonce_injector.rb:12:in `call'
config/initializers/008-rack-cors.rb:26:in `call'
rack (2.2.13) lib/rack/session/abstract/id.rb:266:in `context'
rack (2.2.13) lib/rack/session/abstract/id.rb:260:in `call'
actionpack (7.2.2.1) lib/action_dispatch/middleware/cookies.rb:704:in `call'
actionpack (7.2.2.1) lib/action_dispatch/middleware/callbacks.rb:31:in `block in call'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:101:in `run_callbacks'
actionpack (7.2.2.1) lib/action_dispatch/middleware/callbacks.rb:30:in `call'
actionpack (7.2.2.1) lib/action_dispatch/middleware/debug_exceptions.rb:31:in `call'
actionpack (7.2.2.1) lib/action_dispatch/middleware/show_exceptions.rb:32:in `call'
logster (2.20.1) lib/logster/middleware/reporter.rb:40:in `call'
lib/middleware/default_headers.rb:13:in `call'
railties (7.2.2.1) lib/rails/rack/logger.rb:41:in `call_app'
railties (7.2.2.1) lib/rails/rack/logger.rb:29:in `call'
config/initializers/100-quiet_logger.rb:20:in `call'
config/initializers/100-silence_logger.rb:29:in `call'
actionpack (7.2.2.1) lib/action_dispatch/middleware/request_id.rb:33:in `call'
lib/middleware/enforce_hostname.rb:24:in `call'
rack (2.2.13) lib/rack/method_override.rb:24:in `call'
actionpack (7.2.2.1) lib/action_dispatch/middleware/executor.rb:16:in `call'
rack (2.2.13) lib/rack/sendfile.rb:110:in `call'
rack-mini-profiler (3.3.1) lib/mini_profiler.rb:191:in `call'
lib/middleware/processing_request.rb:12:in `call'
message_bus (4.4.1) lib/message_bus/rack/middleware.rb:60:in `call'
lib/middleware/request_tracker.rb:385:in `call'
actionpack (7.2.2.1) lib/action_dispatch/middleware/remote_ip.rb:96:in `call'
railties (7.2.2.1) lib/rails/engine.rb:535:in `call'
railties (7.2.2.1) lib/rails/railtie.rb:226:in `public_send'
railties (7.2.2.1) lib/rails/railtie.rb:226:in `method_missing'
rack (2.2.13) lib/rack/urlmap.rb:74:in `block in call'
rack (2.2.13) lib/rack/urlmap.rb:58:in `each'
rack (2.2.13) lib/rack/urlmap.rb:58:in `call'
unicorn (6.1.0) lib/unicorn/http_server.rb:634:in `process_client'
unicorn (6.1.0) lib/unicorn/http_server.rb:739:in `worker_loop'
unicorn (6.1.0) lib/unicorn/http_server.rb:547:in `spawn_missing_workers'
unicorn (6.1.0) lib/unicorn/http_server.rb:143:in `start'
unicorn (6.1.0) bin/unicorn:128:in `<top (required)>'
vendor/bundle/ruby/3.3.0/bin/unicorn:25:in `load'
vendor/bundle/ruby/3.3.0/bin/unicorn:25:in `<main>'

env log

hostname	community-app
process_id	913
application_version	6fc5ce968892b980c3db6b19b49683fb38a59e29
HTTP_HOST	meta.discourse.org
REQUEST_URI	/groups/200/handle_membership_request.json
REQUEST_METHOD	PUT
HTTP_USER_AGENT	Mozilla/5.0
HTTP_ACCEPT	/
HTTP_REFERER	https://meta.discourse.org/g/group_name/requests
HTTP_X_FORWARDED_FOR	0.0.0.0
HTTP_X_REAL_IP	0.0.0.0
username	copuxtest
time	7:37 am
params
user_id	5836
accept	true

[joffreyjaffeux]

Im sorry but Im very confused how this is related to the op. You don’t get this error through automation right? This is a direct action you are doing in the admin as far as I can tell.

[gassim (Al-Gassim Sharaf Addin)]

Hi again!
Thank you for spending your time on this one so I think it’s now resolved. Initially, the error only appeared after we activated the automation (first error posted in first post), and then after your fix the error disappeared but the logs showed a different error as explained above.

The errors disappeared after I did the following:

1. Turned off the automation
2. Cleared the browser cache
3. Turned the automation back on

After turning the automation on/off and clearing cache all the errors disappeared. Thank you!

[joffreyjaffeux]

Ok, very surprising, but if it works for you, all good! Thanks for the update.

[gassim (Al-Gassim Sharaf Addin)]

Thank you!