mgo writeConcern wtimeout does not work

[Mei-Zhao]

After obtain a session using the Dial function(mgo.Dial(url)), try to make the session in safety mode (session.EnsureSafe) with wmode="majority" and wtimeout = 5000. I should get the writeConcernErr of a insert command because the mongo cluster has 5 nodes and 3 was locked by fsyncLock. After 1 min (the default socketTimeout) I got net tcp error like "read tcp i/o timeout".

Some details about code in newSession function:

`

func newSession(consistency Mode, cluster mongoCluster, timeout time.Duration) (session Session) {

......
session.SetMode(consistency, true)

session.SetSafe(&Safe{})

session.queryConfig.prefetch = defaultPrefetch

return session

} `

The session has beed init safe mode with &Safe{}.Wtimeout has beed set to 0.

The ensureSafe function will try to update the safe mode with some check ,detail in code:

` var cmd getLastError

if s.safeOp == nil {

    cmd = getLastError{1, w, safe.WTimeout, safe.FSync, safe.J}

} else {

           ......

           if safe.WTimeout > 0 && safe.WTimeout < cmd.WTimeout {

        cmd.WTimeout = safe.WTimeout

    }

         ......

   }

` This condition could not be true cause cmd.WTimeout is 0.So the wtimeout always is 0.

I could see the wmode=majority but no wtimeout info of writeConcern with the mongosniff, some test result ; 2018/05/25-10:10:31.146682 [10.46.22.23:44792] QUERY id:7 coll:test.$cmd toskip:0 toret:-1 flag:0 query:{"documents":[{"_id":1,"val":"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=="}],"insert":"test2","ordered":true,"writeConcern":{"getLastError":1,"w":"majority"}} sel:null

[domodwyer]

Hi @Mei-Zhao

Can you provide a runnable example to test with? We use wtimeout and it seems to be fine for us.

Dom

[Mei-Zhao]

I attach a runnable example go file .The rs.status and rs.conf about getLastErrorDefaults as below: (1)---->rs.conf

"settings" : {
        "chainingAllowed" : true,
        "heartbeatIntervalMillis" : 2000,
        "heartbeatTimeoutSecs" : 10,
        "electionTimeoutMillis" : 10000,
        "catchUpTimeoutMillis" : 60000,
        "getLastErrorModes" : {

        },
        "getLastErrorDefaults" : {
            "w" : "majority",
            "j" : true,
            "wtimeout" : 5000
        },
        "replicaSetId" : ObjectId("5afbf4771a649ab2deda0266")
    }

The repl set has 5 nodes and 3 of them are lockd by db.fsyncLock().

rs38_18:SECONDARY> db.fsyncLock()
{
    "info" : "now locked against writes, use db.fsyncUnlock() to unlock",
    "lockCount" : NumberLong(1),
    "seeAlso" : "http://dochub.mongodb.org/core/fsynccommand",
    "ok" : 1
}

(2)---->mongo shell insert op Insert use mongo shell the result like:

rs38_18:PRIMARY> db.test100.insert({"val2":"test2"})

WriteResult({
    "nInserted" : 1,
    "writeConcernError" : {
        "code" : 64,
        "codeName" : "WriteConcernFailed",
        "errInfo" : {
            "wtimeout" : true
        },
        "errmsg" : "waiting for replication timed out"
    }
})

(3)----> go mgo client use like in the file mgo_wTimeout_example(the .go file type not support so just txt)

the mgosniff of this req like:

2018/06/04-15:15:03.027897 [127.0.0.1:15955] QUERY id:7 coll:test.$cmd toskip:0 toret:-1 flag:0 query:{"documents":[{"val":"test"}],"insert":"test100","ordered":true,"writeConcern":{"getLastError":1,"w":"majority"}} sel:null

The result of mgo_wTimeout_example like:

read tcp 127.0.0.1:15955->127.0.0.1:7017: i/o timeout

[Mei-Zhao]

mgo_wTimeout_example.txt

[domodwyer]

Hi @Mei-Zhao

The docs for EnsureSafe say:

- safe.WTimeout is used if set and smaller than the current WTimeout.

Because Wtimeout defaults to 0 (no delay) using EnsureSafe() won't work, because (WTimeout < 0) == false so you need to use session.SetSafe().

I've attached a screenshot of a packet capture confirming the value is sent to mongo as expected when using session.SetSafe(&mgo.Safe{WTimeout: 42})

Dom

[Mei-Zhao]

Thanks for reply. mgo.Dial(url) always set session.SetSafe(&Safe{}). So after that EnsureSafe() never will work for wTimeout.

[domodwyer]

Hi @Mei-Zhao

Sorry, I missed that in your ticket!

Luckily @DaytonG (thanks!) added wTimeout to the dial string in https://github.com/globalsign/mgo/pull/162 (development branch), so this should let you set the initial value set by the mgo.Dial() call :)

I hope this helps!

Dom