Start background tasks after we fork the process (daemonize) #18886

MadLittleMods · 2025-09-05T16:13:51Z

Spawning from #18871

This change was originally used to fix CPU time going backwards when we daemonize.

While, we don't seem to run into this problem on develop, I still think this is a good change to make. We don't need background tasks running on a process that will soon be forcefully exited and where the reactor isn't even running yet. We now kick off the background tasks (run_as_background_process) after we have forked the process and started the reactor.

Also as simple note, we don't need background tasks running in both halves of a fork.

Testing strategy:

Run with daemonize: true in your homeserver.yaml
poetry run synapse_homeserver --config-path homeserver.yaml
Shutdown the server
Look for any bad log entries in your homeserver logs:
- utime went backwards!/stime went backwards!

Bad log examples from the other PR (to be clear I wasn't seeing this on develop or with this change):

synapse.logging.context - ERROR - _schedule_next_expiry-0 - utime went backwards! 0.050467 < 0.886526
synapse.logging.context - ERROR - _schedule_db_events-0 - stime went backwards! 0.009941 < 0.155106
synapse.logging.context - ERROR - wake_destinations_needing_catchup-0 - stime went backwards! 0.010175 < 0.130923
synapse.logging.context - ERROR - resume_sync_partial_state_room-0 - utime went backwards! 0.052898 < 0.886526

Dev notes

startup

Pull Request Checklist

Pull request is based on the develop branch
Pull request includes a changelog file. The entry should:
- Be a short description of your change which makes sense to users. "Fixed a bug that prevented receiving messages from other servers." instead of "Moved X method from EventStore to EventWorkerStore.".
- Use markdown where necessary, mostly for code blocks.
- End with either a period (.) or an exclamation mark (!).
- Start with a capital letter.
- Feel free to credit yourself, by adding a sentence "Contributed by @github_username." or "Contributed by [Your Name]." to the end of the entry.
Code style is correct (run the linters)

When we `daemonize`, we fork the process and cputime metrics get confused about the per-thread resource usage appearing to go backwards because we're comparing the resource usage (`rusage`) from the original process to the forked process. We now kick off the background tasks (`run_as_background_process`) after we have forked the process so the `rusage` we record when we `start` is in the same thread when we `stop`. Bad log examples from before: ``` synapse.logging.context - ERROR - _schedule_next_expiry-0 - utime went backwards! 0.050467 < 0.886526 synapse.logging.context - ERROR - _schedule_db_events-0 - stime went backwards! 0.009941 < 0.155106 synapse.logging.context - ERROR - wake_destinations_needing_catchup-0 - stime went backwards! 0.010175 < 0.130923 synapse.logging.context - ERROR - resume_sync_partial_state_room-0 - utime went backwards! 0.052898 < 0.886526 ``` Testing strategy: 1. Run with `daemonize: true` in your `homeserver.yaml` 1. `poetry run synapse_homeserver --config-path homeserver.yaml` 1. Shutdown the server 1. Look for any bad log entries in your homeserver logs: - `Expected logging context sentinel but found main` - `Expected logging context main was lost` - `utime went backwards!`/`stime went backwards!`

MadLittleMods · 2025-09-05T16:34:34Z

synapse/server.py

-        # Register background tasks required by this server. This must be done
-        # somewhat manually due to the background tasks not being registered
-        # unless handlers are instantiated.
-        if self.config.worker.run_background_tasks:
-            self.setup_background_tasks()


In terms of where we moved this code from and to:

Relevant starting point is here:

synapse/synapse/app/homeserver.py

Lines 407 to 417 in b2997a8

def main() -> None:

with LoggingContext("main"):

# check base requirements

check_requirements()

hs = setup(sys.argv[1:])

# redirect stdio to the logs, if configured.

if not hs.config.logging.no_redirect_stdio:

redirect_stdio_to_logs()

run(hs)

The main thing to see here is setup() vs run(). We fork the process in run() and then start the reactor after.

Previously, we started the background tasks in the setup() phase.

Now we start the background tasks in start which happens "once the reactor is running".

MadLittleMods · 2025-09-05T16:41:42Z

synapse/server.py

        """

-    def setup_background_tasks(self) -> None:
+    def start_background_tasks(self) -> None:


Just a rename to align with it's new home in start(). I think either could fit but this might be more straightforward to understand.

synapse/app/_base.py

See #18886 (comment)

MadLittleMods · 2025-09-05T18:51:01Z

synapse/app/_base.py

+        # TODO: This should be moved to same pattern we use for other background tasks:
+        # Add to `REQUIRED_ON_BACKGROUND_TASK_STARTUP` and rely on
+        # `start_background_tasks` to start it.
        await hs.get_common_usage_metrics_manager().setup()
+
+        # TODO: This feels like another pattern that should refactored as one of the
+        # `REQUIRED_ON_BACKGROUND_TASK_STARTUP`
        start_phone_stats_home(hs)


These are future refactors to do.

But given we're already starting a few snowflake background tasks in start(), this is just is more evidence why it makes sense to start background tasks here vs in setup()

…base.py` so portdb can maybe finish See #18886 (comment)

changelog.d/18886.misc

…pse_database.py` so portdb can maybe finish" This reverts commit 11c39c5.

… registered are available

MadLittleMods · 2025-09-09T05:05:09Z

synapse/_scripts/update_synapse_database.py

+    # This will cause all of the relevant storage classes to be instantiated and call
+    # `register_background_update_handler(...)`,
+    # `register_background_index_update(...)`,
+    # `register_background_validate_constraint(...)`, etc so they are available to use
+    # if we are asked to run those background updates.
+    hs.get_storage_controllers()


Previously this was handled in an extremely tenuous fashion because previously hs.setup() used to call hs.start_background_tasks() which instantiated some handlers which ended up instantiating the storage controllers at some point.

Now we just explicitly call this

changelog.d/18886.misc

…r-daemonize

reivilibre

yep, definitely not a good thing to be running background tasks in both halves of a fork! :-)

…r-daemonize

MadLittleMods · 2025-09-09T15:10:59Z

Thanks for the review @reivilibre 🐿️

This was originally removed in #18886 but it looks like it snuck back in #18828 during a bad merge

This was originally removed in #18886 but it looks like it snuck back in #18828 during a [bad merge](4cd3d91). Noticed while looking at Synapse setup and startup (just by happen stance). I don't think this has adverse effects on Synapse actually working and `start_background_tasks()` can be called multiple times. ### Is there a good way to audit all of these merges? As I would like to see the conflicts for each merge. This works but it's still hard to notice anything is wrong: ``` git log --remerge-diff <commit-sha> ``` > shows the difference from mechanical merge result and the result that is actually recorded in a merge commit via https://stackoverflow.com/questions/15277708/how-do-you-see-show-a-git-merge-conflict-resolution-that-was-done-given-a-mer/71181334#71181334 The following better. Specify the version range to the commit right before the merge to the merge. And can even specify which file to look at to make it more obvious with the hindsight we have now. ``` git log --remerge-diff <merge-commit-sha>~1..<merge-commit-sha> -- synapse/server.py ``` Example: ``` git log --remerge-diff 4cd3d91~1..4cd3d91 -- synapse/server.py ```

MadLittleMods added 3 commits September 5, 2025 10:31

Add context

e39a219

Add changelog

313da3e

MadLittleMods commented Sep 5, 2025

View reviewed changes

MadLittleMods mentioned this pull request Sep 5, 2025

Store the LoggingContext in a ContextVar #18871

Closed

8 tasks

Use correct changelog number

ee29030

MadLittleMods commented Sep 5, 2025

View reviewed changes

synapse/app/_base.py Outdated Show resolved Hide resolved

MadLittleMods commented Sep 5, 2025

View reviewed changes

synapse/app/_base.py Outdated Show resolved Hide resolved

MadLittleMods added 2 commits September 5, 2025 13:40

start_background_tasks where we start other background tasks

2f235e3

See #18886 (comment)

start_background_tasks in tests

99b99c2

MadLittleMods commented Sep 5, 2025

View reviewed changes

Try start_background_tasks in `synapse/_scripts/update_synapse_data…

11c39c5

…base.py` so portdb can maybe finish See #18886 (comment)

MadLittleMods commented Sep 9, 2025

View reviewed changes

changelog.d/18886.misc Show resolved Hide resolved

MadLittleMods added 2 commits September 8, 2025 23:33

Revert "Try start_background_tasks in `synapse/_scripts/update_syna…

ed42696

…pse_database.py` so portdb can maybe finish" This reverts commit 11c39c5.

Ensure storage classes are instantiated so the background updates are…

74cd02d

… registered are available

MadLittleMods commented Sep 9, 2025

View reviewed changes

changelog.d/18886.misc Show resolved Hide resolved

MadLittleMods marked this pull request as ready for review September 9, 2025 05:17

MadLittleMods requested a review from a team as a code owner September 9, 2025 05:17

Merge branch 'develop' into madlittlemods/start-background-tasks-afte…

02bb9b4

…r-daemonize

reivilibre approved these changes Sep 9, 2025

View reviewed changes

Merge branch 'develop' into madlittlemods/start-background-tasks-afte…

2ab99d5

…r-daemonize

MadLittleMods merged commit ca655e4 into develop Sep 9, 2025
44 checks passed

MadLittleMods deleted the madlittlemods/start-background-tasks-after-daemonize branch September 9, 2025 15:10

MadLittleMods added a commit that referenced this pull request Oct 3, 2025

Fix bad with start_background_tasks

b6bafaa

This was originally removed in #18886 but it looks like it snuck back in #18828 during a bad merge

This was referenced Oct 3, 2025

Fix bad merge with start_background_tasks #19013

Merged

Cleanly shutdown SynapseHomeServer object #18828

Merged

Split homeserver creation and setup #19015

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Start background tasks after we fork the process (daemonize) #18886

Start background tasks after we fork the process (daemonize) #18886

Uh oh!

MadLittleMods commented Sep 5, 2025 •

edited

Loading

Uh oh!

MadLittleMods Sep 5, 2025

Uh oh!

MadLittleMods Sep 5, 2025

Uh oh!

Uh oh!

Uh oh!

MadLittleMods Sep 5, 2025

Uh oh!

Uh oh!

MadLittleMods Sep 9, 2025

Uh oh!

Uh oh!

reivilibre left a comment

Uh oh!

Uh oh!

MadLittleMods commented Sep 9, 2025

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

	def main() -> None:
	with LoggingContext("main"):
	# check base requirements
	check_requirements()
	hs = setup(sys.argv[1:])

	# redirect stdio to the logs, if configured.
	if not hs.config.logging.no_redirect_stdio:
	redirect_stdio_to_logs()

	run(hs)

Start background tasks after we fork the process (daemonize) #18886

Start background tasks after we fork the process (daemonize) #18886

Uh oh!

Conversation

MadLittleMods commented Sep 5, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Testing strategy:

Dev notes

Pull Request Checklist

Uh oh!

MadLittleMods Sep 5, 2025

Choose a reason for hiding this comment

Uh oh!

MadLittleMods Sep 5, 2025

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

MadLittleMods Sep 5, 2025

Choose a reason for hiding this comment

Uh oh!

Uh oh!

MadLittleMods Sep 9, 2025

Choose a reason for hiding this comment

Uh oh!

Uh oh!

reivilibre left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

MadLittleMods commented Sep 9, 2025

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

MadLittleMods commented Sep 5, 2025 •

edited

Loading