docstore/mongo protobuf timestamp panics on get

[eqinox76]

Describe the bug

A struct generated from a .proto schema with a timestamp is written to mongodb but panics when reading it.

To Reproduce

$ go version
go version go1.14.3 linux/amd64

Using a protobuf specification like

import "google/protobuf/timestamp.proto";

message Test{
  ...
  google.protobuf.Timestamp start_date = 4;
}

Will result in a struct like

type Test struct{
  ...
  StartTime *timestamp.Timestamp `protobuf:"bytes,5,opt,name=start_time,json=startTime,proto3" json:"start_time,omitempty"`
}

Writing this to a mongodb instance will work and checking via mongo shell shows binary data:

{
	"_id" : "3d964883c5e60d36",
	"DocstoreRevision" : "2f1954b9-f038-440c-b0e0-c0ed88f2d04a",
	...
	"StartDate" : BinData(0,"CIDCr/AF"),
}

Which causes a panic when read via the go cloud cdk:

panic: reflect.Set: value of type []uint8 is not assignable to type *timestamppb.Timestamp

goroutine 28 [running]:
reflect.Value.assignTo(0xca0040, 0xc0000a8900, 0x97, 0xe166df, 0xb, 0xd81da0, 0x0, 0xc0000a8900, 0x0, 0x0)
	/snap/go/5759/src/reflect/value.go:2403 +0x426
reflect.Value.Set(0xd81da0, 0xc0000ae670, 0x196, 0xca0040, 0xc0000a8900, 0x97)
	/snap/go/5759/src/reflect/value.go:1532 +0xbd
gocloud.dev/docstore/driver.decode(0xd81da0, 0xc0000ae670, 0x196, 0x1013c00, 0xc0000a88e0, 0x2, 0xd81da0)
	/home/carsten/go/pkg/mod/gocloud.dev@v0.19.0/docstore/driver/codec.go:391 +0x193
gocloud.dev/docstore/driver.decodeStruct.func1(0xc0000aa970, 0x9, 0x1013c00, 0xc0000a88e0, 0x40dd01, 0xc000144d40)
	/home/carsten/go/pkg/mod/gocloud.dev@v0.19.0/docstore/driver/codec.go:679 +0x15b
gocloud.dev/docstore/mongodocstore.decoder.DecodeMap(0xcfdd00, 0xc000462630, 0x0, 0xc000144d40)
	/home/carsten/go/pkg/mod/gocloud.dev/docstore/mongodocstore@v0.19.0/codec.go:242 +0x12d
gocloud.dev/docstore/driver.decodeStruct(0xd6aae0, 0xc0000ae660, 0x199, 0x1013c00, 0xc0000a88c0, 0xc0005b1d18, 0xc0000a88c0)
	/home/carsten/go/pkg/mod/gocloud.dev@v0.19.0/docstore/driver/codec.go:658 +0x171
gocloud.dev/docstore/driver.Document.Decode(0xdbd640, 0xc0000ae660, 0x0, 0xd6aae0, 0xc0000ae660, 0x199, 0xc000121500, 0xa, 0x10, 0x1013c00, ...)
	/home/carsten/go/pkg/mod/gocloud.dev@v0.19.0/docstore/driver/document.go:184 +0x142
gocloud.dev/docstore/mongodocstore.decodeDoc(0xc000462630, 0xdbd640, 0xc0000ae660, 0x0, 0xd6aae0, 0xc0000ae660, 0x199, 0xc000121500, 0xa, 0x10, ...)
	/home/carsten/go/pkg/mod/gocloud.dev/docstore/mongodocstore@v0.19.0/codec.go:125 +0x115
gocloud.dev/docstore/mongodocstore.(*docIterator).Next(0xc0004623f0, 0x1005ca0, 0xc000481080, 0xdbd640, 0xc0000ae660, 0x0, 0xd6aae0, 0xc0000ae660, 0x199, 0xc000121500, ...)
	/home/carsten/go/pkg/mod/gocloud.dev/docstore/mongodocstore@v0.19.0/query.go:127 +0xe6
