"update_client_ips-0 - There was no active span when trying to log. Did you forget to start one or did a context slip?"

This issue has been migrated from [#11108](https://github.com/matrix-org/synapse/issues/11108).

---

### Description
Occasionally the main Synapse process will print out a logging context error just after starting up.

https://sentry.matrix.org/sentry/synapse-matrixorg/issues/15795/events/17b3e31e182a43fab52a461df986017b/
https://sentry.matrix.org/sentry/synapse-matrixorg/issues/15795/events/2cb307a746ff4c08b8c4dc527e1fec1c/

```
2021-10-12 10:33:54,182 - synapse.logging.opentracing - 342 - ERROR - update_client_ips-0 - There was no active span when trying to log. Did you forget to start one or did a context slip?
Stack (most recent call last):
File "/usr/local/lib/python3.7/threading.py", line 885, in _bootstrap
self._bootstrap_inner()
File "/usr/local/lib/python3.7/threading.py", line 917, in _bootstrap_inner
self.run()
File "/usr/local/lib/python3.7/threading.py", line 865, in run
self._target(*self._args, **self._kwargs)
File "/home/synapse/env-py37/lib/python3.7/site-packages/twisted/_threads/_threadworker.py", line 47, in work
task()
File "/home/synapse/env-py37/lib/python3.7/site-packages/twisted/_threads/_team.py", line 181, in doWork
task()
File "/home/synapse/env-py37/lib/python3.7/site-packages/twisted/python/threadpool.py", line 238, in inContext
result = inContext.theWork() # type: ignore[attr-defined]
File "/home/synapse/env-py37/lib/python3.7/site-packages/twisted/python/threadpool.py", line 255, in
ctx, func, *args, **kw
File "/home/synapse/env-py37/lib/python3.7/site-packages/twisted/python/context.py", line 118, in callWithContext
return self.currentContext().callWithContext(ctx, func, *args, **kw)
File "/home/synapse/env-py37/lib/python3.7/site-packages/twisted/python/context.py", line 83, in callWithContext
return func(*args, **kw)
File "/home/synapse/env-py37/lib/python3.7/site-packages/twisted/enterprise/adbapi.py", line 284, in _runWithConnection
result = func(conn, *args, **kw)
File "/home/synapse/src/synapse/storage/database.py", line 786, in inner_func
return func(db_conn, *args, **kwargs)
File "/home/synapse/src/synapse/storage/database.py", line 555, in new_transaction
opentracing.log_kv({"message": "commit"})
File "/home/synapse/src/synapse/logging/opentracing.py", line 342, in ensure_active_span_inner_2
stack_info=True,
```

The `log_kv` call in question is nested within an opentracing span, after a non-async function call:
https://github.com/matrix-org/synapse/blob/7d70582eb0e0b9656e64e827eca6dfc2533b8ae1/synapse/storage/database.py#L547-L555

Both occurrences of the error have `update_client_ips-0` as the logging context, ie. the first execution of the `update_client_ips` background process. This can't be correct, since the logging context ought to be `update_client_ips-0---` at the point the error is logged.

### Version information

- **Homeserver**: matrix.org

Start in synapse/storage/database.py around the new_transaction log_kv call, then trace the span and logging-context handling in synapse/logging/opentracing.py. Reproduce the startup update_client_ips-0 path if possible and compare its context with the expected update_client_ips-0--- context. Done means the startup error no longer occurs and the transaction commit is logged with the correct active span.

Written by the indexing model from the issue text.