Workers / MiniRacer::ScriptTerminatedError timeouts in /logs

Support
1

For a few months now, we have been seeing these dozens of these warnings in /logs on a daily basis:

Unicorn worker received USR2 signal indicating it is about to timeout, dumping backtrace for main thread

As we usually run on stable, I assumed they would eventually go away when we jumped into the next major version which we did this week. We are now on 3.4.1, but the errors continue.

backtrace 
activesupport-7.2.2.1/lib/active_support/broadcast_logger.rb:130:in `block in warn' 
activesupport-7.2.2.1/lib/active_support/broadcast_logger.rb:231:in `block in dispatch' 
activesupport-7.2.2.1/lib/active_support/broadcast_logger.rb:231:in `each' 
activesupport-7.2.2.1/lib/active_support/broadcast_logger.rb:231:in `dispatch' 
activesupport-7.2.2.1/lib/active_support/broadcast_logger.rb:130:in `warn' 
/var/www/discourse/lib/signal_trap_logger.rb:40:in `public_send' 
/var/www/discourse/lib/signal_trap_logger.rb:40:in `block (2 levels) in ensure_logging_thread_running' 
<internal:kernel>:187:in `loop'
/var/www/discourse/lib/signal_trap_logger.rb:37:in `block in ensure_logging_thread_running'
info 
Unicorn worker received USR2 signal indicating it is about to timeout, dumping backtrace for main thread
config/unicorn.conf.rb:203:in `backtrace'
config/unicorn.conf.rb:203:in `block (2 levels) in reload'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/rack-mini-profiler-3.3.1/lib/patches/db/pg.rb:69:in `exec_params'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/rack-mini-profiler-3.3.1/lib/patches/db/pg.rb:69:in `exec_params'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/postgresql_adapter.rb:894:in `block (2 levels) in exec_no_cache'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract_adapter.rb:1004:in `block in with_raw_connection'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activesupport-7.2.2.1/lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract_adapter.rb:976:in `with_raw_connection'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/postgresql_adapter.rb:893:in `block in exec_no_cache'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activesupport-7.2.2.1/lib/active_support/notifications/instrumenter.rb:58:in `instrument'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract_adapter.rb:1119:in `log'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/postgresql_adapter.rb:892:in `exec_no_cache'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/postgresql_adapter.rb:872:in `execute_and_clear'
/var/www/discourse/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:66:in `internal_exec_query'
/var/www/d...

I’m not sure if they may be related, but we are also seeing two classes of errors (not warnings), intermixed, although less often:

Job exception: terminated

backtrace 
/var/www/discourse/lib/pretty_text.rb:239:in `eval' 
/var/www/discourse/lib/pretty_text.rb:239:in `block in markdown' 
/var/www/discourse/lib/pretty_text.rb:691:in `block in protect' 
/var/www/discourse/lib/pretty_text.rb:691:in `synchronize' 
/var/www/discourse/lib/pretty_text.rb:691:in `protect' 
/var/www/discourse/lib/pretty_text.rb:176:in `markdown' 
/var/www/discourse/lib/pretty_text.rb:302:in `cook' 
/var/www/discourse/app/models/post_analyzer.rb:30:in `cook' 
/var/www/discourse/app/models/post_analyzer.rb:149:in `cooked_stripped' 
/var/www/discourse/app/models/post_analyzer.rb:88:in `raw_mentions' 
/var/www/discourse/app/models/post.rb:310:in `public_send' 
/var/www/discourse/app/models/post.rb:310:in `block (2 levels) in <class:Post>' 
/var/www/discourse/app/services/post_alerter.rb:735:in `extract_mentions' 
/var/www/discourse/app/services/post_alerter.rb:174:in `after_save_post' 
/var/www/discourse/app/jobs/regular/post_alert.rb:10:in `execute' 
/var/www/discourse/app/jobs/base.rb:316:in `block (2 levels) in perform' 
rails_multisite-6.1.0/lib/rails_multisite/connection_management/null_instance.rb:49:in `with_connection'
rails_multisite-6.1.0/lib/rails_multisite/connection_management.rb:21:in `with_connection'
/var/www/discourse/app/jobs/base.rb:303:in `block in perform' 
/var/www/discourse/app/jobs/base.rb:299:in `each' 
/var/www/discourse/app/jobs/base.rb:299:in `perform' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:202:in `execute_job' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:170:in `block (2 levels) in process' 
sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:177:in `block in invoke' 
/var/www/discourse/lib/sidekiq/pausable.rb:132:in `call' 
sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:179:in `block in invoke' 
sidekiq-6.5.12/lib/sidekiq/middleware/chain.rb:182:in `invoke' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:169:in `block in process' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:136:in `block (6 levels) in dispatch' 
sidekiq-6.5.12/lib/sidekiq/job_retry.rb:113:in `local' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:135:in `block (5 levels) in dispatch' 
sidekiq-6.5.12/lib/sidekiq.rb:44:in `block in <module:Sidekiq>' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:131:in `block (4 levels) in dispatch' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:263:in `stats' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:126:in `block (3 levels) in dispatch' 
sidekiq-6.5.12/lib/sidekiq/job_logger.rb:13:in `call' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:125:in `block (2 levels) in dispatch' 
sidekiq-6.5.12/lib/sidekiq/job_retry.rb:80:in `global' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:124:in `block in dispatch' 
sidekiq-6.5.12/lib/sidekiq/job_logger.rb:39:in `prepare' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:123:in `dispatch' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:168:in `process' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:78:in `process_one' 
sidekiq-6.5.12/lib/sidekiq/processor.rb:68:in `run' 
sidekiq-6.5.12/lib/sidekiq/component.rb:8:in `watchdog' 
sidekiq-6.5.12/lib/sidekiq/component.rb:17:in `block in safe_thread
info 
Job exception: terminated