gocloud.dev/docstore.(*DocumentIterator).Next(0xc000462420, 0x1005ca0, 0xc000481080, 0xdbd640, 0xc0000ae660, 0xc0003426b0, 0x1)
	/home/carsten/go/pkg/mod/gocloud.dev@v0.19.0/docstore/query.go:234 +0x204
main.(*ServerJob).GetJobs(0xc00048a400, 0x1005ca0, 0xc000481080, 0xc0002b6508, 0x0, 0x0, 0x0)
...

Expected behavior

Using the in memory docstore i can see the expected behavior of the struct being filled with data.

input: {StartDate:seconds:1589872418 nanos:319671987 ...
output: {StartDate:seconds:1589872418 nanos:319671987 ... 

Version

gocloud.dev v0.19.0
gocloud.dev/docstore/mongodocstore v0.19.0

Additional context

[vangent]

@jba

I took a look at this but I'm not sure how to fix it. It looks like the timestamp field is marshalled as a proto on the way out (https://github.com/google/go-cloud/blob/master/docstore/driver/codec.go#L135), but then unmarshalled as a primitive.Binary on the way out (https://github.com/google/go-cloud/blob/master/docstore/mongodocstore/codec.go#L251).

[eqinox76]

#2926 Improves this issue but doe not fix it. If i copy the protobuf generated code into a simple test case it works well with the in memory database but seems to lose the data when using mongodb.
Output:

# mem://
Id 77791404-c70f-4f85-8385-0b2c3ad49cfd
StartDate seconds:1534
# mongodb://
Id ecaec01c-a858-4878-80ee-9b424ba67d7c
StartDate <nil>

Even more peculiar is the error message when i am using the protobuf generated code and do not just copy over the generated struct:

# mem://
panic: cannot set type main.TestInput to map[Name: SecurityId:0 StartDate:[8 254 11]] (code=InvalidArgument)

goroutine 1 [running]:
main.createAndQuery(0xc00025aab0)
        /home/carsten/projects/test/main.go:64 +0x34d
main.main()
        /home/carsten/projects/test/main.go:41 +0xf3
exit status 2

I attached my test code (similar to #2922 ) and the generated protobuf code.
test.zip

Thanks again for looking into this issue!

[vangent]

Can you try restarting your mongo server instance and re-running the test? I tried your test, and it failed as you describe, but then restarted the server and it worked. I think the problem is that Mongo has captured the schema from before the fix (at least, when I debugged, the doc returned from Query was decoded as a map with the subfields of the TestInput proto, while it was being marshalled to bytes; when I restarted my local mongo instance it was decoded from bytes back to proto).

[eqinox76]

Thanks vangent, restarting indeed fixes the first issue and your explanation sounds very likely. The second test with

type Item struct {
	Id    uuid.UUID
	Proto TestInput

	DocstoreRevision interface{}
}

Still fails with this strange error:

# mem://
panic: cannot set type main.TestInput to map[Name: SecurityId:0 StartDate:[8 254 11]] (code=InvalidArgument)

goroutine 1 [running]:
main.createAndQuery(0xc00025aab0)
        /home/carsten/projects/xtp/tca/calculationserver/test/main.go:64 +0x34d
main.main()
        /home/carsten/projects/xtp/tca/calculationserver/test/main.go:41 +0xf3
exit status 2

I tested around some and it seems to fail when the following three functions are defined. even if those do nothing:

func (x *TestInput) Reset() {}

func (x *TestInput) String() string {
	return "123"
}

func (*TestInput) ProtoMessage() {}

Removing any of these makes the test run fine. The functions are all default generated by protobuf.

[vangent]

seems to fail when the following three functions are defined

I suspect that this is related to whether the struct implements the proto.Message interface.

[vangent]

OK, I think I found the bug and updated PR #2926. Can you try this again to verify?
Please make sure you restart your local mongoDB first.

FWIW, I realized that it's not that Mongo was capturing the schema somehow, but rather that the test creates a document and then tries to fetch it; when the test panics in the middle, it doesn't clean up after itself and delete the document. Since the query in the doc just iterates over all documents, when you re-run it fetches a document from a previous run.

[eqinox76]

Ah yes of course you are correct.

I tested with github.com/vangent/go-cloud v0.1.1-0.20201221195848-5a2ba71e2455 and its working fine. Many thanks for fixing this issue !