ValueError: Cyclic dependency while building _presence_handler

[konradkonrad]

It seems that https://github.com/raiden-network/raiden-synapse-modules/blob/main/raiden_synapse_modules/pfs_presence_router.py#L88-L92 does not work as intended.

2021-06-15 12:02:28,848 root(326) [WARNING ]: main Server /synapse-venv/lib/python3.9/site-packages/synapse/app/homeserver.py version 1.35.1
2021-06-15 12:02:29,575 raiden_synapse_modules.pfs_presence_router(269) [DEBUG   ]: main Creating UserID for address 0x956b18Fb47F9626DDbA869feb3e91bF94224E767
2021-06-15 12:02:29,576 raiden_synapse_modules.pfs_presence_router(269) [DEBUG   ]: main Creating UserID for address 0xf5107B9E51d1b2E7D9Be60D2fD4786898a8f663b
2021-06-15 12:02:29,576 raiden_synapse_modules.pfs_presence_router(264) [DEBUG   ]: main Now 2 users registered for presence updates.
2021-06-15 12:02:29,576 raiden_synapse_modules.pfs_presence_router(209) [DEBUG   ]: pfs_presence_router_send_current_presences_on_init-0 Sending presences to 2 users
2021-06-15 12:02:29,576 synapse.metrics.background_process_metrics(209) [ERROR   ]: pfs_presence_router_send_current_presences_on_init-0 Background process 'pfs_presence_router_send_current_presences_on_init' threw an exception
Traceback (most recent call last):
  File "/synapse-venv/lib/python3.9/site-packages/synapse/metrics/background_process_metrics.py", line 207, in run
    return await maybe_awaitable(func(*args, **kwargs))
  File "/synapse-venv/lib/python3.9/site-packages/raiden_synapse_modules/pfs_presence_router.py", line 210, in send_current_presences_to
    await self._module_api.send_local_online_presence_to(users)
  File "/synapse-venv/lib/python3.9/site-packages/synapse/module_api/__init__.py", line 420, in send_local_online_presence_to
    presence_handler = self._hs.get_presence_handler()
  File "/synapse-venv/lib/python3.9/site-packages/synapse/server.py", line 183, in _get
    raise ValueError("Cyclic dependency while building %s" % (depname,))
ValueError: Cyclic dependency while building _presence_handler
2021-06-15 12:02:29,611 raiden_synapse_modules.pfs_presence_router(98) [DEBUG   ]: main Module setup done
2021-06-15 12:02:30,029 federation_whitelist_reloader(58) [WARNING ]: federation_whitelist_reloader-0 Updated federation whitelist. New list: ['transport.demo002.env.raiden.network']

[anoadragon453]

I believe this may be due to the import line:

from synapse.metrics.background_process_metrics import run_as_background_process

ModuleApi exposes run_in_background which should be sufficient for your purposes. run_as_background_process will start the function in its own logcontext, which may result in log lines getting lost.

You should be able to simply do:

from synapse.module_api import run_in_background

and use that method instead (just drop the desc argument in your existing calls).

Interestingly I wasn't able to reproduce this cyclic dependency when attempting to run this on Synapse v1.37.0, which may be a result of the recent module refactoring.

[ulope]

@anoadragon453 As suggested I replaced run_as_background_process with run_in_background.

Unfortunately this doesn't fix the issue.

I assume the reason you can't reproduce is is because of the two conditions:

raiden-synapse-modules/raiden_synapse_modules/presence_router/pfs.py

Line 84 in 817ac8b

if self.worker_type is WorkerType.FEDERATION_SENDER:

and

raiden-synapse-modules/raiden_synapse_modules/presence_router/pfs.py

Line 230 in 817ac8b

if self.worker_type is WorkerType.FEDERATION_SENDER:

In a non-worker setup those will always be false.
For testing just replace them with if True: please.

[ulope]

2022-01-21 10:29:32,773 twisted(258) [CRITICAL]: sentinel Unhandled error in Deferred:
2022-01-21 10:29:32,774 twisted(258) [CRITICAL]: sentinel
Traceback (most recent call last):
  File "/synapse-venv/lib/python3.9/site-packages/twisted/internet/defer.py", line 1661, in _inlineCallbacks
    result = current_context.run(gen.send, result)
  File "/synapse-venv/lib/python3.9/site-packages/raiden_synapse_modules/presence_router/pfs.py", line 227, in send_current_presences_to
    await self._module_api.send_local_online_presence_to(users)
  File "/synapse-venv/lib/python3.9/site-packages/synapse/module_api/__init__.py", line 420, in send_local_online_presence_to
    presence_handler = self._hs.get_presence_handler()
  File "/synapse-venv/lib/python3.9/site-packages/synapse/server.py", line 183, in _get
    raise ValueError("Cyclic dependency while building %s" % (depname,))
ValueError: Cyclic dependency while building _presence_handler

[anoadragon453]

In Synapse v1.35.1 (with the module running on the main process):

• PresenceHandler is initialised as part of setting up Synapse
• PresenceHandler initialises PresenceRouter
• PresenceRouter initialises the PFS presence router module.
• The presence router module has an __init__ which eventually runs ModuleApi.send_local_online_presence_to:

raiden-synapse-modules/raiden_synapse_modules/presence_router/pfs.py

Lines 241 to 246 in 9186b17

	async def send_current_presences_to(self, users: List[UserID]) -> None:
	"""Send all presences to users."""
	start = time.time()
	log.debug(f"Sending presences to {len(users)} users")
	await self._module_api.send_local_online_presence_to(users)
	log.info(f"Presences updated in {time.time() - start} seconds")

• The module api grabs the currently initialised PresenceHandler inside of send_local_online_presence_to, but the @cache_in_self decorator recognises that a request for PresenceHandler is made while PresenceHandler is being initialised, causing it to raise the ValueError we see above.

In Synapse v1.50.1 (5666773341):

The PFS presence router is now being initialised as Synapse starts up (which in contrast to v1.35.1, means that Synapse has initialised even less stuff now):

• The PFS presence router module is initialised
• PFS presence router calls ModuleApi.send_local_online_presence_to
• ModuleApi initialises PresenceHandler
• PresenceHandler tries to do lots of stuff
• Synapse is not started up yet and things will probably break.

The key problem is that we're trying to do things in __init__ that interact with Synapse. However, we would like to execute ModuleApi methods when our module starts up! __init__ thus seems like a good place to do this, but it has problems as seen above. A suggestion is to add a callback to ModuleApi which fires when Synapse is initialised fully and ModuleApi methods can be safely called. This does not currently exist.

A workaround for now may be to call these methods once from either PresenceRouter.get_users_for_states or PresenceRouter.get_interested_users as those will only be called once Synapse is fully initialised.

Questions:

1. Does using looping_background_call allow us to defer the call to ModuleApi.send_local_online_presence_to and thus break out of the initialisation dependency loop?

[anoadragon453]

The PFS presence router is now being initialised as Synapse starts up (which in contrast to v1.35.1, means that Synapse has initialised even less stuff now)

Actually, what we were seeing was the class being loaded, not an instance of it. The modules are actually initialised here, outside of PresenceRouter's __init__ method now. This breaks the dependency loop, and means that the point where __init__ is called in your module in later Synapse versions should be at a point where Synapse has mostly initialised already.

Thus, I would try upgrading Synapse and see if the exception no longer occurs.