And also,

MiniRacer::ScriptTerminatedError (terminated) lib/pretty_text.rb:239:in eval' lib/pretty_text.rb:239:in block in markdown’ lib/pretty_text.rb:691:in block in protect' lib/pretty_text.rb:691:in syn

backtrace 
lib/pretty_text.rb:239:in `eval'
lib/pretty_text.rb:239:in `block in markdown'
lib/pretty_text.rb:691:in `block in protect'
lib/pretty_text.rb:691:in `synchronize'
lib/pretty_text.rb:691:in `protect'
lib/pretty_text.rb:176:in `markdown'
lib/pretty_text.rb:302:in `cook'
app/models/post_analyzer.rb:30:in `cook'
app/models/post_analyzer.rb:149:in `cooked_stripped'
app/models/post_analyzer.rb:88:in `raw_mentions'
app/models/post.rb:310:in `public_send'
app/models/post.rb:310:in `block (2 levels) in <class:Post>'
lib/validators/post_validator.rb:80:in `max_mention_validator'
lib/validators/post_validator.rb:17:in `validate'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:385:in `block in make_lambda'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:179:in `block in call'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:668:in `block (2 levels) in default_terminator'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:667:in `catch'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:667:in `block in default_terminator'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:180:in `call'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:559:in `block in invoke_before'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:559:in `each'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:559:in `invoke_before'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:109:in `run_callbacks'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:913:in `_run_validate_callbacks'
activemodel (7.2.2.1) lib/active_model/validations.rb:441:in `run_validations!'
activemodel (7.2.2.1) lib/active_model/validations/callbacks.rb:115:in `block in run_validations!'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:110:in `run_callbacks'
activesupport (7.2.2.1) lib/active_support/callbacks.rb:913:in `_run_validation_callbacks'
activemodel (7.2.2.1) lib/active_model/validations/callbacks.rb:115:in `run_validations!'
activemodel (7.2.2.1) lib/active_model/validations.rb:366:in `valid?'
activerecord (7.2.2.1) lib/active_record/validations.rb:71:in `valid?'
activerecord (7.2.2.1) lib/active_record/validations.rb:91:in `perform_validations'
activerecord (7.2.2.1) lib/active_record/validations.rb:48:in `save'
activerecord (7.2.2.1) lib/active_record/transactions.rb:362:in `block in save'
activerecord (7.2.2.1) lib/active_record/transactions.rb:418:in `block (2 levels) in with_transaction_returning_status'
activerecord (7.2.2.1) lib/active_record/connection_adapters/abstract/database_statements.rb:359:in `transaction'
activerecord (7.2.2.1) lib/active_record/transactions.rb:414:in `block in with_transaction_returning_status'
activerecord (7.2.2.1) lib/active_record/connection_adapters/abstract/connection_pool.rb:415:in `with_connection'
activerecord (7.2.2.1) lib/active_record/connection_handling.rb:296:in `with_connection'
activerecord (7.2.2.1) lib/active_record/transactions.rb:410:in `with_transaction_returning_status'
activerecord (7.2.2.1) lib/active_record/transactions.rb:362:in `save'
activerecord (7.2.2.1) lib/active_record/suppressor.rb:52:in `save'
lib/post_revisor.rb:499:in `update_post'
lib/post_revisor.rb:460:in `revise'
lib/post_revisor.rb:454:in `revise_and_create_new_version'
lib/post_revisor.rb:357:in `revise_post'
lib/post_revisor.rb:279:in `block in revise!'
activerecord (7.2.2.1) lib/active_record/connection_adapters/abstract/transaction.rb:616:in `block in within_new_transaction'
activesupport (7.2.2.1) lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
activerecord (7.2.2.1) lib/active_record/connection_adapters/abstract/transaction.rb:613:in `within_new_transaction'
activerecord (7.2.2.1) lib/active_record/connection_adapters/abstract/database_statements.rb:361:in `transaction'
activerecord (7.2.2.1) lib/active_record/transactions.rb:234:in `block in transaction'
activerecord (7.2.2.1) lib/active_record/connection_adapters/abstract/connection_pool.rb:415:in `with_connection'
activerecord (7.2.2.1) lib/active_record/connection_handling.rb:296:in `with_connection'
activerecord (7.2.2.1) lib/active_record/transactions.rb:233:in `transaction'
lib/post_revisor.rb:278:in `revise!'
app/controllers/posts_controller.rb:276:in `update'
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:64:in `call'
rack (2.2.10) lib/rack/tempfile_reaper.rb:15:in `call'
rack (2.2.10) lib/rack/conditional_get.rb:40:in `call'
rack (2.2.10) 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:403:in `call'
lib/middleware/csp_script_nonce_injector.rb:12:in `call'
config/initializers/008-rack-cors.rb:14:in `call'
rack (2.2.10) lib/rack/session/abstract/id.rb:266:in `context'
rack (2.2.10) 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.0) lib/logster/m
info 
MiniRacer::ScriptTerminatedError (terminated)
lib/pretty_text.rb:239:in `eval'
lib/pretty_text.rb:239:in `block in markdown'
lib/pretty_text.rb:691:in `block in protect'
lib/pretty_text.rb:691:in `synchronize'
lib/pretty_text.rb:691:in `protect'
lib/pretty_text.rb:176:in `markdown'
lib/pretty_text.rb:302:in `cook'
app/models/post_analyzer.rb:30:in `cook'
app/models/post_analyzer.rb:149:in `cooked_stripped'
app/models/post_analyzer.rb:88:in `raw_mentions'
app/models/post.rb:310:in `public_send'
app/models/post.rb:310:in `block (2 levels) in <class:Post>'
lib/validators/post_validator.rb:80:in `max_mention_validator'
lib/validators/post_validator.rb:17:in `validate'
lib/post_revisor.rb:499:in `update_post'
lib/post_revisor.rb:460:in `revise'
lib/post_revisor.rb:454:in `revise_and_create_new_version'
lib/post_revisor.rb:357:in `revise_post'
lib/post_revisor.rb:279:in `block in revise!'
lib/post_revisor.rb:278:in `revise!'
app/controllers/posts_controller.rb:276:in `update'
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:64:in `call'
lib/content_security_policy/middleware.rb:12:in `call'
lib/middleware/anonymous_cache.rb:403:in `call'
lib/middleware/csp_script_nonce_injector.rb:12:in `call'
config/initializers/008-rack-cors.rb:14: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'

These may be related with this, but in my case they seem to persist. And, as mentioned there, the logs do seem to get truncated sometimes.

And what all this looks like in /logs:

Screenshot 2025-03-07 at 12.18.50
Screenshot 2025-03-07 at 12.18.502724×734 164 KB

Any clues on what might be causing these? Can I prove any other info?

2 Likes
3

Seeing this same error on our instance when posting/editing/approving a topic with very specific Markdown content. It will load for a while and then throw internal server error.

The image shows a pop-up dialog with the message "Internal Server Error," along with an "OK" button. (Captioned by AI)
The image shows a pop-up dialog with the message "Internal Server Error," along with an "OK" button. (Captioned by AI)785×172 10.2 KB

2 Likes
4

FWIW, we have also seen sporadic reports from users with similar errors when editing some posts (usually quite long, although not close to the limit), where making tiny changes to the text seem to overcome the error (anecdotally: adding another period, replacing a dash, etc). Haven’t been able to find reproducible steps yet as I usually hear about it only when someone found the “magic trick” to it.

1 Like
5

I’ve just noticed these warnings as well. When they start, they may have several recurrences within an hour or so, then stop. Until next time. I’d swear we didn’t have them until a few days ago.

image
image1148×508 131 KB

1 Like
6

Which version are you on, @icaria36 and @Indra? We are on stable, but I’m wondering if this is also happening in tests-passed.

1 Like
7

We are on 3.5.0.beta3-dev (3f353a726b).

8

I think have found something likely related to this and that may provide some more clues to the source of the problem. This gets a bit long-winded, so please bear with me.

I noticed today that I have a couple sidekiq jobs that fail and have been retrying for at least a week with the same error as in the /logs.

Screenshot 2025-04-03 at 17.09.13
Screenshot 2025-04-03 at 17.09.132432×566 204 KB

On the console, if I retry to rebake that specific post, it takes a long time (near 30s) and eventually ends in

error 
lib/pretty_text.rb:239:in `eval': terminated (MiniRacer::ScriptTerminatedError)
	from lib/pretty_text.rb:239:in `block in markdown'
	from lib/pretty_text.rb:691:in `block in protect'
	from lib/pretty_text.rb:691:in `synchronize'
	from lib/pretty_text.rb:691:in `protect'
	from lib/pretty_text.rb:176:in `markdown'
	from lib/pretty_text.rb:302:in `cook'
	from app/models/post_analyzer.rb:30:in `cook'
	from app/models/post.rb:357:in `cook'
	from app/models/post.rb:825:in `rebake!'
	from (discourse):1:in `<main>'

