[SERVER-30473] Denial of service from wild Created: 02/Aug/17  Updated: 30/Oct/23  Resolved: 17/Aug/17

Status: Closed
Project: Core Server
Component/s: Networking
Affects Version/s: 3.5.9
Fix Version/s: 3.5.12

Type: Bug Priority: Major - P3
Reporter: Richard Hutta Assignee: Sara Golemon
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
is duplicated by SERVER-30576 junk data on the wire causes segfault... Closed
is duplicated by SERVER-30694 Large legacy wire protocol messages c... Closed
Related
related to SERVER-30902 mongod aborts rather then just discar... Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Sprint: Platforms 2017-08-21
Participants:

 Description   

Guys Im not really sure if title is the exactly case. But to me its seems that someone from wild send message to our (authenticated) mongo and service has been restarted. Afterwards golang services connected to the mongo instance start failing with message `EOF `.

Take a look on this logs:

 2017-08-02T07:55:43.624+0000 I NETWORK  [listener] connection accepted from 139.162.253.137:38676 #484 (0 connections now open) 
 2017-08-02T07:55:44.378+0000 I NETWORK  [listener] connection accepted from 45.79.183.235:60838 #485 (0 connections now open) 
 2017-08-02T07:55:44.383+0000 I NETWORK  [conn485] received client metadata from 45.79.183.235:60838 conn: { driver: { name: "nodejs", version: "2.2.29" }, os: { type: "Linux", name: "linux", architecture: "x64", version: "4.9.15-x86_64-linode81" }, platform: "Node.js v4.4.3, LE, mongodb-core: 2.1.13" } 
 2017-08-02T07:55:44.550+0000 I NETWORK  [listener] connection accepted from 45.79.183.235:60908 #486 (0 connections now open) 
 2017-08-02T07:55:44.629+0000 I NETWORK  [listener] connection accepted from 45.79.183.235:60910 #487 (0 connections now open) 
 2017-08-02T07:55:44.630+0000 I ACCESS   [conn487] Unauthorized: not authorized on admin to execute command { listDatabases: 1, $db: "admin" } 
 2017-08-02T07:55:44.711+0000 I NETWORK  [conn486] end connection 45.79.183.235:60908 (4 connections now open) 
 2017-08-02T07:55:44.711+0000 I NETWORK  [conn487] end connection 45.79.183.235:60910 (4 connections now open) 
 2017-08-02T07:55:44.712+0000 I NETWORK  [conn485] end connection 45.79.183.235:60838 (3 connections now open) 
 2017-08-02T07:55:45.122+0000 I NETWORK  [conn484] end connection 139.162.253.137:38676 (2 connections now open) 
 2017-08-02T07:55:45.137+0000 I NETWORK  [listener] connection accepted from 139.162.253.137:38986 #488 (0 connections now open) 
 2017-08-02T07:55:46.639+0000 I NETWORK  [conn488] end connection 139.162.253.137:38986 (2 connections now open) 
 2017-08-02T07:55:46.649+0000 I NETWORK  [listener] connection accepted from 139.162.253.137:39276 #489 (0 connections now open) 
 2017-08-02T07:55:46.649+0000 I ACCESS   [conn489] Unauthorized: not authorized on test to execute command { serverStatus: 1.0, $db: "test" } 
 2017-08-02T07:55:48.162+0000 I NETWORK  [conn489] end connection 139.162.253.137:39276 (2 connections now open) 
 2017-08-02T07:55:48.244+0000 I NETWORK  [listener] connection accepted from 139.162.253.137:39630 #490 (0 connections now open) 
 2017-08-02T07:55:49.746+0000 I NETWORK  [conn490] end connection 139.162.253.137:39630 (2 connections now open) 
 2017-08-02T07:55:49.758+0000 I NETWORK  [listener] connection accepted from 139.162.253.137:39808 #491 (0 connections now open) 
 2017-08-02T07:55:51.260+0000 I NETWORK  [conn491] end connection 139.162.253.137:39808 (2 connections now open) 
 2017-08-02T07:55:51.271+0000 I NETWORK  [listener] connection accepted from 139.162.253.137:40076 #492 (0 connections now open) 
 2017-08-02T07:55:52.772+0000 I NETWORK  [conn492] end connection 139.162.253.137:40076 (2 connections now open) 
 2017-08-02T07:55:52.784+0000 I NETWORK  [listener] connection accepted from 139.162.253.137:40402 #493 (0 connections now open) 
 2017-08-02T07:55:52.784+0000 I NETWORK  [conn493] Error receiving request from client: SSLHandshakeFailed: SSLHandshakeFailed. Ending connection from 139.162.253.137:40402 (connection id: 493) 
 2017-08-02T07:55:52.784+0000 I NETWORK  [conn493] end connection 139.162.253.137:40402 (2 connections now open) 
 2017-08-02T07:55:52.807+0000 I NETWORK  [listener] connection accepted from 139.162.253.137:40408 #494 (0 connections now open) 
 2017-08-02T07:55:52.807+0000 I NETWORK  [conn494] Error receiving request from client: SSLHandshakeFailed: SSLHandshakeFailed. Ending connection from 139.162.253.137:40408 (connection id: 494) 
 2017-08-02T07:55:52.807+0000 I NETWORK  [conn494] end connection 139.162.253.137:40408 (2 connections now open) 
 2017-08-02T07:55:52.832+0000 I NETWORK  [listener] connection accepted from 139.162.253.137:40412 #495 (0 connections now open) 
 2017-08-02T07:55:52.832+0000 I NETWORK  [conn495] Error receiving request from client: SSLHandshakeFailed: SSLHandshakeFailed. Ending connection from 139.162.253.137:40412 (connection id: 495) 
 2017-08-02T07:55:52.832+0000 I NETWORK  [conn495] end connection 139.162.253.137:40412 (2 connections now open) 
 2017-08-02T07:55:52.858+0000 I NETWORK  [listener] connection accepted from 139.162.253.137:40418 #496 (0 connections now open) 
 2017-08-02T07:55:52.858+0000 I NETWORK  [conn496] recv(): message msgLen 671088768 is invalid. Min 16 Max: 48000000 
 2017-08-02T07:55:52.858+0000 F -        [conn496] Invariant failure !_inMessage.empty() src/mongo/transport/service_state_machine.cpp 162 
 2017-08-02T07:55:52.858+0000 F -        [conn496]  
 ***aborting after invariant() failure 
 2017-08-02T07:55:52.890+0000 F -        [conn496] Got signal: 6 (Aborted). 
  0x55c62aed9491 0x55c62aed86a9 0x55c62aed8b8d 0x7f8003cd6890 0x7f8003951067 0x7f8003952448 0x55c62982cff2 0x55c629ac64e8 0x55c629ac4714 0x55c629ac3a88 0x55c62ad670e4 0x7f8003ccf064 0x7f8003a0462d 
 ----- BEGIN BACKTRACE ----- 
  mongod(_ZN5mongo15printStackTraceERSo+0x41) [0x55c62aed9491] 
  mongod(+0x1F116A9) [0x55c62aed86a9] 
  mongod(+0x1F11B8D) [0x55c62aed8b8d] 
  libpthread.so.0(+0xF890) [0x7f8003cd6890] 
  libc.so.6(gsignal+0x37) [0x7f8003951067] 
  libc.so.6(abort+0x148) [0x7f8003952448] 
  mongod(_ZN5mongo17invariantOKFailedEPKcRKNS_6StatusES1_j+0x0) [0x55c62982cff2] 
  mongod(_ZN5mongo19ServiceStateMachine14processMessageEv+0x988) [0x55c629ac64e8] 
  mongod(_ZN5mongo19ServiceStateMachine7runNextEv+0x254) [0x55c629ac4714] 
  mongod(+0xAFCA88) [0x55c629ac3a88] 
  mongod(+0x1DA00E4) [0x55c62ad670e4] 
  libpthread.so.0(+0x8064) [0x7f8003ccf064] 
  libc.so.6(clone+0x6D) [0x7f8003a0462d] 
 -----  END BACKTRACE  ----- 
 2017-08-02T07:55:55.070+0000 I CONTROL  [initandlisten] MongoDB starting : pid=1 port=27017 dbpath=/data/db 64-bit host=87ddc89b0e06 
 2017-08-02T07:55:55.071+0000 I CONTROL  [initandlisten] db version v3.5.9 
 2017-08-02T07:55:55.071+0000 I CONTROL  [initandlisten] git version: d5e9b4994557285017795d9ed9129341314da202 
 2017-08-02T07:55:55.072+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1t  3 May 2016 
 2017-08-02T07:55:55.072+0000 I CONTROL  [initandlisten] allocator: tcmalloc 
 2017-08-02T07:55:55.072+0000 I CONTROL  [initandlisten] modules: none 
 2017-08-02T07:55:55.072+0000 I CONTROL  [initandlisten] build environment: 
 2017-08-02T07:55:55.072+0000 I CONTROL  [initandlisten]     distmod: debian81 
 2017-08-02T07:55:55.072+0000 I CONTROL  [initandlisten]     distarch: x86_64 
 2017-08-02T07:55:55.072+0000 I CONTROL  [initandlisten]     target_arch: x86_64 
 2017-08-02T07:55:55.072+0000 I CONTROL  [initandlisten] options: { net: { bindIpAll: true }, security: { authorization: "enabled" }, storage: { engine: "wiredTiger" } } 
 2017-08-02T07:55:55.072+0000 W -        [initandlisten] Detected unclean shutdown - /data/db/mongod.lock is not empty. 
 2017-08-02T07:55:55.073+0000 W STORAGE  [initandlisten] Recovering data from the last clean checkpoint. 
 2017-08-02T07:55:55.074+0000 I STORAGE  [initandlisten]  
 2017-08-02T07:55:55.074+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine 
 2017-08-02T07:55:55.074+0000 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem 
 2017-08-02T07:55:55.074+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=1369M,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-08-02T07:55:55.178+0000 I STORAGE  [initandlisten] WiredTiger message [1501660555:178135][1:0x7f20b5c79d40], txn-recover: Main recovery loop: starting at 20/32106368 
 2017-08-02T07:55:55.179+0000 I STORAGE  [initandlisten] WiredTiger message [1501660555:179041][1:0x7f20b5c79d40], txn-recover: Recovering log 20 through 21 
 2017-08-02T07:55:55.179+0000 I STORAGE  [initandlisten] WiredTiger message [1501660555:179729][1:0x7f20b5c79d40], txn-recover: Recovering log 21 through 21 
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten]  
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten] ** NOTE: This is a development version (3.5.9) of MongoDB. 
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten] **       Not recommended for production. 
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten]  
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten]  
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'. 
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten] **        We suggest setting it to 'never' 
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten]  
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'. 
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten] **        We suggest setting it to 'never' 
 2017-08-02T07:55:55.272+0000 I CONTROL  [initandlisten]  
 2017-08-02T07:55:55.281+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data' 
 2017-08-02T07:55:55.437+0000 I NETWORK  [listener] connection accepted from 10.42.103.91:45582 #1 (0 connections now open) 
 2017-08-02T07:55:56.007+0000 I FTDC     [ftdc] Unclean full-time diagnostic data capture shutdown detected, found interim file, some metrics may have been lost. OK 



 Comments   
