Commit Graph

152 Commits (fb664cf159d1d6c5d150726cc365debf911f7e74)

Author SHA1 Message Date
Nick Barrett bb228f3523
Include exception in json logging (#11028) 2021-10-08 13:08:25 +02:00
Sean Quah 660c8c1415
Log stack traces when a missing opentracing span is detected (#10983)
Make it easier to track down where opentracing spans are going missing
by including stack traces in the logs.
2021-10-05 12:23:25 +01:00
Patrick Cloke bb7fdd821b
Use direct references for configuration variables (part 5). (#10897) 2021-09-24 07:25:21 -04:00
Patrick Cloke 01c88a09cd
Use direct references for some configuration variables (#10798)
Instead of proxying through the magic getter of the RootConfig
object. This should be more performant (and is more explicit).
2021-09-13 13:07:12 -04:00
Patrick Cloke 003846d68a
Use the BaseReporter super-class for _WrappedRustReporter. (#10799)
This fixes mypy errors with jaeger-client >= 4.7.0 and should be a no-op
for versions before that.
2021-09-13 08:54:01 -04:00
reivilibre 903db99ed5
Fix PeriodicallyFlushingMemoryHandler inhibiting application shutdown (#10517) 2021-08-03 14:28:30 +01:00
reivilibre e16eab29d6
Add a PeriodicallyFlushingMemoryHandler to prevent logging silence (#10407)
Signed-off-by: Olivier Wilkinson (reivilibre) <olivier@librepush.net>
2021-07-27 14:32:05 +01:00
Richard van der Hoff d8324b8238
Fix a handful of type annotations. (#10446)
* switch from `types.CoroutineType` to `typing.Coroutine`

these should be identical semantically, and since `defer.ensureDeferred` is
defined to take a `typing.Coroutine`, will keep mypy happy

* Fix some annotations on inlineCallbacks functions

* changelog
2021-07-22 12:00:16 +01:00
Jonathan de Jong 95e47b2e78
[pyupgrade] `synapse/` (#10348)
This PR is tantamount to running 
```
pyupgrade --py36-plus --keep-percent-format `find synapse/ -type f -name "*.py"`
```

Part of #9744
2021-07-19 15:28:05 +01:00
Jonathan de Jong bf72d10dbf
Use inline type hints in various other places (in `synapse/`) (#10380) 2021-07-15 11:02:43 +01:00
Richard van der Hoff 91fa9cca99
Expose opentracing trace id in response headers (#10199)
Fixes: #9480
2021-06-18 11:43:22 +01:00
Patrick Cloke 18edc9ab06
Improve comments in the structured logging code. (#10188) 2021-06-16 19:18:02 +01:00
Richard van der Hoff 9e405034e5
Make opentracing trace into event persistence (#10134)
* Trace event persistence

When we persist a batch of events, set the parent opentracing span to the that
from the request, so that we can trace all the way in.

* changelog

* When we force tracing, set a baggage item

... so that we can check again later.

* Link in both directions between persist_events spans
2021-06-16 11:41:15 +01:00
Richard van der Hoff 1bf83a191b
Clean up the interface for injecting opentracing over HTTP (#10143)
* Remove unused helper functions

* Clean up the interface for injecting opentracing over HTTP

* changelog
2021-06-09 11:33:00 +01:00
Richard van der Hoff b2557cbf42
opentracing: use a consistent name for background processes (#10135)
... otherwise we tend to get a namespace clash between the bg process and the
functions that it calls.
2021-06-07 17:57:49 +01:00
Richard van der Hoff d8be7d493d
Enable Prometheus metrics for the jaeger client library (#10112) 2021-06-04 09:25:33 +01:00
Richard van der Hoff 9eea4646be
Add OpenTracing for database activity. (#10113)
This adds quite a lot of OpenTracing decoration for database activity. Specifically it adds tracing at four different levels:

 * emit a span for each "interaction" - ie, the top level database function that we tend to call "transaction", but isn't really, because it can end up as multiple transactions.
 * emit a span while we hold a database connection open
 * emit a span for each database transaction - actual actual transaction.
 * emit a span for each database query.

I'm aware this might be quite a lot of overhead, but even just running it on a local Synapse it looks really interesting, and I hope the overhead can be offset just by turning down the sampling frequency and finding other ways of tracing requests of interest (eg, the `force_tracing_for_users` setting).
2021-06-03 16:31:56 +01:00
Brad Murray 10e6d2abce
Fix opentracing inject to use the SpanContext, not the Span (#10074)
Signed-off-by: Brad Murray brad@beeper.com
2021-06-01 08:40:26 +01:00
Richard van der Hoff ed53bf314f
Set opentracing priority before setting other tags (#10092)
... because tags on spans which aren't being sampled get thrown away.
2021-05-28 16:14:08 +01:00
Richard van der Hoff b378d98c8f
Add debug logging for issue #9533 (#9959)
Hopefully this will help us track down where to-device messages are getting
lost/delayed.
2021-05-11 11:04:03 +01:00
Andrew Morgan 3186324260 Merge branch 'master' into develop 2021-04-22 11:23:56 +01:00
Richard van der Hoff d9bd62f9d1
Make LoggingContext's name optional (#9857)
Fixes https://github.com/matrix-org/synapse-s3-storage-provider/issues/55
2021-04-21 16:39:34 +01:00
Andrew Morgan 6982db9651 Merge branch 'master' into develop 2021-04-20 14:55:16 +01:00
Patrick Cloke b076bc276e
Always use the name as the log ID. (#9829)
As far as I can tell our logging contexts are meant to log the request ID, or sometimes the request ID followed by a suffix (this is generally stored in the name field of LoggingContext). There's also code to log the name@memory location, but I'm not sure this is ever used.

This simplifies the code paths to require every logging context to have a name and use that in logging. For sub-contexts (created via nested_logging_contexts, defer_to_threadpool, Measure) we use the current context's str (which becomes their name or the string "sentinel") and then potentially modify that (e.g. add a suffix).
2021-04-20 14:19:00 +01:00
Jonathan de Jong 495b214f4f
Fix (final) Bugbear violations (#9838) 2021-04-20 11:50:49 +01:00
Jonathan de Jong 4b965c862d
Remove redundant "coding: utf-8" lines (#9786)
Part of #9744

Removes all redundant `# -*- coding: utf-8 -*-` lines from files, as python 3 automatically reads source code as utf-8 now.

`Signed-off-by: Jonathan de Jong <jonathan@automatia.nl>`
2021-04-14 15:34:27 +01:00
Jonathan de Jong 2ca4e349e9
Bugbear: Add Mutable Parameter fixes (#9682)
Part of #9366

Adds in fixes for B006 and B008, both relating to mutable parameter lint errors.

Signed-off-by: Jonathan de Jong <jonathan@automatia.nl>
2021-04-08 22:38:54 +01:00
Patrick Cloke 48d44ab142
Record more information into structured logs. (#9654)
Records additional request information into the structured logs,
e.g. the requester, IP address, etc.
2021-04-08 08:01:14 -04:00
Erik Johnston 33548f37aa
Improve tracing for to device messages (#9686) 2021-04-01 17:08:21 +01:00
Jonathan de Jong fc53a606e4
Fix `re.Pattern` mypy error on 3.6 (#9703) 2021-03-29 09:40:45 -04:00
Erik Johnston b5efcb577e
Make it possible to use dmypy (#9692)
Running `dmypy run` will do a `mypy` check while spinning up a daemon
that makes rerunning `dmypy run` a lot faster.

`dmypy` doesn't support `follow_imports = silent` and has
`local_partial_types` enabled, so this PR enables those options and
fixes the issues that were newly raised. Note that `local_partial_types`
will be enabled by default in upcoming mypy releases.
2021-03-26 16:49:46 +00:00
Jonathan de Jong 4c3827f2c1
Enable addtional flake8-bugbear linting checks. (#9659) 2021-03-24 09:34:30 -04:00
Patrick Cloke 55da8df078
Fix additional type hints from Twisted 21.2.0. (#9591) 2021-03-12 11:37:57 -05:00
Patrick Cloke 7fdc6cefb3
Fix additional type hints. (#9543)
Type hint fixes due to Twisted 21.2.0 adding type hints.
2021-03-09 07:41:32 -05:00
Patrick Cloke 33a02f0f52
Fix additional type hints from Twisted upgrade. (#9518) 2021-03-03 15:47:38 -05:00
Eric Eastwood 0a00b7ff14
Update black, and run auto formatting over the codebase (#9381)
- Update black version to the latest
 - Run black auto formatting over the codebase
    - Run autoformatting according to [`docs/code_style.md
`](80d6dc9783/docs/code_style.md)
 - Update `code_style.md` docs around installing black to use the correct version
2021-02-16 22:32:34 +00:00
Patrick Cloke a78016dadf
Add type hints to E2E handler. (#9232)
This finishes adding type hints to the `synapse.handlers` module.
2021-01-28 08:34:19 -05:00
Patrick Cloke 06fefe0bb1
Add type hints to the logging context code. (#8939) 2021-01-05 08:06:55 -05:00
Patrick Cloke 1619802228
Various clean-ups to the logging context code (#8935) 2020-12-14 14:19:47 -05:00
Patrick Cloke 8b42a4eefd
Gracefully handle a pending logging connection during shutdown. (#8685) 2020-10-29 12:53:57 -04:00
Patrick Cloke 00b24aa545
Support generating structured logs in addition to standard logs. (#8607)
This modifies the configuration of structured logging to be usable from
the standard Python logging configuration.

This also separates the formatting of logs from the transport allowing
JSON logs to files or standard logs to sockets.
2020-10-29 07:27:37 -04:00
Erik Johnston 2b7c180879
Start fewer opentracing spans (#8640)
#8567 started a span for every background process. This is good as it means all Synapse code that gets run should be in a span (unless in the sentinel logging context), but it means we generate about 15x the number of spans as we did previously.

This PR attempts to reduce that number by a) not starting one for send commands to Redis, and b) deferring starting background processes until after we're sure they're necessary.

I don't really know how much this will help.
2020-10-26 09:30:19 +00:00
Patrick Cloke 20a67aa70d
Separate the TCP and terse JSON formatting code. (#8587)
This should (theoretically) allow for using the TCP code with a different output type
and make it easier to use the JSON code with files / console.
2020-10-21 06:59:54 -04:00
Patrick Cloke 4ff0201e62
Enable mypy checking for unreachable code and fix instances. (#8432) 2020-10-01 08:09:18 -04:00
Richard van der Hoff 5e3ca12b15
Create a mechanism for marking tests "logcontext clean" (#8399) 2020-09-28 17:58:33 +01:00
Patrick Cloke 8a4a4186de
Simplify super() calls to Python 3 syntax. (#8344)
This converts calls like super(Foo, self) -> super().

Generated with:

    sed -i "" -Ee 's/super\([^\(]+\)/super()/g' **/*.py
2020-09-18 09:56:44 -04:00
Patrick Cloke aec294ee0d
Use slots in attrs classes where possible (#8296)
slots use less memory (and attribute access is faster) while slightly
limiting the flexibility of the class attributes. This focuses on objects
which are instantiated "often" and for short periods of time.
2020-09-14 12:50:06 -04:00
Patrick Cloke d2a3eb04a4 Fix typos in comments. 2020-09-14 11:46:58 -04:00
Richard van der Hoff 703e2b8a96
Use the right constructor for log records (#8278)
Update `log_function` to use the right factory to create log records, to make
sure that they have `request` attributes.

Fixes: #8267.
2020-09-08 14:52:51 +01:00
Patrick Cloke c619253db8
Stop sub-classing object (#8249) 2020-09-04 06:54:56 -04:00
Patrick Cloke dbc630a628
Use the JSON encoder without whitespace in more places. (#8124) 2020-08-20 10:32:33 -04:00
Patrick Cloke eebf52be06
Be stricter about JSON that is accepted by Synapse (#8106) 2020-08-19 07:26:03 -04:00
Erik Johnston 1ef9efc1e0
Fix error reporting when using `opentracing.trace` (#7961) 2020-07-27 16:20:24 +01:00
Richard van der Hoff 15997618e2
Clean up PreserveLoggingContext (#7877)
This had some dead code and some just plain wrong docstrings.
2020-07-22 00:40:27 +01:00
Karthikeyan Singaravelan 5662e2b0f3
Remove unused code from synapse.logging.utils. (#7897) 2020-07-20 15:20:53 -04:00
Patrick Cloke d1d5fa66e4
Fix the trace function for async functions. (#7872)
Co-authored-by: Richard van der Hoff <1389908+richvdh@users.noreply.github.com>
2020-07-17 13:32:01 -04:00
Will Hunt 62b1ce8539
isort 5 compatibility (#7786)
The CI appears to use the latest version of isort, which is a problem when isort gets a major version bump. Rather than try to pin the version, I've done the necessary to make isort5 happy with synapse.
2020-07-05 16:32:02 +01:00
Erik Johnston 5cdca53aa0
Merge different Resource implementation classes (#7732) 2020-07-03 19:02:19 +01:00
Erik Johnston e07a8caf58
Add support for using rust-python-jaeger-reporter (#7697) 2020-06-17 14:13:41 +01:00
Dagfinn Ilmari Mannsåker a3f11567d9
Replace all remaining six usage with native Python 3 equivalents (#7704) 2020-06-16 08:51:47 -04:00
Richard van der Hoff d4676910c9 remove miscellaneous PY2 code 2020-05-15 19:37:41 +01:00
Patrick Cloke d7c2df2fa3
Improve per-block CPU and DB usage metrics (#7426) 2020-05-06 16:43:39 -04:00
Patrick Cloke fe69fb6263
Add backwards compatibility codepath to LoggingContext. (#7408) 2020-05-05 09:21:34 -04:00
Erik Johnston 37f6823f5b
Add instance name to RDATA/POSITION commands (#7364)
This is primarily for allowing us to send those commands from workers, but for now simply allows us to ignore echoed RDATA/POSITION commands that we sent (we get echoes of sent commands when using redis). Currently we log a WARNING on the master process every time we receive an echoed RDATA.
2020-04-29 16:23:08 +01:00
Richard van der Hoff 0f05fd1530
Reduce the number of calls to `resource.getrusage` (#7183)
Let's just call `getrusage` once on each logcontext change, rather than twice.
2020-04-03 13:21:30 +01:00
Richard van der Hoff 60adcbed91
Fix "'NoneType' has no attribute start|stop" logcontext errors (#7181)
Fixes #7179.
2020-03-31 15:18:41 +01:00
Richard van der Hoff 39230d2171
Clean up some LoggingContext stuff (#7120)
* Pull Sentinel out of LoggingContext

... and drop a few unnecessary references to it

* Factor out LoggingContext.current_context

move `current_context` and `set_context` out to top-level functions.

Mostly this means that I can more easily trace what's actually referring to
LoggingContext, but I think it's generally neater.

* move copy-to-parent into `stop`

this really just makes `start` and `stop` more symetric. It also means that it
behaves correctly if you manually `set_log_context` rather than using the
context manager.

* Replace `LoggingContext.alive` with `finished`

Turn `alive` into `finished` and make it a bit better defined.
2020-03-24 14:45:33 +00:00
Brendan Abolivier dc6fb56c5f
Hopefully mypy is happy now 2020-03-10 14:40:28 +00:00
Brendan Abolivier fe593ef990
Attempt at appeasing the gods of mypy 2020-03-10 14:19:06 +00:00
Neil Pilgrim 2bff4457d9
Add type hints to logging/context.py (#6309)
* Add type hints to logging/context.py

Signed-off-by: neiljp (Neil Pilgrim) <github@kepier.clara.net>
2020-03-07 17:57:26 +00:00
Patrick Cloke 509e381afa
Clarify list/set/dict/tuple comprehensions and enforce via flake8 (#6957)
Ensure good comprehension hygiene using flake8-comprehensions.
2020-02-21 07:15:07 -05:00
Richard van der Hoff da4e52544e comment for run_in_background 2020-01-12 21:53:47 +00:00
Erik Johnston 495005360c Bump version of mypy 2019-12-12 15:21:12 +00:00
Erik Johnston ffeafade48 Update comment 2019-12-10 13:17:39 +00:00
Erik Johnston 9a2223d4c8 Fix make_deferred_yieldable to work with coroutines 2019-12-10 11:22:12 +00:00
Amber Brown fdec84aa42
Add benchmarks for structured logging performance (#6266) 2019-12-03 20:21:25 +11:00
Amber Brown 9eebd46048
Improve the performance of structured logging (#6322) 2019-11-26 03:45:50 +11:00
Andrew Morgan 73d091be48 A couple more instances 2019-11-12 13:12:25 +00:00
Amber Brown 020add5099
Update black to 19.10b0 (#6304)
* update version of black and also fix the mypy config being overridden
2019-11-01 02:43:24 +11:00
Andrew Morgan 54fef094b3
Remove usage of deprecated logger.warn method from codebase (#6271)
Replace every instance of `logger.warn` with `logger.warning` as the former is deprecated.
2019-10-31 10:23:24 +00:00
Erik Johnston f3ceaf4323 Trace non-JSON APIs, /media, /key etc 2019-10-11 11:58:52 +01:00
Amber Brown 864f144543
Fix up some typechecking (#6150)
* type checking fixes

* changelog
2019-10-02 05:29:01 -07:00
J. Ryan Stinnett a86a290850 Fix logcontext spam on non-Linux platforms (#6059)
This checks whether the current platform supports thread resource usage tracking
before logging a warning to avoid log spam.

Fixes https://github.com/matrix-org/synapse/issues/6055
2019-09-18 21:55:37 +01:00
Amber Brown b617864cd9
Fix for structured logging tests stomping on logs (#6023) 2019-09-13 02:29:55 +10:00
Erik Johnston d8517da85b Don't assume there is a 'self' arg in @trace decorator 2019-09-06 10:07:12 +01:00
Jorik Schellekens bc604e7f94
Gracefully handle log context slips and missing opentracing import errors. (#5988) 2019-09-05 17:33:29 +01:00
Jorik Schellekens 909827b422
Add opentracing to all client servlets (#5983) 2019-09-05 14:46:04 +01:00
Jorik Schellekens b9cfd3c375
Fix opentracing contexts missing from outbound replication requests (#5982) 2019-09-05 14:22:15 +01:00
Jorik Schellekens a90d16dabc
Opentrace device lists (#5853)
Trace device list changes.
2019-09-03 10:21:30 +01:00
Amber Brown 7dc398586c
Implement a structured logging output system. (#5680) 2019-08-28 21:18:53 +10:00
Jorik Schellekens 8767b63a82
Propagate opentracing contexts through EDUs (#5852)
Propagate opentracing contexts through EDUs
Co-Authored-By: Richard van der Hoff <1389908+richvdh@users.noreply.github.com>
2019-08-22 18:21:10 +01:00
Jorik Schellekens 812ed6b0d5
Opentracing across workers (#5771)
Propagate opentracing contexts across workers


Also includes some Convenience modifications to opentracing for servlets, notably:
- Add boolean to skip the whitelisting check on inject
  extract methods. - useful when injecting into carriers
  locally. Otherwise we'd always have to include our
  own servername and whitelist our servername
- start_active_span_from_request instead of header
- Add boolean to decide whether to extract context
  from a request to a servlet
2019-08-22 18:08:07 +01:00
Jorik Schellekens c886f976e0
Opentracing doc update (#5776)
Update opentracing docs to use the unified 'trace' method
2019-08-20 13:56:03 +01:00
Jorik Schellekens 3641784e8c
Make Jaeger fully configurable (#5694)
* Allow Jaeger to be configured

* Update sample config
2019-07-23 15:46:04 +01:00
Amber Brown 4806651744
Replace returnValue with return (#5736) 2019-07-23 23:00:55 +10:00
Jorik Schellekens 18a466b84e
Opentracing Utils (#5722)
* Add decerators for tracing functions

* Use the new clean contexts

* Context and edu utils

* Move opentracing setters

* Move whitelisting

* Sectioning comments

* Better args wrapper

* Docstrings

Co-Authored-By: Erik Johnston <erik@matrix.org>

* Remove unused methods.

* Don't use global

* One tracing decorator to rule them all.
2019-07-23 13:31:16 +01:00
Jorik Schellekens 0fd171770a Merge branch 'release-v1.2.0' into develop 2019-07-22 11:18:50 +01:00
Jorik Schellekens 826e6ec3bd
Opentracing Documentation (#5703)
* Opentracing survival guide

* Update decorator names in doc

* Doc cleanup

These are all alterations as a result of comments in #5703, it
includes mostly typos and clarifications. The most interesting
changes are:

- Split developer and user docs into two sections
- Add a high level description of OpenTracing

* newsfile

* Move contributer specific info to docstring.

* Sample config.

* Trailing whitespace.

* Update 5703.misc

* Apply suggestions from code review

Mostly just rewording parts of the docs for clarity.

Co-Authored-By: Richard van der Hoff <1389908+richvdh@users.noreply.github.com>
2019-07-22 11:15:21 +01:00
Jorik Schellekens 7b8bc61834
Don't accept opentracing data from clients. (#5715)
* Don't accept opentracing data from clients.

* newsfile
2019-07-19 16:29:57 +01:00
Richard van der Hoff 82345bc09a
Clean up opentracing configuration options (#5712)
Clean up config settings and dead code.

This is mostly about cleaning up the config format, to bring it into line with our conventions. In particular:
 * There should be a blank line after `## Section ##' headings
 * There should be a blank line between each config setting
 * There should be a `#`-only line between a comment and the setting it describes
 * We don't really do the `#  #` style commenting-out of whole sections if we can help it
 * rename `tracer_enabled` to `enabled`

While we're here, do more config parsing upfront, which makes it easier to use
later on.

Also removes redundant code from LogContextScopeManager.

Also changes the changelog fragment to a `feature` - it's exciting!
2019-07-18 15:06:54 +01:00