Uploaded image for project: 'Apache Storm'
  1. Apache Storm
  2. STORM-3163

ShellLogHandler loses thread context between setup and use

    XMLWordPrintableJSON

    Details

      Description

      UPDATE

      Turns out that this is much better solved by leveraging log4j2's isThreadContextMapInheritable property, which hands child threads a point-in-time copy of the parent's MDC contents, which completely solves the issue this sought to address.

      ORIGINAL

      tl;dr: ShellLogHandler is handed context in one thread, before being used exclusively from another, this obstructs sane usage of slf4j's MDC feature which is thread local.

      ShellBolt instantiates the ShellLogHandler and calls its setUpContext as part of prepare, immediately before it spawns its BoltReaderRunnable and BoltWriterRunnable threads which are responsible for communication with the ShellProcess that's already been spawned.

      The ShellLogHandler is used exclusively from BoltReaderRunnable. The upshot of this is that setUpContext is executed in the task thread (i.e. Thread-21-joiner-executor[2 2]) while the log method is executed in the anonymous thread (i.e. Thread-30) running the BoltReaderRunnable.

      This creates a problem when trying to leverage slf4j's MDC (or NDC) which are used for augmenting log messages with additional information which is localised and persisted at the thread level.

      The current work around for this is to store all relevant context on the ShellLogHandler during setUpContext, and then write it into the MDC during the log call, and taking precautions around that state being thread safe. The thread safety requirement is the first drawback, the second is that each log call has the additional overhead of either unconditionally writing to the MDC or checking that the MDC is already populated. Neither is very appealing.

      The suggested solution is to pass stormConf, _process, and _context into the constructor of BoltReaderRunnable (and perhaps also BoltWriterRunnable) and instantiate ShellLogHandler and call its setUpContext from that thread.

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              mal Mal Graty
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Time Tracking

                Estimated:
                Original Estimate - Not Specified
                Not Specified
                Remaining:
                Remaining Estimate - 0h
                0h
                Logged:
                Time Spent - 20m
                20m