-
Type: Bug
-
Resolution: Fixed
-
Priority: Major - P3
-
Affects Version/s: 2.12.1
-
Component/s: Wire Protocol
-
Environment:Mongoid 7.1.1
Mongodb 4.2.6
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