tslog icon indicating copy to clipboard operation
tslog copied to clipboard

Bug: [BUG]mongodb 4.0.3 shard duplicate key error log failed

Open kohakugame opened this issue 2 years ago • 3 comments

Describe the bug mongodb use findOneAndUpdate second time trigger duplicate key error, logger this error fail.

To Reproduce Steps to reproduce the behavior:

mongo db 4.0.3 shard mode

package.json

{
  "name": "test-mongo-tslog",
  "version": "1.0.0",
  "main": "index.js",
  "license": "MIT",
  "dependencies": {
    "mongodb": "^4.4.0",
    "tslog": "^4.8.2",
    "typescript": "^5.1.6"
  },
  "scripts": {
    "start": "ts-node index.ts"
  },
  "devDependencies": {
    "ts-node": "^10.9.1"
  }
}

index.ts

import { MongoClient } from "mongodb";
import { Logger, ILogObj } from "tslog";

interface ITestData {
    _id: string,
    testList: string[],
}

const log: Logger<ILogObj> = new Logger();

const dbOperate = async (col: any, id: string, testId: string) => {
    const firstResult = await col.findOneAndUpdate(
        { _id: id, testList: { $not: { $eq: testId } } },
        {
            $push: {
                testList: {
                    $each: [testId],
                    $slice: 10
                },
            }
        },
        {
            upsert: true, 
            projection: { testList: 1 }, 
            returnDocument: 'after', 
        }
    );
}

const main = async():Promise<void>=>{
    const mongoClient = new MongoClient("mongodb://127.0.0.1:27017", {
        family: 4,
        noDelay: true,
        connectTimeoutMS: 5000,
    });

    await mongoClient.connect();

    const db = mongoClient.db('test');
    const col = db.collection<ITestData>('test_col');
    const id = '10001'
    const testId = '1001'

    // delete key may already exist
    await col.deleteOne({ _id: id });
 
    // should ok
    const firstResult = await dbOperate(col, id, testId);
    // log.info('first result', firstResult);

    try {
        const secondResult = await dbOperate(col, id, testId); // trigger duplicate key error
        log.info('second result', secondResult);
    } catch (error) {
        console.log('error', error);
        log.error('second result', error); //traceback here       
    } 
}

main();

yarn start

Expected behavior A clear and concise description of what you expected to happen.

Screenshots console.log('error', error); // this works fine image

log.error('second result', error); cause traceback image

Additional context Add any other context about the problem here.

Node.js Version v18.15.0

OS incl. Version windows 10

kohakugame avatar Aug 05 '23 09:08 kohakugame

Screenshot 2023-08-07 at 22 42 55

That's weird, it works for me. This is my package.json

{
    "name": "test-mongo-tslog",
    "version": "1.0.0",
    "main": "index.js",
    "license": "MIT",
    "type": "module",
    "dependencies": {
        "mongodb": "^4.4.0",
        "tslog": "^4.8.2",
        "typescript": "^5.1.6"
    },
    "scripts": {
        "start": "node --experimental-specifier-resolution=node --enable-source-maps --no-warnings --loader ts-node/esm index.ts"
    },
    "devDependencies": {
        "ts-node": "^10.9.1"
    }
}

terehov avatar Aug 07 '23 20:08 terehov

it only happen with mongodb shard mode

here is a simple docker setup mongo shard

  1. save as docker-compose.yaml and run docker-compose up -d
version: '3.4'
services:
  shard1:
    container_name: shard1
    image: mongo:4.0.3
    command: mongod --noauth --shardsvr --replSet shard1

  shard2:
    container_name: shard2
    image: mongo:4.0.3
    command: mongod --noauth --shardsvr --replSet shard2

  shard3:
    container_name: shard3
    image: mongo:4.0.3
    command: mongod --noauth --shardsvr --replSet shard3

  config1:
    container_name: config1
    image: mongo:4.0.3
    command: mongod --noauth --configsvr --replSet csrs

  config2:
    container_name: config2
    image: mongo:4.0.3
    command: mongod --noauth --configsvr --replSet csrs

  config3:
    container_name: config3
    image: mongo:4.0.3
    command: mongod --noauth --configsvr --replSet csrs

  mongos:
    container_name: mongos
    image: mongo:4.0.3
    command: mongos --configdb csrs/config1:27019,config2:27019,config3:27019 --bind_ip 0.0.0.0 --port 27017
    ports:
      - 27017:27017
    depends_on:
      - config1
      - config2
      - config3

  1. run docker exec -it config1 /bin/bash
mongo --port 27019
config = {_id:"csrs",configsvr:true,members:[{_id:0,host:"config1:27019"},{_id:1,host:"config2:27019"},{_id:2,host:"config3:27019"}]}
rs.initiate(config)
  1. run docker exec -it shard1 /bin/bash
mongo --port 27018
rs.initiate({_id: "shard1",members: [{ _id : 0, host : "shard1:27018" }]})
  1. run docker exec -it shard2 /bin/bash
mongo --port 27018
rs.initiate({_id: "shard2",members: [{ _id : 0, host : "shard2:27018" }]})
  1. run docker exec -it shard3 /bin/bash
mongo --port 27018
rs.initiate({_id: "shard3",members: [{ _id : 0, host : "shard3:27018" }]})
  1. run docker exec -it mongos /bin/bash
sh.addShard("shard1/shard1:27018")
sh.addShard("shard2/shard2:27018")
sh.addShard("shard3/shard3:27018")

kohakugame avatar Aug 12 '23 06:08 kohakugame

shard mode error contains Timestamp which cause error image

kohakugame avatar Aug 12 '23 07:08 kohakugame