Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix tagged logger concurrent update exception #3270

Conversation

afkelsall
Copy link
Contributor

The way loggers are accessed, they are most often a static instance shared between threads like so:

class EventConsumer {
  companion object {
      private val logger = this::class.getTaggedLogger()
    }
}

The previous version failed to identify the shared state on the logger where multiple threads consume from event streams, job queues and web actions etc.

This fix changes the way the logger works to reflect our local service TaggedLogger's we've implemented internally at Cash where on each tag("tagKey" to "tagValue123") call the logger copies itself and a new instance with the updated Set<Tag> is passed into the constructor for the next call to the builder or asContext {}. This addresses the concurrent thread problem because each thread copies the logger for itself when building it.

The challenge moving the TaggedLogger implementation into the misk framework where a service will extend the abstract TaggedLogger class is that there needs to be a way for the misk TaggedLogger to get the implementing class to copy itself with new tags. That's where the interface Copyable {} comes in. This ends up making the ServiceTaggedLogger: TaggedLogger() implementation more complex and the generics are more complex, but this is a write once per service class and I think with good documentation and support will be fine.

@@ -21,6 +21,7 @@ import org.assertj.core.api.Assertions.assertThat
import org.junit.jupiter.api.BeforeEach
import org.junit.jupiter.api.Test
import wisp.feature.testing.FakeFeatureFlags
import wisp.logging.Copyable
Copy link
Collaborator

@adrw adrw May 17, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I can't find this in the repo, can you link where it is? edit: nvm found it as part of this PR.

Copy link
Collaborator

@ean5533 ean5533 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I had to come up to speed on TaggedLogger (I missed the original addition). While reading the original PR, I had several thoughts that were't strictly related to this PR, but they end up being relevant once you follow them to their logical conclusion:

  • withContext might be a better name for asContext. The “with” is fairly well established idiom for “do a thing with this additional context”.
  • Taking it further, it would be useful if that method optionally took tags so that you didn’t have to chain method calls if you don’t need to:
fun <T> withContext(vararg newTags: Tag, f: () -> T): T

logger.withContext("foo" to "bar") {
  ...
}
  • By this point, we’ve now nearly duplicated the signature of wisp.logging.withTags. It’s tempting to say we should just name this method withTags for consistency.
  • But this raises an important question: why is TaggedLogger a logger? Its only job is to set some tags and clear them at the right time, it doesn’t do any logging. It doesn't need to be a KLogger, it can just be used in conjunction with one. We could just call it something like MiskTagSetter (except, like, pick a less crappy name than that),
  • For that matter, I may be missing a critical detail, but it’s not clear to me that this thing even needs to be an instantiated, stateful class at all. The existing wisp.logging.withTags is just a static method, and it seems like this thing could be too, because the only thing it does differently is conditionally set (and unset) a threadlocal. You could name it slightly differently to disambiguate its behavior of retaining tags for exceptions:
withSmartTags("foo" to "bar") {
  ...
}

tl;dr it feels like TaggedLogger is just a smarter, more integrated version of wisp.logging.withTags, and could be made just as lightweight. Incidentally, none of the complicated generics in this PR would be needed because tags would only persist for the scope of each withSmartTags call instead being saved in a static object.

All that said, I'm approving this PR because I think it solves your immediate problem, but I'd love if we could simplify the whole thing.

@ean5533 ean5533 enabled auto-merge (squash) May 22, 2024 14:42
@ean5533 ean5533 merged commit 7698e93 into cashapp:master May 22, 2024
9 checks passed
ean5533 added a commit that referenced this pull request May 24, 2024
Shamelessly cribbed from [ExperimentalOkHttpApi](https://github.com/square/okhttp/blob/54238b4c713080c3fd32fb1a070fb5d6814c9a09/okhttp/src/main/kotlin/okhttp3/ExperimentalOkHttpApi.kt), this new annotation will allow us to better communicate the unstable nature of new public classes and methods. This will allow us to more rapidly iterate on these features without worrying as much about breaking changes, which is good both for code authors and reviewers. It's also good for Misk users who will have a clearer signal about what is and isn't safe to start using.

This PR also demonstrates usage of the annotation by applying it to `TaggedLogger`, a class which was created recently and is being iterated on [right now](#3270).
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants