Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-34823

Thread name and connection number are not synchronized in TransportLayerLegacy

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major - P3
    • Resolution: Fixed
    • Affects Version/s: 3.4.0, 3.6.0
    • Fix Version/s: 3.4.16, 3.6.5
    • Component/s: Networking
    • Labels:
      None
    • Backwards Compatibility:
      Fully Compatible
    • Operating System:
      ALL
    • Backport Requested:
      v3.4
    • Sprint:
      Platforms 2018-05-07, Platforms 2018-05-21

      Description

      In 3.4 we introduced TransportLayerLegacy which wrapped up the legacy Listener/MessagePort classes behind a new abstraction. In 3.4, the log message

      NETWORK [thread1] connection accepted from 1.2.3.4:34397 #15 (6 connections now open) comes from here:

                  long long myConnectionNumber = globalConnectionNumber.addAndFetch(1);
       
                  if (_logConnect && !serverGlobalParams.quiet) {
                      int conns = globalTicketHolder.used() + 1;
                      const char* word = (conns == 1 ? " connection" : " connections");
                      log() << "connection accepted from " << from.toString() << " #"
                            << myConnectionNumber << " (" << conns << word << " now open)";
                  }
      

      This gets passed off to TransportLayerLegacy as an AbstractMessagingPort which gets stored in a transport:::Session, which has it's own ID created here:

      AtomicUInt64 sessionIdCounter(0);
       
      }  // namespace
       
      Session::Session() : _id(sessionIdCounter.addAndFetch(1)), _tags(kEmptyTagMask) {}
      

      A thread is started to service the connection, and the first thing it does is set the thread name here:

      void* runFunc(void* ptr) {
          std::unique_ptr<Context> ctx(static_cast<Context*>(ptr));
       
          auto tl = ctx->session->getTransportLayer();
          Client::initThread("conn", ctx->session);
          setThreadName(str::stream() << "conn" << ctx->session->id());
      

      This is what causes log messages to have their "conn" prefixes like this
      2018-04-12T22:42:17.197-0400 I - [conn15] end connection 1.2.3.4:6087 (9 connections now open)

      Because the "accepted" log message and the thread name are coming from different ID numbers, it's possible that the "conn15" log messages are not related to the number in the "connection accepted from" log messages.

        Attachments

          Activity

            People

            Assignee:
            jonathan.reams Jonathan Reams
            Reporter:
            jonathan.reams Jonathan Reams
            Participants:
            Votes:
            0 Vote for this issue
            Watchers:
            12 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: