[SERVER-28831] Log which compressor is being used for decompressing Created: 17/Apr/17  Updated: 19/Feb/20  Resolved: 19/Apr/17

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: 3.4.3, 3.5.6
Fix Version/s: 3.5.7

Type: Improvement Priority: Major - P3
Reporter: Hannes Magnusson Assignee: Jonathan Reams
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
related to SERVER-28986 Improve compression negotiation logging Closed
Backwards Compatibility: Fully Compatible
Sprint: Platforms 2017-05-08
Participants:

 Description   

When running mongod with

mongod --networkMessageCompressors=snappy -vvv

It will issue a log message when compressing an outbound message, like so:

2017-04-17T14:17:43.346-0700 D NETWORK  [conn4] Compressing message with snappy

There is however no such log when decompressing an inbound message.
This is an improvement request to add

2017-04-17T14:17:43.346-0700 D NETWORK  [conn4] Decompressing message with snappy



 Comments   
Comment by Githook User [ 19/Apr/17 ]

Author:

{u'username': u'bjori', u'name': u'Hannes Magnusson', u'email': u'bjori@php.net'}

Message: SERVER-28831 Log which compressor is being used for decompressing

Closes #1146

Signed-off-by: Jonathan Reams <jbreams@mongodb.com>
Branch: master
https://github.com/mongodb/mongo/commit/d54dabeb93b36e4ce2a67ea35dba1f57e1298f4f

Comment by Hannes Magnusson [ 17/Apr/17 ]

After the PR, the log for connecting, issuing isMaster, then ping, then disconnecting becomes:

2017-04-17T14:52:27.720-0700 I NETWORK  [thread1] connection accepted from 127.0.0.1:56950 #3 (1 connection now open)
2017-04-17T14:52:27.720-0700 D COMMAND  [conn3] run command admin.$cmd { isMaster: 1, client: { driver: { name: "mongoc", version: "1.7.0-dev" }, os: { type: "Linux", name: "Ubuntu", version: "16.10", architecture: "x86_64" }, platform: "cfg=0xeb8e9 posix=200809 stdc=201112 CC=GCC 6.2.0 20161005 CFLAGS="" LDFLAGS=""" }, compression: [ "snappy" ] }
2017-04-17T14:52:27.720-0700 I NETWORK  [conn3] received client metadata from 127.0.0.1:56950 conn3: { driver: { name: "mongoc", version: "1.7.0-dev" }, os: { type: "Linux", name: "Ubuntu", version: "16.10", architecture: "x86_64" }, platform: "cfg=0xeb8e9 posix=200809 stdc=201112 CC=GCC 6.2.0 20161005 CFLAGS="" LDFLAGS=""" }
2017-04-17T14:52:27.720-0700 D NETWORK  [conn3] Starting server-side compression negotiation
2017-04-17T14:52:27.720-0700 D NETWORK  [conn3] snappy is supported
2017-04-17T14:52:27.720-0700 I COMMAND  [conn3] command admin.$cmd command: isMaster { isMaster: 1, client: { driver: { name: "mongoc", version: "1.7.0-dev" }, os: { type: "Linux", name: "Ubuntu", version: "16.10", architecture: "x86_64" }, platform: "cfg=0xeb8e9 posix=200809 stdc=201112 CC=GCC 6.2.0 20161005 CFLAGS="" LDFLAGS=""" }, compression: [ "snappy" ] } numYields:0 reslen:221 locks:{} protocol:op_query 0ms
2017-04-17T14:52:27.720-0700 D NETWORK  [conn3] Compressing message with snappy
2017-04-17T14:52:27.720-0700 D NETWORK  [conn3] Decompressing message with snappy
2017-04-17T14:52:27.720-0700 D COMMAND  [conn3] run command test.$cmd { ping: 1, $comment: 1 }
2017-04-17T14:52:27.720-0700 I COMMAND  [conn3] command test.$cmd command: ping { ping: 1, $comment: 1 } numYields:0 reslen:37 locks:{} protocol:op_query 0ms
2017-04-17T14:52:27.720-0700 D NETWORK  [conn3] Compressing message with snappy
2017-04-17T14:52:27.721-0700 D NETWORK  [conn3] Socket recv() conn closed? 127.0.0.1:56950
2017-04-17T14:52:27.721-0700 D NETWORK  [conn3] SocketException: remote: 127.0.0.1:56950 error: 9001 socket exception [CLOSED] server [127.0.0.1:56950] 
2017-04-17T14:52:27.721-0700 I -        [conn3] end connection 127.0.0.1:56950 (1 connection now open)

Comment by Hannes Magnusson [ 17/Apr/17 ]

Created a Pull Request for this to master

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