[JAVA-2692] NullPointerException logged when compression is enabled Created: 06/Dec/17  Updated: 28/Oct/23  Resolved: 11/Dec/17

Status: Closed
Project: Java Driver
Component/s: Internal
Affects Version/s: 3.6.0
Fix Version/s: 3.6.1

Type: Bug Priority: Minor - P4
Reporter: Scott Lipcon Assignee: Jeffrey Yemin
Resolution: Fixed Votes: 1
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

MacOS, server 3.6.0, java-driver 3.6.0



 Description   

When I enable client side compression, either zlib or snappy, I get tons of NullPointerExceptions thrown:

     [java] java.lang.NullPointerException
     [java] 	at com.mongodb.connection.ProtocolHelper.sendCommandStartedEvent(ProtocolHelper.java:253)
     [java] 	at com.mongodb.connection.InternalStreamConnection$CommandEventSender.sendStartedEvent(InternalStreamConnection.java:684)
     [java] 	at com.mongodb.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:245)
     [java] 	at com.mongodb.connection.UsageTrackingInternalConnection.sendAndReceive(UsageTrackingInternalConnection.java:98)
     [java] 	at com.mongodb.connection.DefaultConnectionPool$PooledConnection.sendAndReceive(DefaultConnectionPool.java:441)
     [java] 	at com.mongodb.connection.CommandProtocolImpl.execute(CommandProtocolImpl.java:76)
     [java] 	at com.mongodb.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:189)
     [java] 	at com.mongodb.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:263)
     [java] 	at com.mongodb.connection.DefaultServerConnection.command(DefaultServerConnection.java:126)
     [java] 	at com.mongodb.connection.DefaultServerConnection.command(DefaultServerConnection.java:118)
     [java] 	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:226)
     [java] 	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:217)
     [java] 	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:154)
     [java] 	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:147)
     [java] 	at com.mongodb.operation.CreateIndexesOperation$1.call(CreateIndexesOperation.java:173)
     [java] 	at com.mongodb.operation.CreateIndexesOperation$1.call(CreateIndexesOperation.java:168)
     [java] 	at com.mongodb.operation.OperationHelper.withConnectionSource(OperationHelper.java:461)
     [java] 	at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:423)
     [java] 	at com.mongodb.operation.CreateIndexesOperation.execute(CreateIndexesOperation.java:168)
     [java] 	at com.mongodb.operation.CreateIndexesOperation.execute(CreateIndexesOperation.java:69)
     [java] 	at com.mongodb.Mongo$3.execute(Mongo.java:833)
     [java] 	at com.mongodb.Mongo$3.execute(Mongo.java:814)
     [java] 	at com.mongodb.DBCollection.createIndex(DBCollection.java:1623)
     [java] 	at com.mongodb.DBCollection.createIndex(DBCollection.java:1608)
....



 Comments   
Comment by Githook User [ 11/Dec/17 ]

Author:

{'name': 'Jeff Yemin', 'email': 'jeff.yemin@10gen.com', 'username': 'jyemin'}

Message: JAVA-2692: Only attempt to send command started event when there is a command listener and the connection handshake is complete
Branch: 3.6.x
https://github.com/mongodb/mongo-java-driver/commit/fdef54955bdf51825e6c1725fd0ae2ab662e50bd

Comment by Githook User [ 11/Dec/17 ]

Author:

{'name': 'Jeff Yemin', 'email': 'jeff.yemin@10gen.com', 'username': 'jyemin'}

Message: JAVA-2692: Only attempt to send command started event when there is a command listener and the connection handshake is complete
Branch: master
https://github.com/mongodb/mongo-java-driver/commit/365fefe44ce111581e58d8b8959e134ee3995c04

Comment by Scott Lipcon [ 08/Dec/17 ]

Jeff - sorry this isn't more scientific - but using wireshark I was able to see that when I request no compression from my client, the data is in semi-plain text - e.g. I can see very readable snippets of strings from my data in the stream. When I enable zlib compression, the data is completely binary, so that appears to be working - although at an initial glance, the bandwidth is not significantly less, and my application's performance is not significantly better.

When I enable snappy compression, the data looks to be plain text - I did read that snappy requires some additional dependency jars, which I installed (snappy-java-1.1.7.jar) but it doesn't appear to be working - I don't see any errors or warnings either with or without that jar on my classpath. Although realistically since the zlib compression didn't seem to help my performance, I don't think snappy would either. Back to trying to do smarter queries.... thanks for your help.

Comment by Scott Lipcon [ 08/Dec/17 ]

I tried both zlib and snappy. Both are enabled on my server, and I tried enabling them one at a time in the MongoClientOptions. I was out of the office today at a meeting, so I didn't have time yet to investigate further - I will try to do that tomorrow and get back to you. Is this jira ticket appropriate for further discussion or is there a better avenue? (Note that I upgraded our codebase to 3.6.0 specifically to try compression, to help with a performance issue - I suspect there are other approaches in terms of smarter formatting of the documents on disk to enable better queries, etc, but was hoping compression would help. )

Comment by Jeffrey Yemin [ 06/Dec/17 ]

Interesting. Which compressor did you enable?

Comment by Scott Lipcon [ 06/Dec/17 ]

Thanks - I didn't realize it was only a logging issue - I see next to no performance gain by using compression unfortunately for my workload. Need to confirm with wireshark or similar that the utilized bandwidth is actually less.

Comment by Jeffrey Yemin [ 06/Dec/17 ]

I've reproduced the issue. Our regression tests didn't catch this because the exception doesn't actually escape the driver. Rather, what you're seeing is the driver's own logging of the exception here. If you want to suppress those log messages, set the logging level for "org.mongodb.driver.protocol.event" to ERROR.

Generated at Thu Feb 08 08:57:51 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.