Running on not-Linux results in constant logcontext spam

[jryans]

Description

I am running Synapse on macOS and getting constant (many times per second) log messages like:

2019-09-18 14:57:24,338 - synapse.logging.context - 362 - WARNING - GET-16 - Called stop on logcontext GET-16 without calling start
2019-09-18 14:57:24,339 - synapse.logging.context - 362 - WARNING - GET-16 - Called stop on logcontext GET-16 without calling start
2019-09-18 14:57:24,340 - synapse.logging.context - 362 - WARNING - GET-16 - Called stop on logcontext GET-16 without calling start
2019-09-18 14:57:25,219 - synapse.logging.context - 362 - WARNING - update_client_ips-13 - Called stop on logcontext update_client_ips-13 without calling start
2019-09-18 14:57:25,221 - synapse.logging.context - 362 - WARNING - update_client_ips-13 - Called stop on logcontext update_client_ips-13 without calling start
2019-09-18 14:57:25,223 - synapse.logging.context - 362 - WARNING - update_client_ips-13 - Called stop on logcontext update_client_ips-13 without calling start
2019-09-18 14:57:25,285 - synapse.logging.context - 362 - WARNING - handle_presence_timeouts-7 - Called stop on logcontext handle_presence_timeouts-7 without calling start

For a longer log snippet, see this gist.

@richvdh took an initial look and suggested there's something that would likely fail on macOS that causes this.

Version information

• Homeserver: local on my development machine

If not matrix.org:

• Version: Synapse/1.3.1 (b=anoa/msc2290,cd6f3a89d,dirty)

• Install method: pip install from source

• Platform: macOS 10.14.6

[richvdh]

we have this code which attempts to fail gracefully when resource.getrusage(RUSAGE_THREAD) is unavailable

But that means that when we get here, usage_start is always None, resulting in the warning spam.

[jryans]

I assume you want to keep the warnings for platforms that do have support...?

[jryans]

IRL answer is yes.

[jryans]

I'll give a try given I can clearly reproduce quite easily... 😅

[richvdh]

fixed by #6059