UnexpectedMessageError: unexpected message type: 0x45

[bmathisbrandcoders]

Describe the bug
Long running web services connected to a single edgedb instance will log this error, then time out during connection verification and must be restarted to function again.

Reproduction
This is the code that is timing out after the error message (dbConnectionError is never thrown)

log.Println("Attempting to connect to EdgeDB...")
		ctx, _ := context.WithTimeout(context.Background(), time.Second)
		dbError := client.EnsureConnected(ctx)
		log.Println(dbError)

		if dbError != nil {
			response.Error.Code = "dbConnectionError"
			response.Error.Message = dbError.Error()
			c.JSON(http.StatusInternalServerError, response)
			return
		}

This is how we're creating our db connection

log.Println("Connecting to EdgeDB...")
	ctx := context.Background()
	var opts edgedb.Options
	if os.Getenv("FOO_ENVIRONMENT") == "local" {
		opts = edgedb.Options{
			Database:    "edgedb",
			User:        "edgedb",
			Concurrency: 4,
		}
	} else {
		concurrency, concurrencyCastErr := strconv.Atoi(os.Getenv("DB_CONCURRENCY"))
		if concurrencyCastErr != nil {
			concurrency = 4
		}
		port, portCastErr := strconv.Atoi(os.Getenv("DB_PORT"))
		if portCastErr != nil {
			port = 5656
		}
		opts = edgedb.Options{
			Database:    os.Getenv("DB_DBNAME"),
			User:        os.Getenv("DB_USER"),
			Password:    edgedb.NewOptionalStr(os.Getenv("DB_PASSWORD")),
			Host:        os.Getenv("DB_HOST"),
			Port:        port,
			Concurrency: uint(concurrency),
			TLSOptions: edgedb.TLSOptions{
				SecurityMode: "insecure",
			},
			ConnectTimeout: time.Duration(5 * time.Second),
		}
	}
	db, dbErr := edgedb.CreateClient(ctx, opts)

	return fooDb{DB: db}, db, dbErr

Example of how we're calling the edgedb client (any one of these could throw the 0x45 error it isn't a specific request)

timeout, _ := time.ParseDuration(os.Getenv("DB_CONTEXT_TIMEOUT"))

ctx, _ := context.WithTimeout(context.Background(), timeout)
err := fdb.DB.Query(ctx, `SELECT foo::Foo {foo: {id}} FILTER .name =<str>$0`, &fooDestination, fooName)

Expected behavior
Better error reporting? I'm unsure as to whether this is something I'm doing wrong or if this is a bug in the client library

Versions (please complete the following information):

• OS : linux/docker
• EdgeDB version: {'2.9+5ac35ff'}
• EdgeDB CLI version: EdgeDB CLI 2.2.6+7eabbf9
• edgedb-go version: v0.12.0
• Go version: go version go1.19 darwin/amd64 (from my machine but problem is happening when deployed)

Additional context
I have deployed an upgrade to edgedb-go v0.13.5 and am waiting to see if there are still issues

[bmathisbrandcoders]

Here is how we initialize the client and connect it to our service, if that helps:

	db, edb, dbErr := fooDb.NewFooDbConnection() // function code above
	if dbErr != nil {
		log.Fatal(dbErr)
	}
	defer edb.Close()

	svc := service.NewFooSvc(db)

[fmoor]

For context, the message unexpected message type: 0x45 means that the client received something from the server that it doesn't know how to handle. In this case 0x45 indicates that the server sent an error to the client that should be deserialized and returned to the calling code.

[bmathisbrandcoders]

@fmoor since deploying the v0.13.5 edgedb-go library frontend hasn't noticed the server going down. It's possible this fixed it but I'll keep checking with them.

Could it have been an error the client is now handling internally?

[fmoor]

Could it have been an error the client is now handling internally?

Yes. The client retries certain errors if it is possible they would succeed on a second attempt.

[bmathisbrandcoders]

This hasn't been happening nearly as often anymore, but it is still happening.
Logs from the server(s):
2023/02/22 15:22:07 edgedb.UnexpectedMessageError: unexpected message type: 0x45
2023-02-22T15:22:34.993 edb.server: Connection discarded to backend database: edgedb

[fmoor]

This hasn't been happening nearly as often

When this happens now do you still have to restart the process to get the connection to the database back? Or does it print this message, but continue to operate?

[fmoor]

@bmathisbrandcoders I pushed a branch with my best guess at a fix for this. Would you try building and deploying with that branch and reporting back if it makes a difference?

go mod edit -replace github.com/edgedb/edgedb-go=github.com/edgedb/edgedb-go@debug-261

[bmathisbrandcoders]

This hasn't been happening nearly as often

When this happens now do you still have to restart the process to get the connection to the database back? Or does it print this message, but continue to operate?

This time it seems to fix itself, our service just returns 503 for the request it happens in

I just deployed your debug branch, hopefully that fixes it.

[bmathisbrandcoders]

@fmoor looks like your branch has fixed it entirely!

[fmoor]

@fmoor looks like your branch has fixed it entirely!

Great. Thanks for working on this with me! I'll merge that fix and release it.

[fmoor]

The fix was released in v0.13.6