Skip to content

feat: Replace log.Println with slog for structured logging

6a5a793
Select commit
Loading
Failed to load commit list.
Draft

Replace log.Println with slog for structured logging #1602

feat: Replace log.Println with slog for structured logging
6a5a793
Select commit
Loading
Failed to load commit list.
Google Cloud Build / mixer-pull-request (datcom-ci) succeeded Aug 26, 2025 in 3m 31s

Summary

Build Information

Trigger mixer-pull-request
Build 909fd985-3192-47f7-b3ac-1d0b158c840e
Start 2025-08-26T12:13:16-07:00
Duration 2m38.065s
Status SUCCESS

Steps

Step Status Duration
lint SUCCESS 1m28.052s
build-proto SUCCESS 13.634s
test SUCCESS 2m17.216s

Details

starting build "909fd985-3192-47f7-b3ac-1d0b158c840e"

FETCHSOURCE
hint: Using 'master' as the name for the initial branch. This default branch name
hint: is subject to change. To configure the initial branch name to use in all
hint: of your new repositories, which will suppress this warning, call:
hint: 
hint: 	git config --global init.defaultBranch <name>
hint: 
hint: Names commonly chosen instead of 'master' are 'main', 'trunk' and
hint: 'development'. The just-created branch can be renamed via this command:
hint: 
hint: 	git branch -m <name>
Initialized empty Git repository in /workspace/.git/
From https://github.com/datacommonsorg/mixer
 * branch            6a5a793873e82456ad32da7adc1fc39d4b78db85 -> FETCH_HEAD
HEAD is now at 6a5a793 feat: Replace log.Println with slog for structured logging
GitCommit:
6a5a793873e82456ad32da7adc1fc39d4b78db85
BUILD
Starting Step #0 - "lint"
Starting Step #1 - "build-proto"
Step #0 - "lint": Pulling image: golangci/golangci-lint:v2.3.0-alpine
Step #1 - "build-proto": Pulling image: gcr.io/datcom-ci/go-protoc:2025-07-30
Step #1 - "build-proto": 2025-07-30: Pulling from datcom-ci/go-protoc
Step #1 - "build-proto": 9824c27679d3: Already exists
Step #1 - "build-proto": 2fc78e6fe765: Pulling fs layer
Step #1 - "build-proto": 8037d4fff50b: Pulling fs layer
Step #1 - "build-proto": ee9845387c02: Pulling fs layer
Step #1 - "build-proto": 4f4fb700ef54: Pulling fs layer
Step #1 - "build-proto": 8ce21599cf91: Pulling fs layer
Step #1 - "build-proto": 569e70303207: Pulling fs layer
Step #1 - "build-proto": 311f14333ec8: Pulling fs layer
Step #1 - "build-proto": b18c0b137746: Pulling fs layer
Step #1 - "build-proto": 719eb25d7e48: Pulling fs layer
Step #1 - "build-proto": 569e70303207: Waiting
Step #1 - "build-proto": 311f14333ec8: Waiting
Step #1 - "build-proto": b18c0b137746: Waiting
Step #1 - "build-proto": 719eb25d7e48: Waiting
Step #1 - "build-proto": 4f4fb700ef54: Waiting
Step #1 - "build-proto": ee9845387c02: Verifying Checksum
Step #1 - "build-proto": ee9845387c02: Download complete
Step #1 - "build-proto": 2fc78e6fe765: Verifying Checksum
Step #1 - "build-proto": 2fc78e6fe765: Download complete
Step #0 - "lint": v2.3.0-alpine: Pulling from golangci/golangci-lint
Step #1 - "build-proto": 2fc78e6fe765: Pull complete
Step #0 - "lint": 9824c27679d3: Already exists
Step #0 - "lint": cba8abde83f6: Pulling fs layer
Step #0 - "lint": a3e4aa2eec44: Pulling fs layer
Step #0 - "lint": 6d7cd9640707: Pulling fs layer
Step #0 - "lint": 4f4fb700ef54: Pulling fs layer
Step #0 - "lint": b1a7cf8d6878: Pulling fs layer
Step #0 - "lint": 15474b8446f7: Pulling fs layer
Step #0 - "lint": 41263325509e: Pulling fs layer
Step #0 - "lint": a3e4aa2eec44: Waiting
Step #0 - "lint": cba8abde83f6: Waiting
Step #0 - "lint": 6d7cd9640707: Waiting
Step #0 - "lint": 15474b8446f7: Waiting
Step #0 - "lint": 4f4fb700ef54: Waiting
Step #0 - "lint": 41263325509e: Waiting
Step #1 - "build-proto": 4f4fb700ef54: Verifying Checksum
Step #1 - "build-proto": 4f4fb700ef54: Download complete
Step #1 - "build-proto": 8ce21599cf91: Verifying Checksum
Step #1 - "build-proto": 8ce21599cf91: Download complete
Step #1 - "build-proto": 311f14333ec8: Verifying Checksum
Step #1 - "build-proto": 311f14333ec8: Download complete
Step #1 - "build-proto": 569e70303207: Verifying Checksum
Step #1 - "build-proto": 569e70303207: Download complete
Step #1 - "build-proto": 8037d4fff50b: Verifying Checksum
Step #1 - "build-proto": 8037d4fff50b: Download complete
Step #1 - "build-proto": b18c0b137746: Verifying Checksum
Step #1 - "build-proto": b18c0b137746: Download complete
Step #1 - "build-proto": 719eb25d7e48: Verifying Checksum
Step #1 - "build-proto": 719eb25d7e48: Download complete
Step #0 - "lint": cba8abde83f6: Verifying Checksum
Step #0 - "lint": cba8abde83f6: Download complete
Step #0 - "lint": cba8abde83f6: Pull complete
Step #0 - "lint": 6d7cd9640707: Verifying Checksum
Step #0 - "lint": 6d7cd9640707: Download complete
Step #0 - "lint": 4f4fb700ef54: Verifying Checksum
Step #0 - "lint": 4f4fb700ef54: Download complete
Step #0 - "lint": 15474b8446f7: Download complete
Step #0 - "lint": a3e4aa2eec44: Verifying Checksum
Step #0 - "lint": a3e4aa2eec44: Download complete
Step #0 - "lint": 41263325509e: Verifying Checksum
Step #0 - "lint": 41263325509e: Download complete
Step #1 - "build-proto": 8037d4fff50b: Pull complete
Step #1 - "build-proto": ee9845387c02: Pull complete
Step #1 - "build-proto": 4f4fb700ef54: Pull complete
Step #1 - "build-proto": 8ce21599cf91: Pull complete
Step #0 - "lint": b1a7cf8d6878: Verifying Checksum
Step #0 - "lint": b1a7cf8d6878: Download complete
Step #1 - "build-proto": 569e70303207: Pull complete
Step #1 - "build-proto": 311f14333ec8: Pull complete
Step #0 - "lint": a3e4aa2eec44: Pull complete
Step #1 - "build-proto": b18c0b137746: Pull complete
Step #0 - "lint": 6d7cd9640707: Pull complete
Step #0 - "lint": 4f4fb700ef54: Pull complete
Step #1 - "build-proto": 719eb25d7e48: Pull complete
Step #1 - "build-proto": Digest: sha256:a8a889890b66eec58f220d572c2fb4035112911af7e07f20d1f820253f0b27c8
Step #1 - "build-proto": Status: Downloaded newer image for gcr.io/datcom-ci/go-protoc:2025-07-30
Step #1 - "build-proto": gcr.io/datcom-ci/go-protoc:2025-07-30
Step #0 - "lint": b1a7cf8d6878: Pull complete
Step #0 - "lint": 15474b8446f7: Pull complete
Step #0 - "lint": 41263325509e: Pull complete
Step #0 - "lint": Digest: sha256:8cde2fcc8ccc6c8ca7d4476ac35ab30de546204368c678bc7080560e69952a62
Step #0 - "lint": Status: Downloaded newer image for golangci/golangci-lint:v2.3.0-alpine
Step #0 - "lint": docker.io/golangci/golangci-lint:v2.3.0-alpine
Step #0 - "lint": level=info msg="golangci-lint has version 2.3.0 built with go1.24.4 from 364a4bbe on 2025-07-21T14:49:16Z"
Step #0 - "lint": level=info msg="[config_reader] Config search paths: [./ /workspace / /builder/home]"
Step #0 - "lint": level=info msg="[config_reader] Used config file .golangci.yml"
Step #0 - "lint": level=info msg="[config_reader] Module name \"github.com/datacommonsorg/mixer\""
Step #0 - "lint": level=info msg="maxprocs: Leaving GOMAXPROCS=32: CPU quota undefined"
Step #0 - "lint": level=info msg="[goenv] Read go env for 3.933783ms: map[string]string{\"GOCACHE\":\"/builder/home/.cache/go-build\", \"GOROOT\":\"/usr/local/go\"}"
Step #0 - "lint": level=info msg="[lintersdb] Active 5 linters: [errcheck govet ineffassign staticcheck unused]"
Finished Step #1 - "build-proto"
Starting Step #2 - "test"
Step #2 - "test": Already have image (with digest): gcr.io/datcom-ci/go-protoc:2025-07-30
Step #2 - "test": go: downloading google.golang.org/api v0.243.0
Step #2 - "test": go: downloading modernc.org/sqlite v1.38.0
Step #2 - "test": go: downloading github.com/google/flatbuffers v23.5.26+incompatible
Step #2 - "test": go: downloading github.com/klauspost/compress v1.18.0
Step #2 - "test": go: downloading github.com/pierrec/lz4/v4 v4.1.18
Step #2 - "test": go: downloading modernc.org/libc v1.65.10
Step #2 - "test": go: downloading modernc.org/memory v1.11.0
Step #2 - "test": go: downloading modernc.org/mathutil v1.7.1
Step #2 - "test": go: downloading github.com/dustin/go-humanize v1.0.1
Step #0 - "lint": level=info msg="[loader] Go packages loading at mode 8767 (imports|exports_file|name|types_sizes|compiled_files|deps|files) took 47.740626526s"
Step #0 - "lint": level=info msg="[runner/filename_unadjuster] Pre-built 0 adjustments in 57.692418ms"
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/cmd	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/cmd/tools	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/examples/api	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/log	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/metrics	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/proto	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/proto/service	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/proto/v1	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/proto/v2	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/proto/v3	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/pubsub	[no test files]
Step #2 - "test": === RUN   TestMergeResolve
Step #2 - "test": --- PASS: TestMergeResolve (0.00s)
Step #2 - "test": === RUN   TestMergeLinkedGraph
Step #2 - "test": --- PASS: TestMergeLinkedGraph (0.00s)
Step #2 - "test": === RUN   TestMergeNode
Step #2 - "test": --- PASS: TestMergeNode (0.01s)
Step #2 - "test": === RUN   TestMergeMultiNode
Step #2 - "test": --- PASS: TestMergeMultiNode (0.01s)
Step #2 - "test": === RUN   TestMergeEvent
Step #2 - "test": --- PASS: TestMergeEvent (0.00s)
Step #2 - "test": === RUN   TestMergeObservation
Step #2 - "test": --- PASS: TestMergeObservation (0.00s)
Step #2 - "test": === RUN   TestMergeMultiObservation
Step #2 - "test": --- PASS: TestMergeMultiObservation (0.00s)
Step #2 - "test": === RUN   TestMergeBulkVariableInfoResponse
Step #2 - "test": --- PASS: TestMergeBulkVariableInfoResponse (0.00s)
Step #2 - "test": === RUN   TestMergeSearchStatVarResponse
Step #2 - "test": --- PASS: TestMergeSearchStatVarResponse (0.00s)
Step #2 - "test": === RUN   TestMergeFilterStatVarsByEntityResponse
Step #2 - "test": --- PASS: TestMergeFilterStatVarsByEntityResponse (0.00s)
Step #2 - "test": === RUN   TestMergeMultiNodeSearch
Step #2 - "test": --- PASS: TestMergeMultiNodeSearch (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/merger	0.030s
Step #2 - "test": === RUN   TestParseMapping
Step #2 - "test": --- PASS: TestParseMapping (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/parser/mcf	0.005s
Step #2 - "test": === RUN   TestParseComplexValue
Step #2 - "test": --- PASS: TestParseComplexValue (0.00s)
Step #2 - "test": === RUN   TestParseMcf
Step #2 - "test": --- PASS: TestParseMcf (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/parser/tmcf	0.005s
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/biopage	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/cache	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/convert	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/count	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/datasource	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/datasources	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/dispatcher	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/healthcheck	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/model	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/node	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/place	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/placein	[no test files]
Step #2 - "test": === RUN   TestBulkVariableInfo
Step #2 - "test": === PAUSE TestBulkVariableInfo
Step #2 - "test": === RUN   TestMaybeMirrorV3_Percentage
Step #2 - "test": === RUN   TestMaybeMirrorV3_Percentage/0_percent
Step #2 - "test": === RUN   TestMaybeMirrorV3_Percentage/100_percent
Step #2 - "test": --- PASS: TestMaybeMirrorV3_Percentage (0.10s)
Step #2 - "test":     --- PASS: TestMaybeMirrorV3_Percentage/0_percent (0.10s)
Step #2 - "test":     --- PASS: TestMaybeMirrorV3_Percentage/100_percent (0.00s)
Step #2 - "test": === RUN   TestMaybeMirrorV3_IgnoreSubsequentPages
Step #2 - "test": --- PASS: TestMaybeMirrorV3_IgnoreSubsequentPages (0.00s)
Step #2 - "test": === RUN   TestMaybeMirrorV3_LatencyMetric
Step #2 - "test": --- PASS: TestMaybeMirrorV3_LatencyMetric (0.00s)
Step #2 - "test": === RUN   TestMaybeMirrorV3_ResponseMismatch
Step #2 - "test": --- PASS: TestMaybeMirrorV3_ResponseMismatch (0.00s)
Step #2 - "test": === RUN   TestMaybeMirrorV3_ResponseMatch
Step #2 - "test": --- PASS: TestMaybeMirrorV3_ResponseMatch (0.00s)
Step #2 - "test": === RUN   TestMaybeMirrorV3_V3Error
Step #2 - "test": --- PASS: TestMaybeMirrorV3_V3Error (0.00s)
Step #2 - "test": === CONT  TestBulkVariableInfo
Step #2 - "test": --- PASS: TestBulkVariableInfo (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server	0.135s
Step #2 - "test": === RUN   TestDecode
Step #2 - "test": --- PASS: TestDecode (0.00s)
Step #2 - "test": === RUN   TestDecodeNextToken
Step #2 - "test": --- PASS: TestDecodeNextToken (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/pagination	0.019s
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/resource	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/statvar	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/statvar/fetcher	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/search	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/spanner	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/translator	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v0/internalbio	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v0/placestatvar	[no test files]
Step #2 - "test": === RUN   TestGetLocationsRankings
Step #2 - "test": === PAUSE TestGetLocationsRankings
Step #2 - "test": === RUN   TestGetPlaceStatDateWithinPlace
Step #2 - "test": === PAUSE TestGetPlaceStatDateWithinPlace
Step #2 - "test": === RUN   TestGetRelatedLocations
Step #2 - "test": === PAUSE TestGetRelatedLocations
Step #2 - "test": === CONT  TestGetLocationsRankings
Step #2 - "test": === CONT  TestGetRelatedLocations
Step #2 - "test": === CONT  TestGetPlaceStatDateWithinPlace
Step #2 - "test": --- PASS: TestGetPlaceStatDateWithinPlace (4.40s)
Step #2 - "test": --- PASS: TestGetLocationsRankings (4.45s)
Step #2 - "test": --- PASS: TestGetRelatedLocations (4.47s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/place/golden	4.549s
Step #2 - "test": === RUN   TestGetPlacesIn
Step #2 - "test": === PAUSE TestGetPlacesIn
Step #2 - "test": === CONT  TestGetPlacesIn
Step #2 - "test": --- PASS: TestGetPlacesIn (3.60s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/placein/golden	3.653s
Step #2 - "test": === RUN   TestGetScorePb
Step #2 - "test": --- PASS: TestGetScorePb (0.00s)
Step #2 - "test": === RUN   TestSeriesByRank
Step #2 - "test": --- PASS: TestSeriesByRank (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/ranking	0.009s
Step #2 - "test": === RUN   TestIsContainedIn
Step #2 - "test": --- PASS: TestIsContainedIn (0.12s)
Step #2 - "test": === RUN   TestTokenize
Step #2 - "test": --- PASS: TestTokenize (0.00s)
Step #2 - "test": === RUN   TestFindPlaceCandidates
Step #2 - "test": --- PASS: TestFindPlaceCandidates (0.00s)
Step #2 - "test": === RUN   TestReplaceTokensWithCandidates
Step #2 - "test": --- PASS: TestReplaceTokensWithCandidates (0.00s)
Step #2 - "test": === RUN   TestCombineContainedIn
Step #2 - "test": --- PASS: TestCombineContainedIn (0.00s)
Step #2 - "test": === RUN   TestRankAndTrimCandidates
Step #2 - "test": --- PASS: TestRankAndTrimCandidates (0.00s)
Step #2 - "test": === RUN   TestGetId2Span
Step #2 - "test": --- PASS: TestGetId2Span (0.00s)
Step #2 - "test": === RUN   TestSplitQueryBySpan
Step #2 - "test": --- PASS: TestSplitQueryBySpan (0.00s)
Step #2 - "test": === RUN   TestGetItemsForSpans
Step #2 - "test": --- PASS: TestGetItemsForSpans (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/recon	0.160s
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v0/statpoint	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v0/triple	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v1/event	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v1/info	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v1/observationdates	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v1/observationexistence	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v1/properties	[no test files]
Step #0 - "lint": level=info msg="[linters_context/goanalysis] analyzers took 4m10.340336904s with top 10 stages: buildir: 3m6.307321293s, inspect: 4.918477832s, nilness: 4.832971437s, fact_deprecated: 4.663254893s, fact_purity: 3.319411275s, printf: 2.741751777s, ctrlflow: 2.265821649s, directives: 1.871956536s, typedness: 1.61458946s, SA5012: 1.348583452s"
Step #0 - "lint": level=info msg="[runner/exclusion_paths] Skipped 270 issues by pattern \"internal/proto\""
Step #0 - "lint": level=info msg="[runner] Issues before processing: 288, after processing: 0"
Step #0 - "lint": level=info msg="[runner] Processors filtering stat (in/out): nolint_filter: 18/0, exclusion_paths: 288/18, cgo: 288/288, filename_unadjuster: 288/288, invalid_issue: 288/288, path_relativity: 288/288, generated_file_filter: 18/18, path_absoluter: 288/288, exclusion_rules: 18/18"
Step #0 - "lint": level=info msg="[runner] processing took 10.587286ms with stages: nolint_filter: 9.649263ms, generated_file_filter: 376.672µs, path_relativity: 240.399µs, exclusion_paths: 236.81µs, invalid_issue: 39.71µs, cgo: 21.138µs, path_absoluter: 8.954µs, filename_unadjuster: 4.181µs, sort_results: 2.681µs, max_same_issues: 2.133µs, exclusion_rules: 996ns, fixer: 598ns, path_shortener: 560ns, uniq_by_line: 536ns, diff: 523ns, path_prettifier: 515ns, source_code: 510ns, max_from_linter: 411ns, max_per_file_from_linter: 391ns, severity-rules: 305ns"
Step #0 - "lint": level=info msg="[runner] linters took 22.790002877s with stages: goanalysis_metalinter: 22.779277286s"
Step #0 - "lint": 0 issues.
Step #0 - "lint": level=info msg="File cache stats: 0 entries of total size 0B"
Step #0 - "lint": level=info msg="Memory: 705 samples, avg is 731.3MB, max is 2793.7MB"
Step #0 - "lint": level=info msg="Execution took 1m10.594135859s"
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v1/propertyvalues	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v1/triples	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v1/variable	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v1/variables	[no test files]
Step #2 - "test": === RUN   TestFindEntities
Step #2 - "test": === PAUSE TestFindEntities
Step #2 - "test": === RUN   TestRecognizeEntities
Step #2 - "test": === PAUSE TestRecognizeEntities
Step #2 - "test": === RUN   TestRecognizePlaces
Step #2 - "test": === PAUSE TestRecognizePlaces
Step #2 - "test": === RUN   TestResolveCoordinates
Step #2 - "test": === PAUSE TestResolveCoordinates
Step #2 - "test": === RUN   TestResolveEntities
Step #2 - "test": === PAUSE TestResolveEntities
Step #2 - "test": === RUN   TestResolveIds
Step #2 - "test": === PAUSE TestResolveIds
Step #2 - "test": === CONT  TestFindEntities
Step #2 - "test": === CONT  TestResolveIds
Step #2 - "test": === CONT  TestRecognizePlaces
Step #2 - "test": === CONT  TestResolveEntities
Step #2 - "test": === CONT  TestRecognizeEntities
Step #2 - "test": === CONT  TestResolveCoordinates
Step #2 - "test": --- PASS: TestResolveIds (9.78s)
Step #2 - "test": --- PASS: TestResolveEntities (9.91s)
Step #2 - "test": --- PASS: TestFindEntities (10.03s)
Step #2 - "test": --- PASS: TestRecognizePlaces (10.03s)
Step #2 - "test": --- PASS: TestRecognizeEntities (10.54s)
Step #2 - "test": --- PASS: TestResolveCoordinates (11.54s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/recon/golden	11.674s
Step #2 - "test": === RUN   TestCacheClient
Step #2 - "test": redis: 2025/08/26 19:14:37 commands.go:25: specified duration is 1ns, but minimal supported value is 1ms - truncating to 1ms
Step #2 - "test": redis: 2025/08/26 19:14:37 commands.go:25: specified duration is 1ns, but minimal supported value is 1ms - truncating to 1ms
Step #2 - "test": --- PASS: TestCacheClient (0.02s)
Step #2 - "test": === RUN   TestCompressionSize
Step #2 - "test": === RUN   TestCompressionSize/small
Step #2 - "test": === RUN   TestCompressionSize/medium
Step #2 - "test": === RUN   TestCompressionSize/large
Step #2 - "test": --- PASS: TestCompressionSize (0.01s)
Step #2 - "test":     --- PASS: TestCompressionSize/small (0.00s)
Step #2 - "test":     --- PASS: TestCompressionSize/medium (0.00s)
Step #2 - "test":     --- PASS: TestCompressionSize/large (0.01s)
Step #2 - "test": === RUN   TestGetRedisAddress
Step #2 - "test": === RUN   TestGetRedisAddress/us-central1
Step #2 - "test": === RUN   TestGetRedisAddress/us-east1
Step #2 - "test": === RUN   TestGetRedisAddress/default
Step #2 - "test": === RUN   TestGetRedisAddress/unconfigured_region
Step #2 - "test": --- PASS: TestGetRedisAddress (0.00s)
Step #2 - "test":     --- PASS: TestGetRedisAddress/us-central1 (0.00s)
Step #2 - "test":     --- PASS: TestGetRedisAddress/us-east1 (0.00s)
Step #2 - "test":     --- PASS: TestGetRedisAddress/default (0.00s)
Step #2 - "test":     --- PASS: TestGetRedisAddress/unconfigured_region (0.00s)
Step #2 - "test": === RUN   TestCacheProcessorPreProcess
Step #2 - "test": === RUN   TestCacheProcessorPreProcess/Cache_Hit
Step #2 - "test": 2025/08/26 19:14:37 Cache hit: *v2.NodeRequest
Step #2 - "test": === RUN   TestCacheProcessorPreProcess/Cache_Miss
Step #2 - "test": === RUN   TestCacheProcessorPreProcess/Cache_Error
Step #2 - "test": 2025/08/26 19:14:37 Error getting cached response: failed to get from Redis: redis error
Step #2 - "test": --- PASS: TestCacheProcessorPreProcess (0.00s)
Step #2 - "test":     --- PASS: TestCacheProcessorPreProcess/Cache_Hit (0.00s)
Step #2 - "test":     --- PASS: TestCacheProcessorPreProcess/Cache_Miss (0.00s)
Step #2 - "test":     --- PASS: TestCacheProcessorPreProcess/Cache_Error (0.00s)
Step #2 - "test": === RUN   TestCacheProcessorPostProcess
Step #2 - "test": === RUN   TestCacheProcessorPostProcess/Cache_Success
Step #2 - "test": === RUN   TestCacheProcessorPostProcess/Cache_Error
Step #2 - "test": 2025/08/26 19:14:37 Error caching response: failed to set in Redis: redis error
Step #2 - "test": === RUN   TestCacheProcessorPostProcess/No_Response
Step #2 - "test": --- PASS: TestCacheProcessorPostProcess (0.01s)
Step #2 - "test":     --- PASS: TestCacheProcessorPostProcess/Cache_Success (0.00s)
Step #2 - "test":     --- PASS: TestCacheProcessorPostProcess/Cache_Error (0.00s)
Step #2 - "test":     --- PASS: TestCacheProcessorPostProcess/No_Response (0.00s)
Step #2 - "test": === RUN   TestNewEmptyResponse
Step #2 - "test": === RUN   TestNewEmptyResponse/Node
Step #2 - "test": === RUN   TestNewEmptyResponse/Observation
Step #2 - "test": === RUN   TestNewEmptyResponse/NodeSearch
Step #2 - "test": === RUN   TestNewEmptyResponse/Resolve
Step #2 - "test": --- PASS: TestNewEmptyResponse (0.00s)
Step #2 - "test":     --- PASS: TestNewEmptyResponse/Node (0.00s)
Step #2 - "test":     --- PASS: TestNewEmptyResponse/Observation (0.00s)
Step #2 - "test":     --- PASS: TestNewEmptyResponse/NodeSearch (0.00s)
Step #2 - "test":     --- PASS: TestNewEmptyResponse/Resolve (0.00s)
Step #2 - "test": === RUN   TestSkipCache
Step #2 - "test": === RUN   TestSkipCache/Don't_Skip_Cache
Step #2 - "test": 2025/08/26 19:14:37 Cache hit: *v2.NodeRequest
Step #2 - "test": === RUN   TestSkipCache/Skip_Cache
Step #2 - "test": --- PASS: TestSkipCache (0.00s)
Step #2 - "test":     --- PASS: TestSkipCache/Don't_Skip_Cache (0.00s)
Step #2 - "test":     --- PASS: TestSkipCache/Skip_Cache (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/redis	0.062s
Step #2 - "test": === RUN   TestUpdateNodeRequestNextToken
Step #2 - "test": --- PASS: TestUpdateNodeRequestNextToken (0.00s)
Step #2 - "test": === RUN   TestUpdateNodeResponseNextToken
Step #2 - "test": --- PASS: TestUpdateNodeResponseNextToken (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/remote	0.044s
Step #2 - "test": === RUN   TestNode
Step #2 - "test": 2025/08/26 19:14:37 INFO Spanner graph not enabled.
Step #2 - "test": --- PASS: TestNode (0.00s)
Step #2 - "test": === RUN   TestGetNodePropsQuery
Step #2 - "test": === PAUSE TestGetNodePropsQuery
Step #2 - "test": === RUN   TestGetNodeOutEdgesByIDQuery
Step #2 - "test": === PAUSE TestGetNodeOutEdgesByIDQuery
Step #2 - "test": === RUN   TestGetNodeInEdgesByIDQuery
Step #2 - "test": === PAUSE TestGetNodeInEdgesByIDQuery
Step #2 - "test": === RUN   TestGetObservationsQuery
Step #2 - "test": === PAUSE TestGetObservationsQuery
Step #2 - "test": === RUN   TestGetObservationsContainedInPlaceQuery
Step #2 - "test": === PAUSE TestGetObservationsContainedInPlaceQuery
Step #2 - "test": === RUN   TestSearchNodesQuery
Step #2 - "test": === PAUSE TestSearchNodesQuery
Step #2 - "test": === RUN   TestResolveByIDQuery
Step #2 - "test": === PAUSE TestResolveByIDQuery
Step #2 - "test": === RUN   TestGetNodeProps
Step #2 - "test": 2025/08/26 19:14:37 INFO Spanner graph not enabled.
Step #2 - "test": --- PASS: TestGetNodeProps (0.00s)
Step #2 - "test": === RUN   TestGetNodeOutEdgesByID
Step #2 - "test": 2025/08/26 19:14:37 INFO Spanner graph not enabled.
Step #2 - "test": --- PASS: TestGetNodeOutEdgesByID (0.00s)
Step #2 - "test": === RUN   TestGetNodeInEdgesByID
Step #2 - "test": 2025/08/26 19:14:37 INFO Spanner graph not enabled.
Step #2 - "test": --- PASS: TestGetNodeInEdgesByID (0.00s)
Step #2 - "test": === RUN   TestGetObservations
Step #2 - "test": 2025/08/26 19:14:37 INFO Spanner graph not enabled.
Step #2 - "test": --- PASS: TestGetObservations (0.00s)
Step #2 - "test": === RUN   TestGetObservationsContainedInPlace
Step #2 - "test": 2025/08/26 19:14:37 INFO Spanner graph not enabled.
Step #2 - "test": --- PASS: TestGetObservationsContainedInPlace (0.00s)
Step #2 - "test": === RUN   TestSearchNodes
Step #2 - "test": 2025/08/26 19:14:37 INFO Spanner graph not enabled.
Step #2 - "test": --- PASS: TestSearchNodes (0.00s)
Step #2 - "test": === RUN   TestResolveByID
Step #2 - "test": 2025/08/26 19:14:37 INFO Spanner graph not enabled.
Step #2 - "test": --- PASS: TestResolveByID (0.00s)
Step #2 - "test": === CONT  TestGetNodePropsQuery
Step #2 - "test": === CONT  TestResolveByIDQuery
Step #2 - "test": --- PASS: TestGetNodePropsQuery (0.00s)
Step #2 - "test": === CONT  TestGetObservationsQuery
Step #2 - "test": --- PASS: TestGetObservationsQuery (0.00s)
Step #2 - "test": === CONT  TestGetNodeOutEdgesByIDQuery
Step #2 - "test": === CONT  TestGetNodeInEdgesByIDQuery
Step #2 - "test": --- PASS: TestGetNodeOutEdgesByIDQuery (0.00s)
Step #2 - "test": === CONT  TestSearchNodesQuery
Step #2 - "test": --- PASS: TestSearchNodesQuery (0.00s)
Step #2 - "test": --- PASS: TestGetNodeInEdgesByIDQuery (0.00s)
Step #2 - "test": --- PASS: TestResolveByIDQuery (0.00s)
Step #2 - "test": === CONT  TestGetObservationsContainedInPlaceQuery
Step #2 - "test": --- PASS: TestGetObservationsContainedInPlaceQuery (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/spanner/golden	0.067s
Step #2 - "test": === RUN   TestFilterAndRank
Step #2 - "test": --- PASS: TestFilterAndRank (0.00s)
Step #2 - "test": === RUN   TestByRank
Step #2 - "test": --- PASS: TestByRank (0.00s)
Step #2 - "test": === RUN   TestGetLatest
Step #2 - "test": --- PASS: TestGetLatest (0.00s)
Step #2 - "test": === RUN   TestGetValueFromBestSourcePb
Step #2 - "test": --- PASS: TestGetValueFromBestSourcePb (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/stat	0.056s
Step #2 - "test": === RUN   TestGetStatAll
Step #2 - "test": === PAUSE TestGetStatAll
Step #2 - "test": === RUN   TestGetStatDateWithinPlace
Step #2 - "test": === PAUSE TestGetStatDateWithinPlace
Step #2 - "test": === RUN   TestGetStatSeries
Step #2 - "test": === PAUSE TestGetStatSeries
Step #2 - "test": === RUN   TestGetStats
Step #2 - "test": === PAUSE TestGetStats
Step #2 - "test": === CONT  TestGetStatAll
Step #2 - "test": === CONT  TestGetStats
Step #2 - "test": === CONT  TestGetStatSeries
Step #2 - "test": === CONT  TestGetStatDateWithinPlace
Step #2 - "test": --- PASS: TestGetStatSeries (8.58s)
Step #2 - "test": --- PASS: TestGetStatDateWithinPlace (8.70s)
Step #2 - "test": --- PASS: TestGetStats (9.03s)
Step #2 - "test": --- PASS: TestGetStatAll (9.35s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/stat/golden	9.458s
Step #2 - "test": === RUN   TestParseNodeString
Step #2 - "test": --- PASS: TestParseNodeString (0.00s)
Step #2 - "test": === RUN   TestVariableFormulaParseFormula
Step #2 - "test": --- PASS: TestVariableFormulaParseFormula (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/statvar/formula	0.031s
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v2/facet	[no test files]
Finished Step #0 - "lint"
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v2/observation/helper	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v2/properties	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v2/propertyvalues	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/server/v3/observation	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/store	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/internal/translator/testutil	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/test/http_memprof	[no test files]
Step #2 - "test": ?   	github.com/datacommonsorg/mixer/tools/send_email	[no test files]
Step #2 - "test": === RUN   TestGetEntityStatVarsUnionV1
Step #2 - "test": === PAUSE TestGetEntityStatVarsUnionV1
Step #2 - "test": === RUN   TestGetPlaceStatsVar
Step #2 - "test": === PAUSE TestGetPlaceStatsVar
Step #2 - "test": === RUN   TestSearchStatVar
Step #2 - "test": 2025/08/26 19:14:37 Connected to sqlite db: /workspace/test/datacommo
...
[Logs truncated due to log size limitations. For full logs, see https://console.cloud.google.com/cloud-build/builds/909fd985-3192-47f7-b3ac-1d0b158c840e?project=879489846695.]
...
vations: 560.306µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetNodePredicates: 335.293µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetNodePredicates: 316.929µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 822.739µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetContainedInPlace: 261.16µs
Step #2 - "test": 2025/08/26 19:15:02 INFO Fetch series cache in contained-in observation query
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetContainedInPlace: 341.478µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 2.659957ms
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetNodePredicates: 6.909977ms
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 1.703032ms
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetContainedInPlace: 305.035µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 38.123438ms
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetContainedInPlace: 1.471205ms
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 2.700662ms
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetNodePredicates: 8.263869ms
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 487.796µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 491.812µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetContainedInPlace: 343.63µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 335.393µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 471.386µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 263.331µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetContainedInPlace: 419.495µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 517.634µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 243.283µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 371.048µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetContainedInPlace: 502.758µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 488.219µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 2.258928ms
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetObservations: 4.145086ms
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservationsByEntityType: 3.105528ms
Step #2 - "test": --- PASS: TestFetchContainIn (11.33s)
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 2.211978ms
Step #2 - "test": --- PASS: TestFetchDirect (11.34s)
Step #2 - "test": 2025/08/26 19:15:03 SQL: getNodeChunkTriples: 12.065145ms
Step #2 - "test": 2025/08/26 19:15:03 SQL: getNodeChunkTriples: 19.296272ms
Step #2 - "test": 2025/08/26 19:15:03 SQL: getNodeChunkTriples: 27.280658ms
Step #2 - "test": 2025/08/26 19:15:03 SQL: getNodeChunkTriples: 26.416334ms
Step #2 - "test": 2025/08/26 19:15:03 SQL: getNodeChunkTriples: 31.432359ms
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetNodeTriples: 31.571767ms
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetEntityInfoTriples: 409.13µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: getNodeChunkTriples: 30.753341ms
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetNodeTriples: 30.945355ms
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetEntityInfoTriples: 416.186µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetContainedInPlace: 431.72µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 503.31µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 479.581µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 425.653µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetContainedInPlace: 446.026µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 504.313µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 365.319µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 456.22µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetContainedInPlace: 426.167µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 540.16µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 304.981µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 393.55µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetContainedInPlace: 367.453µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 507.021µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 392.058µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 425.805µs
Step #2 - "test": --- PASS: TestCalculation (12.22s)
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetContainedInPlace: 316.512µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 913.889µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetContainedInPlace: 354.408µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetObservations: 922.608µs
Step #2 - "test": --- PASS: TestCalculationForObsCollection (12.30s)
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetContainedInPlace: 296.06µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetObservations: 813.471µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetContainedInPlace: 354.653µs
Step #2 - "test": 2025/08/26 19:15:04 INFO Fetch series cache in contained-in observation query
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetContainedInPlace: 262.545µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetObservations: 397.274µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetObservations: 8.560714ms
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetContainedInPlace: 360.57µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetObservations: 817.052µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetContainedInPlace: 341.944µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetObservations: 422.574µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetContainedInPlace: 332.503µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetObservations: 2.897957ms
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetContainedInPlace: 257.458µs
Step #2 - "test": 2025/08/26 19:15:04 INFO Fetch series cache in contained-in observation query
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetObservations: 11.244403ms
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetContainedInPlace: 282.278µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetObservations: 448ns
Step #2 - "test": 2025/08/26 19:15:05 SQL: GetObservationsByEntityType: 635.959µs
Step #2 - "test": --- PASS: TestFetchContainInLatest (13.35s)
Step #2 - "test": 2025/08/26 19:15:05 SQL: GetContainedInPlace: 352.988µs
Step #2 - "test": 2025/08/26 19:15:05 INFO Fetch series cache in contained-in observation query
Step #2 - "test": 2025/08/26 19:15:05 SQL: GetObservations: 986.865µs
Step #2 - "test": 2025/08/26 19:15:05 SQL: GetContainedInPlace: 296.186µs
Step #2 - "test": 2025/08/26 19:15:05 INFO Fetch series cache in contained-in observation query
Step #2 - "test": 2025/08/26 19:15:05 SQL: GetObservations: 4.108431ms
Step #2 - "test": 2025/08/26 19:15:06 SQL: GetContainedInPlace: 254.27µs
Step #2 - "test": 2025/08/26 19:15:06 INFO Fetch series cache in contained-in observation query
Step #2 - "test": 2025/08/26 19:15:06 SQL: GetObservations: 3.212029ms
Step #2 - "test": 2025/08/26 19:15:06 SQL: GetAllEntitiesOfType: 280.036µs
Step #2 - "test": 2025/08/26 19:15:06 INFO Fetch series cache in contained-in observation query
Step #2 - "test": 2025/08/26 19:15:07 SQL: GetObservationsByEntityType: 477.076µs
Step #2 - "test": --- PASS: TestFetchContainInAll (15.34s)
Step #2 - "test": 2025/08/26 19:15:10 SQL: GetKeyValue: 209.21µs
Step #2 - "test": 2025/08/26 19:15:10 SQL: GetStatVarGroups: 284.192µs
Step #2 - "test": 2025/08/26 19:15:10 SQL: GetAllStatisticalVariables: 278.471µs
Step #2 - "test": 2025/08/26 19:15:30 SQL: GetAllProvenances: 411.347µs
Step #2 - "test": 2025/08/26 19:15:30 SQL: GetAllEntitiesAndVariables: 229.892µs
Step #2 - "test": 2025/08/26 19:15:30 SQL: GetNodePredicates: 260.417µs
Step #2 - "test": 2025/08/26 19:15:30 SQL: getNodeChunkTriples: 575.234µs
Step #2 - "test": 2025/08/26 19:15:30 SQL: GetNodeTriples: 614.246µs
Step #2 - "test": 2025/08/26 19:15:30 SQL: GetEntityInfoTriples: 184.464µs
Step #2 - "test": 2025/08/26 19:15:30 SQL: GetNodePredicates: 503.706µs
Step #2 - "test": 2025/08/26 19:15:30 SQL: GetNodePredicates: 348.89µs
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetNodePredicates: 5.658943ms
Step #2 - "test": 2025/08/26 19:15:31 SQL: getNodeChunkTriples: 8.780364ms
Step #2 - "test": 2025/08/26 19:15:31 SQL: getNodeChunkTriples: 15.691845ms
Step #2 - "test": 2025/08/26 19:15:31 SQL: getNodeChunkTriples: 26.732655ms
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetNodeTriples: 28.581239ms
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetEntityInfoTriples: 381.593µs
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetExistingStatVarGroups: 378.987µs
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetExistingStatVarGroups: 277.498µs
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetExistingStatVarGroups: 253.899µs
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetExistingStatVarGroups: 267.599µs
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetExistingStatVarGroups: 255.104µs
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetExistingStatVarGroups: 284.16µs
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetExistingStatVarGroups: 281.256µs
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetExistingStatVarGroups: 257.631µs
Step #2 - "test": 2025/08/26 19:15:31 SQL: GetExistingStatVarGroups: 246.558µs
Step #2 - "test": 2025/08/26 19:15:32 SQL: GetExistingStatVarGroups: 296.011µs
Step #2 - "test": 2025/08/26 19:15:32 SQL: GetExistingStatVarGroups: 251.401µs
Step #2 - "test": 2025/08/26 19:15:32 SQL: GetExistingStatVarGroups: 265.541µs
Step #2 - "test": 2025/08/26 19:15:32 SQL: GetExistingStatVarGroups: 246.256µs
Step #2 - "test": --- PASS: TestExistence (40.44s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/v2/observation/golden	40.819s
Step #2 - "test": === RUN   TestPropertiesV2
Step #2 - "test": === PAUSE TestPropertiesV2
Step #2 - "test": === CONT  TestPropertiesV2
Step #2 - "test": 2025/08/26 19:14:52 Connected to sqlite db: /workspace/test/datacommons.db
Step #2 - "test": 2025/08/26 19:14:52 SQL tables check succeeded.
Step #2 - "test": 2025/08/26 19:14:52 SQL schema check succeeded.
Step #2 - "test": 2025/08/26 19:14:58 SQL: GetAllProvenances: 809.885µs
Step #2 - "test": 2025/08/26 19:14:58 SQL: GetAllEntitiesAndVariables: 458.833µs
Step #2 - "test": 2025/08/26 19:14:58 SQL: GetNodePredicates: 541.994µs
Step #2 - "test": 2025/08/26 19:14:58 SQL: GetNodePredicates: 358.026µs
Step #2 - "test": --- PASS: TestPropertiesV2 (6.37s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/v2/properties/golden	6.579s
Step #2 - "test": === RUN   TestContainedInPlace
Step #2 - "test": === PAUSE TestContainedInPlace
Step #2 - "test": === RUN   TestSimplePropertyValues
Step #2 - "test": === PAUSE TestSimplePropertyValues
Step #2 - "test": === RUN   TestSpecializationOf
Step #2 - "test": === PAUSE TestSpecializationOf
Step #2 - "test": === RUN   TestTripleIn
Step #2 - "test": === PAUSE TestTripleIn
Step #2 - "test": === RUN   TestTripleOut
Step #2 - "test": === PAUSE TestTripleOut
Step #2 - "test": === CONT  TestContainedInPlace
Step #2 - "test": === CONT  TestTripleIn
Step #2 - "test": === CONT  TestTripleOut
Step #2 - "test": === CONT  TestSpecializationOf
Step #2 - "test": === CONT  TestSimplePropertyValues
Step #2 - "test": 2025/08/26 19:14:52 Connected to sqlite db: /workspace/test/datacommons.db
Step #2 - "test": 2025/08/26 19:14:52 Connected to sqlite db: /workspace/test/datacommons.db
Step #2 - "test": 2025/08/26 19:14:52 Connected to sqlite db: /workspace/test/datacommons.db
Step #2 - "test": 2025/08/26 19:14:52 SQL tables check succeeded.
Step #2 - "test": 2025/08/26 19:14:52 SQL schema check succeeded.
Step #2 - "test": 2025/08/26 19:14:52 Connected to sqlite db: /workspace/test/datacommons.db
Step #2 - "test": 2025/08/26 19:14:52 SQL tables check succeeded.
Step #2 - "test": 2025/08/26 19:14:52 SQL schema check succeeded.
Step #2 - "test": 2025/08/26 19:14:52 SQL tables check succeeded.
Step #2 - "test": 2025/08/26 19:14:52 SQL schema check succeeded.
Step #2 - "test": 2025/08/26 19:14:52 SQL tables check succeeded.
Step #2 - "test": 2025/08/26 19:14:52 SQL schema check succeeded.
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetAllProvenances: 769.405µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetAllEntitiesAndVariables: 1.18589ms
Step #2 - "test": 2025/08/26 19:15:00 Could not read blocklist svg file. Use empty blocklist svg list.
Step #2 - "test": 2025/08/26 19:15:00 SQL: getNodeChunkTriples: 1.227147ms
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetNodeTriples: 1.285114ms
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetEntityInfoTriples: 240.075µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetAllProvenances: 525.428µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetAllEntitiesAndVariables: 296.107µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetAllProvenances: 435.961µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetAllEntitiesAndVariables: 276.76µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: getNodeChunkTriples: 536.013µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetNodeTriples: 577.624µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetAllProvenances: 419.757µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetAllEntitiesAndVariables: 243.159µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: getNodeChunkTriples: 632.388µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetNodeTriples: 675.053µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetNodePredicates: 438.231µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: getNodeChunkTriples: 678.68µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetNodeTriples: 735.122µs
Step #2 - "test": 2025/08/26 19:15:00 SQL: GetContainedInPlace: 295.467µs
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 580.045µs
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetNodeTriples: 619.915µs
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 1.254296ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetNodeTriples: 1.338277ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetEntityInfoTriples: 409.131µs
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetNodePredicates: 535.53µs
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 688.263µs
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetNodeTriples: 731.555µs
Step #2 - "test": --- PASS: TestTripleIn (9.00s)
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 19.680926ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 44.981138ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 48.131436ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 50.290566ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 50.309644ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 51.390038ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 54.815206ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetNodeTriples: 54.954689ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 547.831µs
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetNodeTriples: 585.561µs
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetNodePredicates: 461.553µs
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 1.248605ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetNodeTriples: 1.29141ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetEntityInfoTriples: 263.177µs
Step #2 - "test": --- PASS: TestTripleOut (9.26s)
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetContainedInPlace: 313.587µs
Step #2 - "test": 2025/08/26 19:15:01 SQL: getNodeChunkTriples: 1.171642ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetNodeTriples: 1.246846ms
Step #2 - "test": 2025/08/26 19:15:01 SQL: GetContainedInPlace: 568.4µs
Step #2 - "test": 2025/08/26 19:15:02 SQL: getNodeChunkTriples: 3.080745ms
Step #2 - "test": 2025/08/26 19:15:02 SQL: GetNodeTriples: 3.150052ms
Step #2 - "test": --- PASS: TestContainedInPlace (9.49s)
Step #2 - "test": 2025/08/26 19:15:03 SQL: getNodeChunkTriples: 702.632µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetNodeTriples: 743.144µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: getNodeChunkTriples: 571.187µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetNodeTriples: 609.186µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: getNodeChunkTriples: 704.787µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetNodeTriples: 763.821µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetEntityInfoTriples: 197.323µs
Step #2 - "test": 2025/08/26 19:15:03 SQL: GetNodePredicates: 309.985µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: getNodeChunkTriples: 778.42µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetNodeTriples: 820.998µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetEntityInfoTriples: 259.58µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetNodePredicates: 258.191µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: getNodeChunkTriples: 633.062µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetNodeTriples: 680.035µs
Step #2 - "test": 2025/08/26 19:15:04 SQL: GetEntityInfoTriples: 225.63µs
Step #2 - "test": --- PASS: TestSimplePropertyValues (11.54s)
Step #2 - "test": --- PASS: TestSpecializationOf (37.39s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/v2/propertyvalues/golden	37.683s
Step #2 - "test": === RUN   TestParseCoordinate
Step #2 - "test": --- PASS: TestParseCoordinate (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/v2/resolve	0.108s
Step #2 - "test": === RUN   TestResolveCoordinate
Step #2 - "test": === PAUSE TestResolveCoordinate
Step #2 - "test": === RUN   TestResolveDescription
Step #2 - "test": === PAUSE TestResolveDescription
Step #2 - "test": === RUN   TestResolveID
Step #2 - "test": === PAUSE TestResolveID
Step #2 - "test": === CONT  TestResolveCoordinate
Step #2 - "test": === CONT  TestResolveID
Step #2 - "test": === CONT  TestResolveDescription
Step #2 - "test": --- PASS: TestResolveID (7.32s)
Step #2 - "test": --- PASS: TestResolveDescription (8.46s)
Step #2 - "test": --- PASS: TestResolveCoordinate (8.52s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/v2/resolve/golden	8.706s
Step #2 - "test": === RUN   TestFetchChildPlaces
Step #2 - "test": === PAUSE TestFetchChildPlaces
Step #2 - "test": === CONT  TestFetchChildPlaces
Step #2 - "test": --- PASS: TestFetchChildPlaces (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/v2/shared	0.130s
Step #2 - "test": === RUN   TestV3Node
Step #2 - "test": --- PASS: TestV3Node (0.00s)
Step #2 - "test": === RUN   TestV3NodePagination
Step #2 - "test": --- PASS: TestV3NodePagination (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/v3/node/golden	0.094s
Step #2 - "test": === RUN   TestV3NodeSearch
Step #2 - "test": --- PASS: TestV3NodeSearch (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/v3/nodesearch/golden	0.244s
Step #2 - "test": === RUN   TestV3Observation
Step #2 - "test": --- PASS: TestV3Observation (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/v3/observation/golden	0.185s
Step #2 - "test": === RUN   TestV3Resolve
Step #2 - "test": --- PASS: TestV3Resolve (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/server/v3/resolve/golden	0.108s
Step #2 - "test": === RUN   TestId
Step #2 - "test": 2025/08/26 19:14:56 Connected to sqlite db: ../../test/sqlquery/key_value/datacommons.db
Step #2 - "test": --- PASS: TestId (0.00s)
Step #2 - "test": === RUN   TestGetKeyValue
Step #2 - "test": 2025/08/26 19:14:56 Connected to sqlite db: ../../test/sqlquery/key_value/datacommons.db
Step #2 - "test": 2025/08/26 19:14:56 SQL: GetKeyValue: 1.409514ms
Step #2 - "test": --- PASS: TestGetKeyValue (0.00s)
Step #2 - "test": === RUN   TestGenerateCTESelectStatement
Step #2 - "test": --- PASS: TestGenerateCTESelectStatement (0.00s)
Step #2 - "test": === RUN   TestChunkSlice
Step #2 - "test": --- PASS: TestChunkSlice (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/sqldb	0.045s
Step #2 - "test": === RUN   TestCountObservation
Step #2 - "test": 2025/08/26 19:14:56 Connected to sqlite db: ../../../test/datacommons.db
Step #2 - "test": 2025/08/26 19:14:56 SQL: GetObservationCount: 1.467332ms
Step #2 - "test": 2025/08/26 19:14:56 SQL: GetObservationCount: 1.12653ms
Step #2 - "test": --- PASS: TestCountObservation (0.01s)
Step #2 - "test": === RUN   TestGetImportTableData
Step #2 - "test": 2025/08/26 19:14:56 Connected to sqlite db: ../../../test/test_get_import_table_data.db
Step #2 - "test": 2025/08/26 19:14:56 SQL: GetAllImports: 1.361677ms
Step #2 - "test": --- PASS: TestGetImportTableData (0.00s)
Step #2 - "test": === RUN   TestGetStatVarSummaries
Step #2 - "test": 2025/08/26 19:14:56 Connected to sqlite db: ../../../test/sqlquery/statvar_summary/datacommons.db
Step #2 - "test": 2025/08/26 19:14:56 SQL tables check succeeded.
Step #2 - "test": 2025/08/26 19:14:56 SQL schema check succeeded.
Step #2 - "test": 2025/08/26 19:14:56 SQL: GetSVSummaries: 2.19917ms
Step #2 - "test": 2025/08/26 19:14:56 SQL: GetStatVarSummaries (var1, var2): 2.285338ms
Step #2 - "test": --- PASS: TestGetStatVarSummaries (0.01s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/sqldb/sqlquery	0.142s
Step #2 - "test": === RUN   TestReadOneTable
Step #2 - "test": --- PASS: TestReadOneTable (0.01s)
Step #2 - "test": === RUN   TestReadTwoTables
Step #2 - "test": --- PASS: TestReadTwoTables (0.01s)
Step #2 - "test": === RUN   TestSortTables
Step #2 - "test": --- PASS: TestSortTables (0.00s)
Step #2 - "test": === RUN   TestBuildRowList
Step #2 - "test": --- PASS: TestBuildRowList (0.00s)
Step #2 - "test": === RUN   TestParseTableInfo
Step #2 - "test": --- PASS: TestParseTableInfo (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/store/bigtable	0.067s
Step #2 - "test": === RUN   TestLoadRecogPlaceStore
Step #2 - "test": --- PASS: TestLoadRecogPlaceStore (4.01s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/store/files	4.064s
Step #2 - "test": === RUN   TestBind
Step #2 - "test": --- PASS: TestBind (0.00s)
Step #2 - "test": === RUN   TestGetBindings
Step #2 - "test": --- PASS: TestGetBindings (0.00s)
Step #2 - "test": === RUN   TestGetGraph
Step #2 - "test": --- PASS: TestGetGraph (0.00s)
Step #2 - "test": === RUN   TestGetConstraint
Step #2 - "test": --- PASS: TestGetConstraint (0.00s)
Step #2 - "test": === RUN   TestGetSQL
Step #2 - "test": --- PASS: TestGetSQL (0.00s)
Step #2 - "test": === RUN   TestTranslate
Step #2 - "test": --- PASS: TestTranslate (0.05s)
Step #2 - "test": === RUN   TestDcidSimplified
Step #2 - "test": --- PASS: TestDcidSimplified (0.00s)
Step #2 - "test": === RUN   TestTranslateIOCountyBQ
Step #2 - "test": Multiple functional deps: `dc_v3.bq_county_outcomes`->E2 => map[gender:`dc_v3.bq_county_outcomes`->gender location:`dc_v3.bq_county_outcomes`->E1 outcome:`dc_v3.bq_county_outcomes`->outcome percentile:`dc_v3.bq_county_outcomes`->percentile race:`dc_v3.bq_county_outcomes`->race]
Step #2 - "test": Multiple functional deps: `dc_v3.bq_county_outcomes`->E2 => map[gender:`dc_v3.bq_county_outcomes`->gender location:`dc_v3.bq_county_outcomes`->E1 outcome:`dc_v3.bq_county_outcomes`->outcome percentile:`dc_v3.bq_county_outcomes`->percentile race:`dc_v3.bq_county_outcomes`->race]
Step #2 - "test": --- PASS: TestTranslateIOCountyBQ (0.00s)
Step #2 - "test": === RUN   TestTranslateWeather
Step #2 - "test": Multiple functional deps: `dc_v3.MonthlyWeather`->E1 => map[observationDate:`dc_v3.MonthlyWeather`->observation_date observationPeriod:P1M observedNode:`dc_v3.MonthlyWeather`->E2]
Step #2 - "test": Multiple functional deps: `dc_v3.MonthlyWeather`->E1 => map[observationDate:`dc_v3.MonthlyWeather`->observation_date observationPeriod:P1M observedNode:`dc_v3.MonthlyWeather`->E2]
Step #2 - "test": Multiple functional deps: `dc_v3.MonthlyWeather`->E1 => map[observationDate:`dc_v3.MonthlyWeather`->observation_date observationPeriod:P1M observedNode:`dc_v3.MonthlyWeather`->E2]
Step #2 - "test": Multiple functional deps: `dc_v3.MonthlyWeather`->E1 => map[observationDate:`dc_v3.MonthlyWeather`->observation_date observationPeriod:P1M observedNode:`dc_v3.MonthlyWeather`->E2]
Step #2 - "test": --- PASS: TestTranslateWeather (0.00s)
Step #2 - "test": === RUN   TestTranslateWeatherSparql
Step #2 - "test": Multiple functional deps: `dc_v3.MonthlyWeather`->E1 => map[observationDate:`dc_v3.MonthlyWeather`->observation_date observationPeriod:P1M observedNode:`dc_v3.MonthlyWeather`->E2]
Step #2 - "test": Multiple functional deps: `dc_v3.MonthlyWeather`->E1 => map[observationDate:`dc_v3.MonthlyWeather`->observation_date observationPeriod:P1M observedNode:`dc_v3.MonthlyWeather`->E2]
Step #2 - "test": --- PASS: TestTranslateWeatherSparql (0.00s)
Step #2 - "test": === RUN   TestTranslatePew
Step #2 - "test": --- PASS: TestTranslatePew (0.00s)
Step #2 - "test": === RUN   TestSparql
Step #2 - "test": --- PASS: TestSparql (0.01s)
Step #2 - "test": === RUN   TestStatVarObs
Step #2 - "test": --- PASS: TestStatVarObs (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/translator	0.089s
Step #2 - "test": === RUN   TestSplit
Step #2 - "test": --- PASS: TestSplit (0.00s)
Step #2 - "test": === RUN   TestParseQuery
Step #2 - "test": --- PASS: TestParseQuery (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/translator/datalog	0.027s
Step #2 - "test": === RUN   TestGetNodeType
Step #2 - "test": --- PASS: TestGetNodeType (0.00s)
Step #2 - "test": === RUN   TestGetEntityType
Step #2 - "test": --- PASS: TestGetEntityType (0.00s)
Step #2 - "test": === RUN   TestGetExplicitTypeProp
Step #2 - "test": --- PASS: TestGetExplicitTypeProp (0.00s)
Step #2 - "test": === RUN   TestGetQueryID
Step #2 - "test": --- PASS: TestGetQueryID (0.00s)
Step #2 - "test": === RUN   TestMatchTriple
Step #2 - "test": --- PASS: TestMatchTriple (0.00s)
Step #2 - "test": === RUN   TestGetFuncDeps
Step #2 - "test": --- PASS: TestGetFuncDeps (0.00s)
Step #2 - "test": === RUN   TestGetFuncDepsWithEntity
Step #2 - "test": --- PASS: TestGetFuncDepsWithEntity (0.00s)
Step #2 - "test": === RUN   TestGetProvColumn
Step #2 - "test": --- PASS: TestGetProvColumn (0.00s)
Step #2 - "test": === RUN   TestRewriteQuery
Step #2 - "test": --- PASS: TestRewriteQuery (0.00s)
Step #2 - "test": === RUN   TestGetOutArcInfo
Step #2 - "test": --- PASS: TestGetOutArcInfo (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/translator/solver	0.024s
Step #2 - "test": === RUN   TestParsePrologue
Step #2 - "test": --- PASS: TestParsePrologue (0.00s)
Step #2 - "test": === RUN   TestParseSelect
Step #2 - "test": --- PASS: TestParseSelect (0.00s)
Step #2 - "test": === RUN   TestParseWhere
Step #2 - "test": --- PASS: TestParseWhere (0.00s)
Step #2 - "test": === RUN   TestParseOrderBy
Step #2 - "test": --- PASS: TestParseOrderBy (0.00s)
Step #2 - "test": === RUN   TestParseLimit
Step #2 - "test": --- PASS: TestParseLimit (0.00s)
Step #2 - "test": === RUN   TestParseTree
Step #2 - "test": --- PASS: TestParseTree (0.00s)
Step #2 - "test": === RUN   TestReader
Step #2 - "test": --- PASS: TestReader (0.00s)
Step #2 - "test": === RUN   TestScanSimple
Step #2 - "test": --- PASS: TestScanSimple (0.00s)
Step #2 - "test": === RUN   TestMulti
Step #2 - "test": --- PASS: TestMulti (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/translator/sparql	0.029s
Step #2 - "test": === RUN   TestQuery
Step #2 - "test": --- PASS: TestQuery (0.00s)
Step #2 - "test": === RUN   TestEntity
Step #2 - "test": --- PASS: TestEntity (0.00s)
Step #2 - "test": === RUN   TestColumn
Step #2 - "test": --- PASS: TestColumn (0.00s)
Step #2 - "test": === RUN   TestMapping
Step #2 - "test": --- PASS: TestMapping (0.00s)
Step #2 - "test": === RUN   TestTableAlias
Step #2 - "test": --- PASS: TestTableAlias (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/translator/types	0.020s
Step #2 - "test": === RUN   TestZipAndEndocde
Step #2 - "test": --- PASS: TestZipAndEndocde (0.00s)
Step #2 - "test": === RUN   TestSnakeToCamel
Step #2 - "test": --- PASS: TestSnakeToCamel (0.00s)
Step #2 - "test": === RUN   TestCheckValidDCIDs
Step #2 - "test": --- PASS: TestCheckValidDCIDs (0.00s)
Step #2 - "test": === RUN   TestMergeDedupe
Step #2 - "test": --- PASS: TestMergeDedupe (0.00s)
Step #2 - "test": === RUN   TestSample
Step #2 - "test": --- PASS: TestSample (0.00s)
Step #2 - "test": === RUN   TestKeysToSlice
Step #2 - "test": --- PASS: TestKeysToSlice (0.00s)
Step #2 - "test": === RUN   TestEncode
Step #2 - "test": --- PASS: TestEncode (0.01s)
Step #2 - "test": === RUN   TestStringListIntersection
Step #2 - "test": --- PASS: TestStringListIntersection (0.00s)
Step #2 - "test": === RUN   TestGetFacetID
Step #2 - "test": --- PASS: TestGetFacetID (0.00s)
Step #2 - "test": === RUN   TestShouldIncludeFacet
Step #2 - "test": --- PASS: TestShouldIncludeFacet (0.00s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/internal/util	0.046s
Step #2 - "test": === RUN   TestChartConfigRankings
Step #2 - "test": === PAUSE TestChartConfigRankings
Step #2 - "test": === CONT  TestChartConfigRankings
Step #2 - "test": === RUN   TestChartConfigRankings/missing_Earth_country_rankings.json
Step #2 - "test": === PAUSE TestChartConfigRankings/missing_Earth_country_rankings.json
Step #2 - "test": === RUN   TestChartConfigRankings/missing_USA_state_rankings.json
Step #2 - "test": === PAUSE TestChartConfigRankings/missing_USA_state_rankings.json
Step #2 - "test": === RUN   TestChartConfigRankings/missing_USA_county_rankings.json
Step #2 - "test": === PAUSE TestChartConfigRankings/missing_USA_county_rankings.json
Step #2 - "test": === RUN   TestChartConfigRankings/missing_USA_city_rankings.json
Step #2 - "test": === PAUSE TestChartConfigRankings/missing_USA_city_rankings.json
Step #2 - "test": === CONT  TestChartConfigRankings/missing_Earth_country_rankings.json
Step #2 - "test": === CONT  TestChartConfigRankings/missing_USA_city_rankings.json
Step #2 - "test": === CONT  TestChartConfigRankings/missing_USA_county_rankings.json
Step #2 - "test": === CONT  TestChartConfigRankings/missing_USA_state_rankings.json
Step #2 - "test": --- PASS: TestChartConfigRankings (4.53s)
Step #2 - "test":     --- PASS: TestChartConfigRankings/missing_USA_state_rankings.json (2.02s)
Step #2 - "test":     --- PASS: TestChartConfigRankings/missing_USA_county_rankings.json (2.02s)
Step #2 - "test":     --- PASS: TestChartConfigRankings/missing_Earth_country_rankings.json (2.03s)
Step #2 - "test":     --- PASS: TestChartConfigRankings/missing_USA_city_rankings.json (2.03s)
Step #2 - "test": PASS
Step #2 - "test": ok  	github.com/datacommonsorg/mixer/test	6.734s
Finished Step #2 - "test"
PUSH
DONE

Build Log: https://console.cloud.google.com/cloud-build/builds/909fd985-3192-47f7-b3ac-1d0b158c840e?project=879489846695