Comment by Githook User [ 17/Aug/17 ]

Author:

{'username': 'sgolemon', 'email': 'sara.golemon@mongodb.com', 'name': 'Sara Golemon'}

Message: SERVER-30473 Invalid return from message packet length check
Branch: master
https://github.com/mongodb/mongo/commit/3c2e253dd0a2cb9b5cee72205eafd48c4d78b324

Comment by Richard Hutta [ 03/Aug/17 ]

No problem. Hope we will solve the issue.
Btw I was running docker container.

  mongodb:
    image: mongo:3.5
    volumes:
      - /home/ubuntu/docker-mongo:/data/db
    command: --storageEngine wiredTiger --bind_ip_all --auth
    ports:
      - 27017:27017
      - 28017:28017
    expose:
      - 28017

Comment by Sara Golemon [ 02/Aug/17 ]

Apologies for that "Waiting for user input" spam. I mis-clicked.
The report was excellent and the underlying cause was easily identified, a fix is forthcoming.

Comment by Andrew Morrow (Inactive) [ 02/Aug/17 ]

Hi huttarichard

Thank you for the bug report. Clearly, a pre-auth denial of service is a serious issue. Please note however that you are running a development version of MongoDB. I would strongly advise against running such a version in a production environment, or in an environment exposed to the open internet. Note that you have started the server with the bindIpAll parameter set to true. This is particularly risky with a development version of MongoDB as there are new features in states of partial evolution, which may expose you to unnecessary security risks.

It appears as if someone sent a malformed wire protocol message, which was detected. However, due to an overly strong invariant introduced in some recent changes to our networking stack, this led to a server shutdown.

My recommendation would be to downgrade your server to a stable release of MongoDB (probably 3.4). On our end, we will ensure that the most recent development versions of MongoDB are not subject to this behavior.

Comment by Richard Hutta [ 02/Aug/17 ]

Btw I forgot to mention. We are not using node js for mongo at all. The node js is attacker from outside.

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