[SERVER-34823] Thread name and connection number are not synchronized in TransportLayerLegacy Created: 03/May/18  Updated: 29/Oct/23  Resolved: 09/May/18

Status: Closed
Project: Core Server
Component/s: Networking
Affects Version/s: 3.4.0, 3.6.0
Fix Version/s: 3.4.16, 3.6.5

Type: Bug Priority: Major - P3
Reporter: Jonathan Reams Assignee: Jonathan Reams
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Related
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Requested:
v3.4
Sprint: Platforms 2018-05-07, Platforms 2018-05-21
Participants:

 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.



 Comments   
Comment by Githook User [ 19/Jun/18 ]

Author:

{'username': 'jbreams', 'name': 'Jonathan Reams', 'email': 'jbreams@mongodb.com'}

Message: SERVER-34823 Make sure LegacySession ID's match their MessagingPort connection ID

(cherry picked from commit dd7de2240e42ea384d3804634522739618a6da0a)
Branch: v3.4
https://github.com/mongodb/mongo/commit/1f9f74c540e36d6edff36b5ae04c7132d2e65c41

Comment by Githook User [ 09/May/18 ]

Author:

{'email': 'jbreams@mongodb.com', 'name': 'Jonathan Reams', 'username': 'jbreams'}

Message: SERVER-34823 Make sure LegacySession ID's match their MessagingPort connection ID
Branch: v3.6
https://github.com/mongodb/mongo/commit/dd7de2240e42ea384d3804634522739618a6da0a

Generated at Thu Feb 08 04:37:58 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.