Add debug log when HMAC incorrect

[MadLittleMods]

Spawning from getting HMAC incorrect errors that seem unexplainable except for the registration_shared_secret being misconfigured. It's also possible my HMAC calculation is incorrect but every time I double-check the result with the known-good Python example (which matches Synapse's source), it's as expected.

With these logs, we can actually debug whether registration_shared_secret is being configured correctly or not.

It also helps specifically when using registration_shared_secret_path since the default Synapse behavior (of creating the file and secret if it doesn't exist) can mask deployment race condition where we would start up Synapse before the registration_shared_secret_path file was put in place:

registration_shared_secret_path

[...]

If this file does not exist, Synapse will create a new shared secret on startup and store it in this file.

-- Synapse config docs

This only applies to the POST /_synapse/admin/v1/register endpoint but does log very sensitive information so we've made it so you have to explicitly enable the logs by configuring synapse.rest.admin.users.registration_debug (does not inherit root log level) (via our new ExplicitlyConfiguredLogger)

homeserver.yaml

log_config: "/myserver.log.config.yaml"

myserver.log.config.yaml

version: 1

formatters:
    precise:
        format: '%(asctime)s - %(name)s - %(lineno)d - %(levelname)s - %(request)s - %(message)s'
        

handlers:
    # ... file/buffer handler (see `sample_log_config.yaml`)

    # A handler that writes logs to stderr. Unused by default, but can be used
    # instead of "buffer" and "file" in the logger handlers.
    console:
        class: logging.StreamHandler
        formatter: precise

loggers:
    synapse.storage.SQL:
        # beware: increasing this to DEBUG will make synapse log sensitive
        # information such as access tokens.
        level: INFO

    # Has to be explicitly configured as such. Will not inherit from the root level even if it's set to DEBUG
    synapse.rest.admin.users.registration_debug:
        level: DEBUG

root:
    level: INFO

    handlers: [console]

disable_existing_loggers: false

Dev notes

Python bug with logging.NOTSET and assertLogs and assertNoLogs: python/cpython#136958

---

• https://docs.python.org/3/library/logging.html
• https://docs.python.org/3/library/logging.config.html

---

ExplicitlyConfiguredLogger

---

Log setup: synapse/config/logger.py

Log setup in tests: tests/test_utils/logging_setup.py

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)

[MadLittleMods]

As an update on the root cause on why we were seeing of HMAC incorrect error, @devonh found that the file for the registration_shared_secret_path itself had an incorrect/unexpected value.

Basically, we're running into the default Synapse behavior (of creating the file and secret if it doesn't exist) masking our deployment race condition where we would start up Synapse before the registration_shared_secret_path file was put in place:

registration_shared_secret_path

[...]

If this file does not exist, Synapse will create a new shared secret on startup and store it in this file.

-- Synapse config docs

[anoadragon453]

I'm taking this off the general review queue while #18474 (comment) is explored.

[MadLittleMods]

Ran into a bug with the built-in unittest Python library so we have this workaround for now, see python/cpython#136958

[anoadragon453]

This now LGTM!

Thanks for adding tests for the new logger class ✨

[MadLittleMods]

Thanks for the review and pushing the ball forward @devonh, @reivilibre, @erikjohnston, @anoadragon453 🦏