Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

npm:mongodb fails on v1.35.1 #19831

Closed
osddeitf opened this issue Jul 14, 2023 · 15 comments · Fixed by #20314
Closed

npm:mongodb fails on v1.35.1 #19831

osddeitf opened this issue Jul 14, 2023 · 15 comments · Fixed by #20314
Labels
bug Something isn't working needs investigation requires further investigation before determining if it is an issue or not node compat

Comments

@osddeitf
Copy link
Contributor

I just update my Deno build to v1.35.1 from v1.35.0 and my Fresh app fails occasionally due to failed Mongodb query:

An error occurred during route handling or page rendering. MongoParseError: Invalid message size: 1882601779, max allowed: 67108864
    at processIncomingData (file:///home/admin/.cache/deno/npm/registry.npmjs.org/mongodb/5.5.0/lib/cmap/message_stream.js:93:25)
    at processIncomingData (file:///home/admin/.cache/deno/npm/registry.npmjs.org/mongodb/5.5.0/lib/cmap/message_stream.js:126:20)
    at MessageStream._write (file:///home/admin/.cache/deno/npm/registry.npmjs.org/mongodb/5.5.0/lib/cmap/message_stream.js:33:9)
    at writeOrBuffer (ext:deno_node/_stream.mjs:3948:16)
    at _write (ext:deno_node/_stream.mjs:3893:14)
    at MessageStream.Writable.write (ext:deno_node/_stream.mjs:3896:14)
    at TLSSocket.ondata (ext:deno_node/_stream.mjs:3180:26)
    at TLSSocket.emit (ext:deno_node/_stream.mjs:1852:9)
    at addChunk (ext:deno_node/_stream.mjs:2874:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2853:13) {
  [Symbol(errorLabels)]: Set(0) {}
}

I'm not sure this is a bug or not, because I used unofficial build from https://github.com/LukeChannings/deno-arm64.

@bartlomieju bartlomieju added needs investigation requires further investigation before determining if it is an issue or not bug Something isn't working node compat labels Jul 17, 2023
@osddeitf
Copy link
Contributor Author

osddeitf commented Jul 19, 2023

Today I tried with v1.35.1 again, without restarting my server (not even restart Mongodb), it worked normally, so I think it was some kind of memory issue.
I'll keep watch for now to see if the issue is still relevant.

Edit: just after I put the comment, the issue occurred again.

@bartlomieju
Copy link
Member

@osddeitf thanks for the report. Is there any reproduction code you'd be able to provide to help debug the problem?

@osddeitf
Copy link
Contributor Author

For now, I don't think I have any useful reproduction code.

I wrote my website in Fresh, and I served some static resources for my web at a route. The route only reads binary data from mongodb with collection.findOne({ $or: conditions }). It occasionally fails and the only difference in error messages is the number of Invalid message size in MongoParseError: Invalid message size: 1882601779, max allowed: 67108864.

I guess it happens at TLS layer (TLSSocket in stack trace), but I don't think my network is tampered with (man in the middle attack, etc.) as it would not occur if I used v1.35.0.

v1.35.2 has been released, so I will try with it.

@eikooc
Copy link

eikooc commented Aug 14, 2023

I also experience this error intermittently and cannot share a reproduction because it only happens intermittently but here is my stack trace:

  full_error: MongoParseError: Invalid message size: 1415196742, max allowed: 67108864
    at processIncomingData (file:///home/user/.cache/deno/npm/registry.npmjs.org/mongodb/5.7.0/lib/cmap/message_stream.js:93:25)
    at processIncomingData (file:///home/user/.cache/deno/npm/registry.npmjs.org/mongodb/5.7.0/lib/cmap/message_stream.js:126:20)
    at MessageStream._write (file:///home/user/.cache/deno/npm/registry.npmjs.org/mongodb/5.7.0/lib/cmap/message_stream.js:33:9)
    at writeOrBuffer (ext:deno_node/_stream.mjs:3948:16)
    at _write (ext:deno_node/_stream.mjs:3893:14)
    at MessageStream.Writable.write (ext:deno_node/_stream.mjs:3896:14)
    at TLSSocket.ondata (ext:deno_node/_stream.mjs:3180:26)
    at TLSSocket.emit (ext:deno_node/_stream.mjs:1852:9)
    at addChunk (ext:deno_node/_stream.mjs:2874:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2853:13) {
    [Symbol(errorLabels)]: Set(0) {}
  }
}

EDIT:
I also get another error sometimes that I'll just add here as well:

error MongoRuntimeError: Getmore must run on the same server operation began on
    at GetMoreOperation.executeCallback (file:///home/user/.cache/deno/npm/registry.npmjs.org/mongodb/5.7.0/lib/operations/get_more.js:22:29)
    at file:///home/user/.cache/deno/npm/registry.npmjs.org/mongodb/5.7.0/lib/operations/operation.js:65:18
    at ext:deno_node/internal/util.mjs:93:15
    at new Promise (<anonymous>)
    at ext:deno_node/internal/util.mjs:78:12
    at GetMoreOperation.execute (file:///home/user/.cache/deno/npm/registry.npmjs.org/mongodb/5.7.0/lib/operations/operation.js:66:11)
    at executeOperationAsync (file:///home/user/.cache/deno/npm/registry.npmjs.org/mongodb/5.7.0/lib/operations/execute_operation.js:82:36)
    at eventLoopTick (ext:core/01_core.js:183:11) {
  [Symbol(errorLabels)]: Set(0) {}
}

@TillaTheHun0
Copy link

I am also seeing this issue when upgrading Deno >1.35.0. I can run code that queries a MongoDB Atlas Cluster on Deno 1.35.0 that will then intermittently throw errors on Deno 1.35.1. It seems a regression was introduced in Deno 1.35.1.

The issue only arose for me when there were concurrent operations being sent to the Node Mongo Driver ie. Promise.all

The error produced by the Node Mongo Driver is always either MongoParseError: Invalid message size or BSONError: bad string length in bson.

Looking at the release for Deno 1.35.1 I am noticing some changes to node/http and ext/http around compression. Perhaps that's related to this issue, as all the errors i'm seeing have to do with message length.

Here's a minimal reproduction (it uses the sample dataset provided by MongoDB Atlas, but you can change it to whatever):

import { MongoClient } from 'npm:mongodb@5.7.0'

const url = '<YOUR_MONGO_CONNECTION_STRING>'

const query = (db) => (collection) =>
  db
    .collection(collection)
    .find({}, { limit: 10 })
    .toArray()

async function main() {
  let client = new MongoClient(url)
  await client.connect()

  const db = client.db('sample_airbnb')

  await Promise.all(Array(10).fill('listingsAndReviews').map(query(db)))
    .then(res => console.log(res.length))
    .finally(() => client.close())
}

main()

@YoussefAK
Copy link

Same issue still occurring on Deno 1.36.1.

@josephrocca
Copy link
Contributor

josephrocca commented Aug 27, 2023

Just ran into the same problem while upgrading Deno. Currently stuck on 1.34.2 because it's the only version that supports npm:mongodb and doesn't have this bug.

@bartlomieju here's a minimal and reliable reproduction with the latest version of Deno (1.36.3) and npm:mongo (5.8.1) and MongoDB server (on Ubuntu 22.04):

import { MongoClient } from "npm:mongodb@5.8.1"; 

let client = new MongoClient(`mongodb://localhost:27017/deno-bug-test`,  {});
let db = client.db("deno-bug-test");

// await db.collection("col1").deleteMany({});

// if collection is empty, insert 10 dummy docs for testing:
if(!await db.collection("col1").findOne({})) {
  console.log("Inserting dummy docs...");
  // note: it may be possible to reproduce with simpler docs than this - haven't tried to chisel them down
  let docs = await fetch("https://gist.githubusercontent.com/josephrocca/88db398d7785b96aacd037fbf1bdce7e/raw/63b5922460e149677f78e8b3280ffc792279b739/denoMongoDbDebugDummyDocs.json").then(r => r.json());
  for(let doc of docs) {
    await db.collection("col1").insertOne(doc);
  }
}

console.log("Starting...");

await Promise.all([
  db.collection("col1").find({}).limit(10).toArray(),
  db.collection("col1").find({}).limit(10).toArray(),
  db.collection("col1").find({}).limit(10).toArray(),
  db.collection("col1").find({}).limit(10).toArray(),
  db.collection("col1").find({}).limit(10).toArray(),
]);

console.log("Done.");

Some notes:

  • It seems to only occur when several concurrent requests are sent to MongoDB
  • The bug was introduced in 1.35.1
  • The bug sometimes causes the query to hang indefinitely rather than throw an error (though I can't reliably reproduce that - the above code just reproduces the errors).

There are several different types of errors that I get and they occur randomly depending on the data, so I think TillaTheHun0 is correct that there's some sort of compression/decompression bug that's feeding MongoDB driver some garbled data:

error: Uncaught BSONError: bad string length in bson
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2626:23)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2687:25)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2705:21)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2687:25)
    at internalDeserialize (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2538:12)
    at Object.deserialize (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:4014:12)
    at BinMsg.parse (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/commands.js:461:54)
    at Connection.onMessage (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/connection.js:178:21)
    at MessageStream.<anonymous> (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/connection.js:61:60)
    at MessageStream.emit (ext:deno_node/_stream.mjs:1852:9)
error: Uncaught (in promise) MongoParseError: Invalid message size: 539784052, max allowed: 67108864
    at processIncomingData (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/message_stream.js:93:25)
    at MessageStream._write (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/message_stream.js:33:9)
    at writeOrBuffer (ext:deno_node/_stream.mjs:3948:16)
    at _write (ext:deno_node/_stream.mjs:3893:14)
    at MessageStream.Writable.write (ext:deno_node/_stream.mjs:3896:14)
    at Socket.ondata (ext:deno_node/_stream.mjs:3180:26)
    at Socket.emit (ext:deno_node/_stream.mjs:1852:9)
    at addChunk (ext:deno_node/_stream.mjs:2874:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2853:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2792:14)
error: Uncaught (in promise) BSONError: Invalid UTF-8 string in BSON document
    at getValidatedString (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:3003:27)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2628:21)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2687:25)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2705:21)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2687:25)
    at internalDeserialize (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2538:12)
    at Object.deserialize (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:4014:12)
    at BinMsg.parse (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/commands.js:461:54)
    at Connection.onMessage (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/connection.js:178:21)
    at MessageStream.<anonymous> (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/connection.js:61:60)
error: Uncaught (in promise) MongoParseError: Invalid message size: -234851216
    at processIncomingData (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/message_stream.js:90:25)
    at MessageStream._write (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/message_stream.js:33:9)
    at writeOrBuffer (ext:deno_node/_stream.mjs:3948:16)
    at _write (ext:deno_node/_stream.mjs:3893:14)
    at MessageStream.Writable.write (ext:deno_node/_stream.mjs:3896:14)
    at Socket.ondata (ext:deno_node/_stream.mjs:3180:26)
    at Socket.emit (ext:deno_node/_stream.mjs:1852:9)
    at addChunk (ext:deno_node/_stream.mjs:2874:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2853:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2792:14)
error: Uncaught (in promise) BSONError: Detected unknown BSON type 96 for fieldname "28"
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2967:19)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2705:21)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2687:25)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2705:21)
    at deserializeObject (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2687:25)
    at internalDeserialize (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2538:12)
    at Object.deserialize (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:4014:12)
    at BinMsg.parse (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/commands.js:461:54)
    at Connection.onMessage (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/connection.js:178:21)
    at MessageStream.<anonymous> (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/connection.js:61:60)