After some experimenting, it seems it is due to a particular upload reference that is being used multiple times (25+) in the same post:

Screenshot 2025-04-03 at 17.11.56
Screenshot 2025-04-03 at 17.11.56116×376 6.96 KB

The time for the post to rebake is proportional to the number of times that image is referenced in it (1-2 seconds per each use). If it is mentioned enough times, it eventually hits the timeout error. However, if another uploaded image is mentioned as many or more times, the rebake is always instant.

Saving the same image and uploading it again doesn’t reproduce the problem. So the issue seems to be with a particular upload reference.

If all this is not odd enough, it gets stranger. Noticing that the re-uploaded image was including the file extension in the upload reference, I tried appending .gif to the problematic upload reference and… then the rebake works instantly as it should – even when the same problematic image is used dozens of times. In other words, I changed something like

![foobar|15x15](upload://w5ilVpOCq4ZcvEahAisyiR1pzhu)

to

![foobar|15x15](upload://w5ilVpOCq4ZcvEahAisyiR1pzhu.gif)

and, somehow, that made this weird timeout error to go away.

Guess: some reprocessing needs to be done to this image e0ded3304aff1477bae442c0ead0050210dce4f0 and for some reason it repeatedly fails, extending the baking process long enough for it to eventually fail? I’m not sure how to go from here.

In any case, this seems like a bug that could use some attention – maybe the @moderators can relocate this to Bug if they agree?

1 Like