Loading...

Type: Bug
Resolution: Fixed
Priority: Major - P3
Fix Version/s: 2.12.2, 2.13.0.rc1
Affects Version/s: 2.12.1
Component/s: Wire Protocol
Labels:
- next-release
Environment:
Mongoid 7.1.1
Mongodb 4.2.6

Confidence Status:
None

Aha! Reference:
None
Tracking Level:
None
Risk Status:
None
Exec Notes:
None
Goal Name:
None
Goal Link:
None

I juste noticed this when upgrading Mongoid, the mongo driver went from 2.11.4 to 2.12.1 and now every request fails with this error message:

Attempted to read 518821760 bytes, but only 135 bytes remain (RangeError)

Here is a reproduction script:

require 'mongoid'

client = Mongo::Client.new('mongodb://127.0.0.1:27017/test?compressors=zlib')
Mongo::Logger.logger.level = :warn

puts Mongo::VERSION
puts client.database.collection_names

Output with 2.11.4:

> ruby mongo-zlib.rb 
D, [2020-05-01T15:09:55.543368 #29022] DEBUG -- : MONGODB | EVENT: #<TopologyOpening topology=Unknown[]>
D, [2020-05-01T15:09:55.543405 #29022] DEBUG -- : MONGODB | Topology type 'unknown' initializing.
D, [2020-05-01T15:09:55.543496 #29022] DEBUG -- : MONGODB | EVENT: #<TopologyChanged prev=Unknown[] new=Unknown[127.0.0.1:27017]>
D, [2020-05-01T15:09:55.543518 #29022] DEBUG -- : MONGODB | Topology type 'Unknown' changed to type 'Unknown'.
D, [2020-05-01T15:09:55.543593 #29022] DEBUG -- : MONGODB | EVENT: #<ServerOpening address=127.0.0.1:27017 topology=Unknown[127.0.0.1:27017]>
D, [2020-05-01T15:09:55.543611 #29022] DEBUG -- : MONGODB | Server 127.0.0.1:27017 initializing.
D, [2020-05-01T15:09:55.543680 #29022] DEBUG -- : MONGODB | Waiting for up to 30.00 seconds for servers to be scanned: #<Cluster topology=Unknown[127.0.0.1:27017] servers=[#<Server address=127.0.0.1:27017 UNKNOWN>]>
D, [2020-05-01T15:09:55.544448 #29022] DEBUG -- : MONGODB | EVENT: #<ServerDescriptionChanged address=127.0.0.1:27017 topology=Single[127.0.0.1:27017] prev=#<Mongo::Server:Description:0x70120735093560 config={} average_round_trip_time=> new=#<Mongo::Server:Description:0x70120735105880 config={"ismaster"=>true, "maxBsonObjectSize"=>16777216, "maxMessageSizeBytes"=>48000000, "maxWriteBatchSize"=>100000, "localTime"=>2020-05-01 13:09:55 UTC, "logicalSessionTimeoutMinutes"=>30, "connectionId"=>635, "minWireVersion"=>0, "maxWireVersion"=>8, "readOnly"=>false, "compression"=>["zlib"], "ok"=>1.0} average_round_trip_time=0.000607605>>
D, [2020-05-01T15:09:55.544481 #29022] DEBUG -- : MONGODB | Server description for 127.0.0.1:27017 changed from 'unknown' to 'standalone'.
D, [2020-05-01T15:09:55.544551 #29022] DEBUG -- : MONGODB | EVENT: #<TopologyChanged prev=Unknown[127.0.0.1:27017] new=Single[127.0.0.1:27017]>
D, [2020-05-01T15:09:55.544574 #29022] DEBUG -- : MONGODB | Topology type 'Unknown' changed to type 'Single'.
2.11.4
comments
users

Output with 2.12.1:

> ruby mongo-zlib.rb 
D, [2020-05-01T15:09:29.934969 #28743] DEBUG -- : MONGODB | EVENT: #<TopologyOpening topology=Unknown[]>
D, [2020-05-01T15:09:29.935007 #28743] DEBUG -- : MONGODB | Topology type 'unknown' initializing.
D, [2020-05-01T15:09:29.935093 #28743] DEBUG -- : MONGODB | EVENT: #<TopologyChanged prev=Unknown[] new=Unknown[127.0.0.1:27017]>
D, [2020-05-01T15:09:29.935118 #28743] DEBUG -- : MONGODB | Topology type 'Unknown' changed to type 'Unknown'.
D, [2020-05-01T15:09:29.935198 #28743] DEBUG -- : MONGODB | EVENT: #<ServerOpening address=127.0.0.1:27017 topology=Unknown[127.0.0.1:27017]>
D, [2020-05-01T15:09:29.935216 #28743] DEBUG -- : MONGODB | Server 127.0.0.1:27017 initializing.
D, [2020-05-01T15:09:29.935352 #28743] DEBUG -- : MONGODB | Waiting for up to 30.00 seconds for servers to be scanned: #<Cluster topology=Unknown[127.0.0.1:27017] servers=[#<Server address=127.0.0.1:27017 UNKNOWN>]>
D, [2020-05-01T15:09:29.936238 #28743] DEBUG -- : MONGODB | EVENT: #<ServerDescriptionChanged address=127.0.0.1:27017 topology=Single[127.0.0.1:27017] prev=#<Mongo::Server:Description:0x70352083072140 config={} average_round_trip_time=> new=#<Mongo::Server:Description:0x70352083115600 config={"ismaster"=>true, "maxBsonObjectSize"=>16777216, "maxMessageSizeBytes"=>48000000, "maxWriteBatchSize"=>100000, "localTime"=>2020-05-01 13:09:29 UTC, "logicalSessionTimeoutMinutes"=>30, "connectionId"=>633, "minWireVersion"=>0, "maxWireVersion"=>8, "readOnly"=>false, "compression"=>["zlib"], "ok"=>1.0} average_round_trip_time=0.000688349>>
D, [2020-05-01T15:09:29.936270 #28743] DEBUG -- : MONGODB | Server description for 127.0.0.1:27017 changed from 'unknown' to 'standalone'.
D, [2020-05-01T15:09:29.936339 #28743] DEBUG -- : MONGODB | EVENT: #<TopologyChanged prev=Unknown[127.0.0.1:27017] new=Single[127.0.0.1:27017]>
D, [2020-05-01T15:09:29.936361 #28743] DEBUG -- : MONGODB | Topology type 'Unknown' changed to type 'Single'.
2.12.1
Traceback (most recent call last):
	34: from mongo-zlib.rb:7:in `<main>'
	33: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/database.rb:120:in `collection_names'
	32: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/database/view.rb:57:in `collection_names'
	31: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/retryable.rb:60:in `read_with_retry_cursor'
	30: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/retryable.rb:117:in `read_with_retry'
	29: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/retryable.rb:316:in `modern_read_with_retry'
	28: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/retryable.rb:61:in `block in read_with_retry_cursor'
	27: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/database/view.rb:58:in `block in collection_names'
	26: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/database/view.rb:177:in `send_initial_query'
	25: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/collections_info.rb:47:in `execute'
	24: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/op_msg_or_command.rb:27:in `execute'
	23: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/executable.rb:38:in `execute'
	22: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/executable.rb:26:in `do_execute'
	21: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/response_handling.rb:73:in `unpin_maybe'
	20: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/executable.rb:27:in `block in do_execute'
	19: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/response_handling.rb:43:in `add_error_labels'
	18: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/executable.rb:28:in `block (2 levels) in do_execute'
	17: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/response_handling.rb:87:in `add_server_diagnostics'
	16: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/executable.rb:29:in `block (3 levels) in do_execute'
	15: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/executable.rb:50:in `get_result'
	14: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/executable.rb:55:in `dispatch_message'
	13: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/server.rb:422:in `with_connection'
	12: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/server/connection_pool.rb:571:in `with_connection'
	11: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/operation/shared/executable.rb:58:in `block in dispatch_message'
	10: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/server/connection_base.rb:135:in `dispatch'
	 9: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/server/connection.rb:405:in `deliver'
	 8: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/server/connection_base.rb:145:in `deliver'
	 7: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/server/connectable.rb:83:in `ensure_connected'
	 6: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/server/connection_base.rb:154:in `block in deliver'
	 5: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/protocol/message.rb:222:in `deserialize'
	 4: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/protocol/message.rb:222:in `each'
	 3: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/protocol/message.rb:226:in `block in deserialize'
	 2: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/protocol/message.rb:398:in `deserialize_field'
	 1: from /home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/protocol/serializers.rb:449:in `deserialize'
/home/bigbourin/.rbenv/versions/2.6.4/lib/ruby/gems/2.6.0/gems/mongo-2.12.1/lib/mongo/protocol/serializers.rb:449:in `get_bytes': Attempted to read 518821760 bytes, but only 135 bytes remain (RangeError)

Thanks.

PS: I had to put 2.12.0 in "Affects Version" because "2.12.1" wasn't added to jira yet.

is depended on by

RUBY-2234 Large bulk writes with zlib throws DBException error

Closed

Details

Description

Attempted to read 518821760 bytes, but only 135 bytes remain (RangeError)

Attachments

Issue Links

Activity

People

Dates