Go Libray v2: wrong time statistics in search query

Go SDK
1

Hi,

I have a simple Testscript for Go Client Library v2:

package main

// test couchbase library v2

import (
“fmt”
“time”

gocb "github.com/couchbase/gocb/v2"
"github.com/couchbase/gocb/v2/search"

)

type result struct {
Type string
ID int
ContentName string
}

func main() {

// -----------------
// connect database
// -----------------

cluster, err := gocb.Connect(
	"localhost",
	gocb.ClusterOptions{
		Username: "test",
		Password: "test",
	})
if err != nil {
	panic(err)
}

// -----------------
// get fts result
// -----------------

searchIndex := "ftsde" // search over both language indices for id search

f := []search.Query{}
f = append(f, search.NewMatchQuery("test").Analyzer("test").Field("title"))
cq := search.NewConjunctionQuery(f...)

start := time.Now()

matchResult, err := cluster.SearchQuery(
	searchIndex,
	cq,
	&gocb.SearchOptions{
		Limit: 10,
	},
)
if err != nil {
	panic(err)
}

for matchResult.Next() {
	row := matchResult.Row()
	fmt.Printf("Document ID: %s, search score: %f\n", row.ID, row.Score)
}

err = matchResult.Err()
if err != nil {
	panic(err)
}

elapsed := time.Since(start)
fmt.Println(elapsed)

// metadata of search.
searchMetadata, err := matchResult.MetaData()
if err != nil {
	panic(err)
}
fmt.Printf("%+v", searchMetadata.Metrics)

}

Result is:

Document ID: 15440904043944, search score: 5.645592
Document ID: 16032810983964, search score: 3.992036
Document ID: 15476322019054, search score: 2.987216
Document ID: 15476510453196, search score: 2.790567
Document ID: 15572179807867, search score: 2.692715
Document ID: 15571809006779, search score: 2.692715
Document ID: 15440907233320, search score: 2.651288
Document ID: 15476322187663, search score: 2.651288
Document ID: 15476504417609, search score: 2.651288
Document ID: 15480642954771, search score: 2.524786
8.049201ms
{Took:150.237ms TotalRows:41 MaxScore:5.645592100487007 TotalPartitionCount:0 SuccessPartitionCount:0 ErrorPartitionCount:0}

You see, Metrics shows a much slower query time than the whole execution time measured in go.
So I think Took() from Metrics can not be valid. I think that should be μs (microseconds) instead of ms (milliseconds). Go Library v1 shows in metrics also about 1’000 times faster results, so I think there is something wrong in v2. Or is there something that I do wrong?

Thanks, Pascal

2

Hi @gizmo74 thanks for raising this - you’re correct, the Go SDK is parsing the value incorrectly. The couchbase docs at Handling Response Objects | Couchbase Docs state that the actual time is in nanoseconds, in the Go SDK we are parsing as microseconds. I’ve raised https://issues.couchbase.com/browse/GOCBC-1100 and we’ll get this fixed for the June 2.3.0 release.

3

Thanks @chvck :slight_smile: I’m working on migrate our application from SDK 1 to SDK 2, so I do a lot of testing now. Maybe I found another problem related to search metadata:

 matchResult, err := cluster.SearchQuery(...)
	
// if I remove this line, I get "the result must be closed before accessing the meta-data" at "matchResult.MeataData()"
for matchResult.Next() {
}

// shouldn't these be enough, without iterating over all results?
err = matchResult.Close()
if err != nil {
  panic(err)
}

// metadata of search.
searchMetadata, err := matchResult.MetaData()
if err != nil {
  // panics here with "the result must be closed before accessing the meta-data" when not iterated over all results
  panic(err)
}

If I read the documentation correctly, it should be possible to iterate over all results or close the results. Both should work for getting the metadata.

4

@gizmo74 I think that this might an issue in the documentation. The way that the result is read from the server is as a stream which contains the rows before the metadata attributes. If you close the result early then we don’t know if we have the full attributes for the metadata (and it doesn’t make sense to read the whole stream to get them if Close has been called). Next implicitly reads the metadata and closes the stream when it detects that there are no further rows to be read. I’ve created https://issues.couchbase.com/browse/GOCBC-1101 to get the docs updated.

I hope that helps to clarify the behaviour.