ASIO listener always logs "(0 connections now open)" on accept

XMLWordPrintableJSON

    • Type: Bug
    • Resolution: Gone away
    • Priority: Critical - P2
    • None
    • Affects Version/s: 3.5.9
    • Component/s: Networking
    • None
    • Fully Compatible
    • ALL
    • Platforms 2017-07-31
    • None
    • 0
    • None
    • None
    • None
    • None
    • None
    • None

      ASIO ingress:

      $ ./mongo --port 12345 --eval 'for(i=0;i<5;i++){connect("localhost:12345");print(db.serverStatus().connections.current)}'
      MongoDB shell version v3.5.9-105-g0ab7f73
      connecting to: mongodb://127.0.0.1:12345/
      MongoDB server version: 3.5.9-105-g0ab7f73
      connecting to: localhost:12345
      MongoDB server version: 3.5.9-105-g0ab7f73
      2
      connecting to: localhost:12345
      MongoDB server version: 3.5.9-105-g0ab7f73
      3
      connecting to: localhost:12345
      MongoDB server version: 3.5.9-105-g0ab7f73
      4
      connecting to: localhost:12345
      MongoDB server version: 3.5.9-105-g0ab7f73
      5
      connecting to: localhost:12345
      MongoDB server version: 3.5.9-105-g0ab7f73
      6
      
      $ ./mongod --port 12345
      2017-07-07T03:46:05.195+0000 I CONTROL  [initandlisten] MongoDB starting : pid=20989 port=12345 dbpath=/data/db 64-bit host=devkev-1
      2017-07-07T03:46:05.195+0000 I CONTROL  [initandlisten] db version v3.5.9-105-g0ab7f73
      2017-07-07T03:46:05.195+0000 I CONTROL  [initandlisten] git version: 0ab7f732e0bee535383dd6dcda400999a1eee6b2
      2017-07-07T03:46:05.195+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1f 6 Jan 2014
      2017-07-07T03:46:05.195+0000 I CONTROL  [initandlisten] allocator: tcmalloc
      2017-07-07T03:46:05.195+0000 I CONTROL  [initandlisten] modules: none
      2017-07-07T03:46:05.195+0000 I CONTROL  [initandlisten] build environment:
      2017-07-07T03:46:05.196+0000 I CONTROL  [initandlisten]     distarch: x86_64
      2017-07-07T03:46:05.196+0000 I CONTROL  [initandlisten]     target_arch: x86_64
      2017-07-07T03:46:05.196+0000 I CONTROL  [initandlisten] options: { net: { port: 12345 } }
      2017-07-07T03:46:05.196+0000 I -        [initandlisten] Detected data files in /data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
      2017-07-07T03:46:05.196+0000 I STORAGE  [initandlisten]
      2017-07-07T03:46:05.196+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
      2017-07-07T03:46:05.196+0000 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
      2017-07-07T03:46:05.196+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=7008M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress),
      2017-07-07T03:46:05.297+0000 I STORAGE  [initandlisten] WiredTiger message [1499399165:297905][20989:0x7fb27208ed40], txn-recover: Main recovery loop: starting at 13/5504
      2017-07-07T03:46:05.343+0000 I STORAGE  [initandlisten] WiredTiger message [1499399165:342989][20989:0x7fb27208ed40], txn-recover: Recovering log 13 through 14
      2017-07-07T03:46:05.343+0000 I STORAGE  [initandlisten] WiredTiger message [1499399165:343809][20989:0x7fb27208ed40], txn-recover: Recovering log 14 through 14
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten]
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten] ** NOTE: This is a development version (3.5.9-105-g0ab7f73) of MongoDB.
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten] **       Not recommended for production.
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten]
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten]
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten] ** WARNING: This server is bound to localhost.
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten] **          Remote systems will be unable to connect to this server.
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten] **          Start the server with --bind_ip <address> to specify which IP
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten] **          addressses it should serve responses from, or with --bind_ip_all to
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten] **          bind to all interfaces. If this behavior is desired, start the
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten] **          server with --bind_ip 127.0.0.1 to disable this warning.
      2017-07-07T03:46:05.440+0000 I CONTROL  [initandlisten]
      2017-07-07T03:46:05.442+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data'
      2017-07-07T03:46:09.866+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:46923 #1 (0 connections now open)
      2017-07-07T03:46:09.866+0000 I NETWORK  [conn1] received client metadata from 127.0.0.1:46923 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:46:09.867+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:46924 #3 (0 connections now open)
      2017-07-07T03:46:09.867+0000 I NETWORK  [conn3] received client metadata from 127.0.0.1:46924 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:46:09.871+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:46925 #4 (0 connections now open)
      2017-07-07T03:46:09.872+0000 I NETWORK  [conn4] received client metadata from 127.0.0.1:46925 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:46:09.875+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:46926 #5 (0 connections now open)
      2017-07-07T03:46:09.875+0000 I NETWORK  [conn5] received client metadata from 127.0.0.1:46926 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:46:09.878+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:46927 #6 (0 connections now open)
      2017-07-07T03:46:09.878+0000 I NETWORK  [conn6] received client metadata from 127.0.0.1:46927 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:46:09.881+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:46928 #7 (0 connections now open)
      2017-07-07T03:46:09.881+0000 I NETWORK  [conn7] received client metadata from 127.0.0.1:46928 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:46:09.886+0000 I NETWORK  [conn1] end connection 127.0.0.1:46923 (5 connections now open)
      2017-07-07T03:46:09.886+0000 I NETWORK  [conn3] end connection 127.0.0.1:46924 (3 connections now open)
      2017-07-07T03:46:09.886+0000 I NETWORK  [conn4] end connection 127.0.0.1:46925 (3 connections now open)
      2017-07-07T03:46:09.886+0000 I NETWORK  [conn5] end connection 127.0.0.1:46926 (2 connections now open)
      2017-07-07T03:46:09.886+0000 I NETWORK  [conn6] end connection 127.0.0.1:46927 (1 connection now open)
      2017-07-07T03:46:09.886+0000 I NETWORK  [conn7] end connection 127.0.0.1:46928 (0 connections now open)
      ^C2017-07-07T03:50:07.523+0000 I CONTROL  [signalProcessingThread] got signal 2 (Interrupt), will terminate after current cmd ends
      2017-07-07T03:50:07.524+0000 I NETWORK  [signalProcessingThread] shutdown: going to close listening sockets...
      2017-07-07T03:50:07.524+0000 I NETWORK  [signalProcessingThread] shutdown: going to flush diaglog...
      2017-07-07T03:50:07.524+0000 I FTDC     [signalProcessingThread] Shutting down full-time diagnostic data capture
      2017-07-07T03:50:07.526+0000 I STORAGE  [signalProcessingThread] WiredTigerKVEngine shutting down
      2017-07-07T03:50:07.570+0000 I STORAGE  [signalProcessingThread] shutdown: removing fs lock...
      2017-07-07T03:50:07.570+0000 I CONTROL  [signalProcessingThread] now exiting
      2017-07-07T03:50:07.571+0000 I CONTROL  [signalProcessingThread] shutting down with code:0
      

      Legacy transport

      $ ./mongo --port 12345 --eval 'for(i=0;i<5;i++){connect("localhost:12345");print(db.serverStatus().connections.current)}'
      MongoDB shell version v3.5.9-105-g0ab7f73
      connecting to: mongodb://127.0.0.1:12345/
      MongoDB server version: 3.5.9-105-g0ab7f73
      connecting to: localhost:12345
      MongoDB server version: 3.5.9-105-g0ab7f73
      2
      connecting to: localhost:12345
      MongoDB server version: 3.5.9-105-g0ab7f73
      3
      connecting to: localhost:12345
      MongoDB server version: 3.5.9-105-g0ab7f73
      4
      connecting to: localhost:12345
      MongoDB server version: 3.5.9-105-g0ab7f73
      5
      connecting to: localhost:12345
      MongoDB server version: 3.5.9-105-g0ab7f73
      6
      
      $ ./mongod --port 12345 --transportLayer legacy
      2017-07-07T03:50:59.504+0000 I CONTROL  [initandlisten] MongoDB starting : pid=22400 port=12345 dbpath=/data/db 64-bit host=devkev-1
      2017-07-07T03:50:59.504+0000 I CONTROL  [initandlisten] db version v3.5.9-105-g0ab7f73
      2017-07-07T03:50:59.504+0000 I CONTROL  [initandlisten] git version: 0ab7f732e0bee535383dd6dcda400999a1eee6b2
      2017-07-07T03:50:59.504+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1f 6 Jan 2014
      2017-07-07T03:50:59.504+0000 I CONTROL  [initandlisten] allocator: tcmalloc
      2017-07-07T03:50:59.504+0000 I CONTROL  [initandlisten] modules: none
      2017-07-07T03:50:59.504+0000 I CONTROL  [initandlisten] build environment:
      2017-07-07T03:50:59.504+0000 I CONTROL  [initandlisten]     distarch: x86_64
      2017-07-07T03:50:59.504+0000 I CONTROL  [initandlisten]     target_arch: x86_64
      2017-07-07T03:50:59.504+0000 I CONTROL  [initandlisten] options: { net: { port: 12345, transportLayer: "legacy" } }
      2017-07-07T03:50:59.524+0000 I -        [initandlisten] Detected data files in /data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
      2017-07-07T03:50:59.524+0000 I STORAGE  [initandlisten]
      2017-07-07T03:50:59.524+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
      2017-07-07T03:50:59.524+0000 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
      2017-07-07T03:50:59.524+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=7008M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress),
      2017-07-07T03:50:59.630+0000 I STORAGE  [initandlisten] WiredTiger message [1499399459:630737][22400:0x7fb802905d40], txn-recover: Main recovery loop: starting at 14/5376
      2017-07-07T03:50:59.675+0000 I STORAGE  [initandlisten] WiredTiger message [1499399459:675716][22400:0x7fb802905d40], txn-recover: Recovering log 14 through 15
      2017-07-07T03:50:59.676+0000 I STORAGE  [initandlisten] WiredTiger message [1499399459:676449][22400:0x7fb802905d40], txn-recover: Recovering log 15 through 15
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten]
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten] ** NOTE: This is a development version (3.5.9-105-g0ab7f73) of MongoDB.
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten] **       Not recommended for production.
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten]
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten]
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten] ** WARNING: This server is bound to localhost.
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten] **          Remote systems will be unable to connect to this server.
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten] **          Start the server with --bind_ip <address> to specify which IP
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten] **          addressses it should serve responses from, or with --bind_ip_all to
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten] **          bind to all interfaces. If this behavior is desired, start the
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten] **          server with --bind_ip 127.0.0.1 to disable this warning.
      2017-07-07T03:50:59.771+0000 I CONTROL  [initandlisten]
      2017-07-07T03:50:59.773+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data'
      2017-07-07T03:50:59.773+0000 I NETWORK  [thread1] waiting for connections on port 12345
      2017-07-07T03:51:05.262+0000 I NETWORK  [thread1] connection accepted from 127.0.0.1:47428 #1 (1 connection now open)
      2017-07-07T03:51:05.262+0000 I NETWORK  [conn1] received client metadata from 127.0.0.1:47428 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:51:05.263+0000 I NETWORK  [thread1] connection accepted from 127.0.0.1:47429 #2 (2 connections now open)
      2017-07-07T03:51:05.263+0000 I NETWORK  [conn2] received client metadata from 127.0.0.1:47429 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:51:05.267+0000 I NETWORK  [thread1] connection accepted from 127.0.0.1:47430 #3 (3 connections now open)
      2017-07-07T03:51:05.268+0000 I NETWORK  [conn3] received client metadata from 127.0.0.1:47430 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:51:05.271+0000 I NETWORK  [thread1] connection accepted from 127.0.0.1:47431 #4 (4 connections now open)
      2017-07-07T03:51:05.271+0000 I NETWORK  [conn4] received client metadata from 127.0.0.1:47431 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:51:05.274+0000 I NETWORK  [thread1] connection accepted from 127.0.0.1:47432 #5 (5 connections now open)
      2017-07-07T03:51:05.274+0000 I NETWORK  [conn5] received client metadata from 127.0.0.1:47432 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:51:05.277+0000 I NETWORK  [thread1] connection accepted from 127.0.0.1:47433 #6 (6 connections now open)
      2017-07-07T03:51:05.277+0000 I NETWORK  [conn6] received client metadata from 127.0.0.1:47433 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.5.9-105-g0ab7f73" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "14.04" } }
      2017-07-07T03:51:05.282+0000 I NETWORK  [conn1] end connection 127.0.0.1:47428 (5 connections now open)
      2017-07-07T03:51:05.282+0000 I NETWORK  [conn3] end connection 127.0.0.1:47430 (4 connections now open)
      2017-07-07T03:51:05.282+0000 I NETWORK  [conn5] end connection 127.0.0.1:47432 (1 connection now open)
      2017-07-07T03:51:05.282+0000 I NETWORK  [conn4] end connection 127.0.0.1:47431 (2 connections now open)
      2017-07-07T03:51:05.282+0000 I NETWORK  [conn6] end connection 127.0.0.1:47433 (0 connections now open)
      2017-07-07T03:51:05.282+0000 I NETWORK  [conn2] end connection 127.0.0.1:47429 (2 connections now open)
      ^C2017-07-07T03:53:55.145+0000 I CONTROL  [signalProcessingThread] got signal 2 (Interrupt), will terminate after current cmd ends
      2017-07-07T03:53:55.145+0000 I NETWORK  [signalProcessingThread] shutdown: going to close listening sockets...
      2017-07-07T03:53:55.146+0000 I NETWORK  [signalProcessingThread] closing listening socket: 7
      2017-07-07T03:53:55.146+0000 I NETWORK  [signalProcessingThread] closing listening socket: 8
      2017-07-07T03:53:55.146+0000 I NETWORK  [signalProcessingThread] removing socket file: /tmp/mongodb-12345.sock
      2017-07-07T03:53:55.146+0000 I NETWORK  [signalProcessingThread] shutdown: going to flush diaglog...
      2017-07-07T03:53:55.146+0000 I FTDC     [signalProcessingThread] Shutting down full-time diagnostic data capture
      2017-07-07T03:53:55.148+0000 I STORAGE  [signalProcessingThread] WiredTigerKVEngine shutting down
      2017-07-07T03:53:55.222+0000 I STORAGE  [signalProcessingThread] shutdown: removing fs lock...
      2017-07-07T03:53:55.222+0000 I CONTROL  [signalProcessingThread] now exiting
      2017-07-07T03:53:55.222+0000 I CONTROL  [signalProcessingThread] shutting down with code:0
      

            Assignee:
            Henrik Edin
            Reporter:
            Kevin Pulo
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

              Created:
              Updated:
              Resolved: