[CSHARP-2359] Error while reading with mongodb 4.0 and latest driver Created: 21/Aug/18  Updated: 06/Apr/23  Resolved: 12/Sep/18

Status: Closed
Project: C# Driver
Component/s: Error Handling, Read Operations
Affects Version/s: 2.7.0
Fix Version/s: None

Type: Task Priority: Major - P3
Reporter: Kris Budde Assignee: Jeffrey Yemin
Resolution: Done Votes: 0
Labels: question
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

MongoDB Replicaset v4.0.0, 3 Nodes
Not affected: version 3.6.3


Attachments: PNG File Write errors.png    

 Description   

Hi,

we've upgraded our replicaset to mongo db version 4.0.0.

One application has write errors every 10 minutes since the upgrade. After downgrading they disappear again.

We did some tests (with/without authentication) and finally we were able to create a small demo application: https://github.com/alvillain/TestMongo/tree/master/TestMongo2.0 to reproduce the issue.

It is a .Net Core Application just reading data in an endless loop. Every 10 minutes we see one write error. The db/collection does not have any validation rules.

Interesting: If the application is stopped the write error will occur one last time at the end of the 10m intervall as usual.

We were seeing the write errors in our monitoring. From mongo db shell you can get the value with:

(db.runCommand( { serverStatus: 1 } )).metrics.getLastError

{
        "wtime" : {
                "num" : 145,
                "totalMillis" : 302
        },
        "wtimeouts" : NumberLong(0)
}

In the log file of mongodb we were not able to find some hints about the issue. Probably we need to change the logging level: Which module is interesting in this case?

I think more information could be needed and we are happy to provide them.

 



 Comments   
Comment by Kris Budde [ 12/Sep/18 ]

I was under the impression that this metric is showing real write errors.

I was running the following command on mongo 3.x and 4.x replicasets.

db.runCommand( { getLastError: 1, w: 2, wtimeout:5000 } )

Both are increasing the metric. So on server side was no change with this behavior. It must be on driver side.

For me it is fixed. It's not an issue for the application or behavior. Thank you for your help.

Comment by Jeffrey Yemin [ 11/Sep/18 ]

I see. This metric isn't reporting actual errors. It's just reporting use of the getLastError command.

I don't know why the server upgrade changes the getLastError reporting, but I am confident that it does not reflect actual errors in your application.

Comment by Kris Budde [ 11/Sep/18 ]

Hi jeff.yemin,

thank you for the response.
Yes, the small demo application which is just reading data is causing write errors in MongoDB. I cannot explain why.
I've just repeated the test in our infrastructure. Today no write errors.
10minutes after starting the application we see write errors.

Before:

Mongo30:PRIMARY> (db.runCommand( { serverStatus: 1 } )).metrics.getLastError
{
        "wtime" : {
                "num" : 0,
                "totalMillis" : 0
        },
        "wtimeouts" : NumberLong(0)
}

Afterwards

{
        "wtime" : {
                "num" : 1,
                "totalMillis" : 28
        },
        "wtimeouts" : NumberLong(0)
}
Mongo30:PRIMARY> (db.runCommand( { serverStatus: 1 } )).metrics.getLastError
{
        "wtime" : {
                "num" : 4,
                "totalMillis" : 49
        },
        "wtimeouts" : NumberLong(0)
}

 

Regarding Application Logs:
There is no stack trace.It's not visible to the application.

Comment by Jeffrey Yemin [ 10/Sep/18 ]

Hi kbudde

You say that your application gets a write error every 10 minutes but the test program seems to only execute reads. Can you provide the application logs showing the full stack trace of the exception that the driver is throwing?

Generated at Wed Feb 07 21:42:20 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.