[GODRIVER-1418] unable to decode message length Created: 27/Nov/19  Updated: 06/Jan/20  Resolved: 06/Jan/20

Status: Closed
Project: Go Driver
Component/s: Connections
Affects Version/s: 1.1.3
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: 滨 黄 Assignee: Divjot Arora (Inactive)
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

mongo server 3.2
Linux Enterprise Server 7.0 x86_64



 Description   

I have a secondary mongo server 3.2, and my client code below prints error.

func main() {func main() { var connString string if len(os.Args) < 2 { fmt.Fprintf(os.Stderr, "mongo <server connection string>") connString = "mongodb://127.0.0.1:27017/?connect=direct" } else { connString = os.Args[1] } clientOptions := options.Client().ApplyURI(connString) clientOptions.SetConnectTimeout(time.Duration(2000) * time.Millisecond) clientOptions.SetSocketTimeout(time.Duration(5000) * time.Millisecond) clientOptions.SetServerSelectionTimeout(time.Duration(2000) * time.Millisecond) ctx, _ := context.WithTimeout(context.Background(), time.Duration(5000)*time.Millisecond) client, err := mongo.Connect(ctx, clientOptions) if err != nil { fmt.Fprintf(os.Stderr, "connect mongo failed: %s\n", err.Error()) os.Exit(1) } defer client.Disconnect(ctx)
 err = client.Ping(context.TODO(), readpref.Primary()) if err != nil { fmt.Fprintf(os.Stderr, "ping mongo failed: %s\n", err.Error()) os.Exit(1) }
 coll := client.Database("maicai").Collection("station_order")
 var now = time.Now() timestamp0 := now.Truncate(30 * time.Minute) var unixTime int64 unixTime = timestamp0.Unix()
 projections := bson.D{ {"_id", 0}, {"order_number", 1}, {"station_id", 1}, {"status", 1}, {"finish_time", 1}, {"goods.origin_price", 1}, {"goods.price", 1}, {"goods.id", 1}, {"goods.count", 1}, {"goods.purchase_stockout", 1}, }
 findOptions := options.Find() findOptions.SetProjection(projections)
 cur, err := coll.Find( ctx, bson.D{ {"finish_time", bson.D{ {"$gte", unixTime}, }}, {"status", bson.D{ {"$in", bson.A{2}}, }}, }, findOptions, )
 if err != nil { fmt.Fprintf(os.Stderr, "mongo find failed: %s\n", err.Error()) os.Exit(1) } orders := make([]StationOrder, 0, 20000) err = cur.All(context.Background(), &orders) if err != nil { fmt.Fprintf(os.Stderr, "Query mongo station order failed: %s", err.Error()) os.Exit(1) }
 t := time.Unix(unixTime, 0) fmt.Fprintf(os.Stdout, "Orders from mongo DB: time = %s, count = %d", t.Format("2006-01-02 15:04:05"), len(orders))}

> ./mongo "mongodb://10.8.72.37:39117/maicai?connect=direct&readPreference=secondary"
mongo find failed: connection(10.8.72.37:39117[-3]) unable to decode message length: read tcp 10.23.30.32:41672->10.8.72.37:39117: i/o timeout

>

 

while the native mongo command works after setting slaveOK

 

> mongo hidden.mgdorder.srv.mc.dd:39117
MongoDB shell version: 2.6.12
connecting to: hidden.mgdorder.srv.mc.dd:39117/test
Server has startup warnings:
2019-11-26T11:17:11.537+0800 I CONTROL [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
2019-11-26T11:17:11.537+0800 I CONTROL [initandlisten]
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten]
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten] ** WARNING: You are running on a NUMA machine.
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten] ** We suggest launching mongod like this to avoid performance problems:
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten] ** numactl --interleave=all mongod [other options]
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten]
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten]
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2019-11-26T11:17:11.538+0800 I CONTROL [initandlisten]
ddmc_order:SECONDARY> use maicai
switched to db maicai
ddmc_order:SECONDARY> db.setSlaveOk()
ddmc_order:SECONDARY>



 Comments   
Comment by Divjot Arora (Inactive) [ 10/Dec/19 ]

Hi mikehb78@icloud.com,

Thank you for your report. I was not able to reproduce this against a locally-running replicaset. One thing you could try is removing or increasing the timeouts. It's possible that creating new connections or executing operations is taking longer than expected due to degraded network performance and the timeouts you're specifying are expiring. Also, you're using a hardcoded IP address in the connection string for the driver repro, but a host name in the connection string for the shell. Can you explain why the connection strings are different?

Generated at Thu Feb 08 08:36:21 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.