error: Uncaught (in promise) BSONError: One object, sized correctly, with a spot for an EOO, but the EOO isn't 0x00
    at internalDeserialize (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:2536:15)
    at Object.deserialize (file:///home/joe/.cache/deno/npm/registry.npmjs.org/bson/5.4.0/lib/bson.cjs:4014:12)
    at BinMsg.parse (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/commands.js:461:54)
    at Connection.onMessage (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/connection.js:178:21)
    at MessageStream.<anonymous> (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/connection.js:61:60)
    at MessageStream.emit (ext:deno_node/_stream.mjs:1852:9)
    at processIncomingData (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/message_stream.js:124:16)
    at MessageStream._write (file:///home/joe/.cache/deno/npm/registry.npmjs.org/mongodb/5.8.1/lib/cmap/message_stream.js:33:9)
    at writeOrBuffer (ext:deno_node/_stream.mjs:3948:16)
    at _write (ext:deno_node/_stream.mjs:3893:14)

@bartlomieju
Copy link
Member

Thanks for the report. We'll try to debug it this week.

@littledivy
Copy link
Member

Hey, this is fixed in canary (deno upgrade --canary). Any chance you can verify?

@josephrocca
Copy link
Contributor

@littledivy Just tested and can verify that it seems to be fixed - thanks!

@osddeitf
Copy link
Contributor Author

Glad to hear this is now fixed, but I can't try canary, because my environment is Arm64. I will try it when the next version get released.
Thank you all for your efforts.

@gaoxiaoliangz
Copy link

The lastest 1.36.3 can still repruduce this issue. Does anyone know which verion will fix this issue?

@bartlomieju
Copy link
Member

The lastest 1.36.3 can still repruduce this issue. Does anyone know which verion will fix this issue?

v1.37 will fix it, you can update to canary (deno upgrade --canary) which includes the fix.

@gaoxiaoliangz
Copy link

@bartlomieju Any plans on the release date of the 1.37?

@bartlomieju
Copy link
Member

September 18th

TillaTheHun0 added a commit to hyper63/hyper-adapter-mongodb that referenced this issue Nov 1, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working needs investigation requires further investigation before determining if it is an issue or not node compat
Projects
None yet
8 participants