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

Thread name and connection number are not synchronized in TransportLayerLegacy

    • Type: Icon: Bug Bug
    • Resolution: Fixed
    • Priority: Icon: Major - P3 Major - P3
    • 3.4.16, 3.6.5
    • Affects Version/s: 3.4.0, 3.6.0
    • Component/s: Networking
    • Labels:
      None
    • Fully Compatible
    • ALL
    • v3.4
    • Platforms 2018-05-07, Platforms 2018-05-21

      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.

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

              Created:
              Updated:
              Resolved: