[Bug] test failed

[suutaku]

Describe the bug
clone master, and run mage test first time, got failed result. but try agin maybe will passed. time cost also very long. (router test will take 92.222s)

To Reproduce
mage test

Expected behavior
Try more times, maybe 4 or 5 times.

Supporting Material

john@Station:ssi-service$ mage test
[test -tags=jwx_es256k -race -short ./...]?     github.com/tbd54566975/ssi-service/cmd  [no test files]
ok      github.com/tbd54566975/ssi-service/config       (cached)
ok      github.com/tbd54566975/ssi-service/integration  (cached)
?       github.com/tbd54566975/ssi-service/internal/credential  [no test files]
ok      github.com/tbd54566975/ssi-service/internal/did (cached)
ok      github.com/tbd54566975/ssi-service/internal/keyaccess   18.074s
?       github.com/tbd54566975/ssi-service/internal/schema      [no test files]
ok      github.com/tbd54566975/ssi-service/internal/util        (cached)
?       github.com/tbd54566975/ssi-service/pkg/jwt      [no test files]
time="2022-12-08T12:35:13+08:00" level=error msg="invalid create credential request" error="field validation error"
time="2022-12-08T12:35:13+08:00" level=error error="could not find key details for key: did:abc:123"
time="2022-12-08T12:35:13+08:00" level=error msg="could not get key for key: did:abc:123" error="could not find key details for key: did:abc:123"
time="2022-12-08T12:35:13+08:00" level=error msg="could not get key for signing credential with key<did:abc:123>" error="could not get key for key: did:abc:123: could not find key details for key: did:abc:123"
time="2022-12-08T12:35:13+08:00" level=error msg="could not sign credential" error="could not get key for signing credential with key<did:abc:123>: could not get key for key: did:abc:123: could not find key details for key: did:abc:123"
time="2022-12-08T12:35:13+08:00" level=error msg="could not create credential" error="could not sign credential: could not get key for signing credential with key<did:abc:123>: could not get key for key: did:abc:123: could not find key details for key: did:abc:123"
time="2022-12-08T12:35:14+08:00" level=error msg="could not get schema from storage" error="schema not found with id: bad"
time="2022-12-08T12:35:14+08:00" level=error msg="error getting schema: bad" error="schema not found with id: bad"
time="2022-12-08T12:35:14+08:00" level=error msg="failed to create credential; could not get schema: bad" error="error getting schema: bad: schema not found with id: bad"
time="2022-12-08T12:35:14+08:00" level=error msg="could not create credential" error="failed to create credential; could not get schema: bad: error getting schema: bad: schema not found with id: bad"
time="2022-12-08T12:35:15+08:00" level=error msg="cannot get credential without ID parameter"
time="2022-12-08T12:35:15+08:00" level=error error="could not get credential from storage credential not found with id: bad"
time="2022-12-08T12:35:15+08:00" level=error msg="could not get credential: bad" error="could not get credential from storage credential not found with id: bad"
time="2022-12-08T12:35:15+08:00" level=error msg="could not get credential with id: bad" error="could not get credential: bad: could not get credential from storage credential not found with id: bad"
time="2022-12-08T12:35:17+08:00" level=error error="could not get credential from storage credential not found with id: eebf3b31-04b1-4a93-827f-5f845812eed2"
time="2022-12-08T12:35:17+08:00" level=error msg="could not get credential: eebf3b31-04b1-4a93-827f-5f845812eed2" error="could not get credential from storage credential not found with id: eebf3b31-04b1-4a93-827f-5f845812eed2"
time="2022-12-08T12:35:17+08:00" level=error msg="could not get credential with id: eebf3b31-04b1-4a93-827f-5f845812eed2" error="could not get credential: eebf3b31-04b1-4a93-827f-5f845812eed2: could not get credential from storage credential not found with id: eebf3b31-04b1-4a93-827f-5f845812eed2"
time="2022-12-08T12:35:17+08:00" level=error msg="could not parse credential from JWT" error="could not parse credential token: failed to parse token: invalid character 'b' looking for beginning of value"
time="2022-12-08T12:35:18+08:00" level=warning msg="no credentials found for issuer: did:key:z6Mki1SNYgeVRdBrT3BeMKtLPntmdKB9ABMVqn3GdT2bJqGL and schema "
time="2022-12-08T12:35:18+08:00" level=warning msg="no credentials found for issuer: did:key:z6MkiU8WXnEUUb7E78D5gvnEJA7DhnwjhLLJNmwmgJAdgqos and schema "
time="2022-12-08T12:35:19+08:00" level=warning msg="no credentials found for issuer: did:key:z6MksvLcNBqrZ2aiZFqNR4hovdusYYt2Bf3ioX73FDscrXTe and schema "
time="2022-12-08T12:35:19+08:00" level=warning msg="no credentials found for issuer: did:key:z6Mkjc4bfc4j6FLYJMiTUtyDeWWHivX3eRSssVeAegd59uwA and schema "
time="2022-12-08T12:35:20+08:00" level=error msg="invalid create DID request" error=EOF
time="2022-12-08T12:35:20+08:00" level=error msg="could not create DID for method<key> with key type: bad" error="could not create did:key: unsupported did:key type: bad"
time="2022-12-08T12:35:20+08:00" level=error error="could not get handler for DID method: bad"
time="2022-12-08T12:35:20+08:00" level=error msg="could not get handler for method<bad>" error="could not get handler for DID method: bad"
time="2022-12-08T12:35:20+08:00" level=error msg="could not get DID for method<bad> with id: worse" error="could not get handler for method<bad>: could not get handler for DID method: bad"
time="2022-12-08T12:35:20+08:00" level=error msg="could not get DID: worse" error="malformed did: worse"
time="2022-12-08T12:35:20+08:00" level=error msg="could not get DID for method<key> with id: worse" error="error getting DID: worse"
time="2022-12-08T12:35:20+08:00" level=error error="could not get handler for DID method: bad"
time="2022-12-08T12:35:20+08:00" level=error msg="could not get handler for method<bad>" error="could not get handler for DID method: bad"
time="2022-12-08T12:35:20+08:00" level=error msg="could not get DIDs for method: bad" error="could not get handler for method<bad>: could not get handler for DID method: bad"
time="2022-12-08T12:35:20+08:00" level=error msg="namespace<did-key> does not exist"
time="2022-12-08T12:35:20+08:00" level=info msg="no DIDs found for method: key"
time="2022-12-08T12:35:20+08:00" level=error msg="could not resolve DID: bad" error="failed to get method for DID before resolving: not a valid did: bad"
time="2022-12-08T12:35:20+08:00" level=error msg="could not get DID with id: bad" error="could not resolve DID: bad: failed to get method for DID before resolving: not a valid did: bad"
time="2022-12-08T12:35:20+08:00" level=error msg="could not resolve DID: did:key:abcd" error="could not expand did:key DID: did:key:abcd: could not decode did:key: could not decode did:key: selected encoding not supported"
time="2022-12-08T12:35:20+08:00" level=error msg="could not get DID with id: did:key:abcd" error="could not resolve DID: did:key:abcd: could not expand did:key DID: did:key:abcd: could not decode did:key: could not decode did:key: selected encoding not supported"
time="2022-12-08T12:35:20+08:00" level=error msg="could not process store key request" error="could not convert bytes to private key: unsupported key type: bad"
time="2022-12-08T12:35:21+08:00" level=error msg="invalid create manifest request" error="field validation error"
time="2022-12-08T12:35:31+08:00" level=error msg="cannot get manifest without ID parameter"
time="2022-12-08T12:35:31+08:00" level=info msg="namespace<manifest> does not exist"
time="2022-12-08T12:35:31+08:00" level=error msg="could not get manifest from storage" error="manifest not found with id: bad"
time="2022-12-08T12:35:31+08:00" level=error msg="could not get manifest: bad" error="manifest not found with id: bad"
time="2022-12-08T12:35:31+08:00" level=error msg="could not get manifest with id: bad" error="could not get manifest: bad: manifest not found with id: bad"
time="2022-12-08T12:35:46+08:00" level=error msg="could not get manifest from storage" error="manifest not found with id: e4329cff-eb3a-426b-b0a4-d041801eb13a"
time="2022-12-08T12:35:46+08:00" level=error msg="could not get manifest: e4329cff-eb3a-426b-b0a4-d041801eb13a" error="manifest not found with id: e4329cff-eb3a-426b-b0a4-d041801eb13a"
time="2022-12-08T12:35:46+08:00" level=error msg="could not get manifest with id: e4329cff-eb3a-426b-b0a4-d041801eb13a" error="could not get manifest: e4329cff-eb3a-426b-b0a4-d041801eb13a: manifest not found with id: e4329cff-eb3a-426b-b0a4-d041801eb13a"
time="2022-12-08T12:35:47+08:00" level=error msg="could not parse application JWT" error="invalid compact serialization format: invalid number of segments"
time="2022-12-08T12:35:47+08:00" level=error msg="invalid submit application request" error="invalid compact serialization format: invalid number of segments"
time="2022-12-08T12:35:50+08:00" level=warning msg="could not find vc in Credential Application token, looking for `verifiableCredentials`"
time="2022-12-08T12:35:56+08:00" level=error msg="could not parse application JWT" error="invalid compact serialization format: invalid number of segments"
time="2022-12-08T12:35:56+08:00" level=error msg="invalid submit application request" error="invalid compact serialization format: invalid number of segments"
time="2022-12-08T12:35:59+08:00" level=warning msg="could not find vc in Credential Application token, looking for `verifiableCredentials`"
time="2022-12-08T12:36:03+08:00" level=warning msg="could not find vc in Credential Application token, looking for `verifiableCredentials`"
time="2022-12-08T12:36:09+08:00" level=error msg="cannot get application without ID parameter"
time="2022-12-08T12:36:13+08:00" level=warning msg="could not find vc in Credential Application token, looking for `verifiableCredentials`"
time="2022-12-08T12:36:24+08:00" level=warning msg="could not find vc in Credential Application token, looking for `verifiableCredentials`"
time="2022-12-08T12:36:30+08:00" level=error error="could not get application from storage; application not found with id: 556e18b5-f039-4dd1-b467-20b92dc9c331"
time="2022-12-08T12:36:30+08:00" level=error msg="could not get application: 556e18b5-f039-4dd1-b467-20b92dc9c331" error="could not get application from storage; application not found with id: 556e18b5-f039-4dd1-b467-20b92dc9c331"
time="2022-12-08T12:36:30+08:00" level=error msg="could not get application with id: 556e18b5-f039-4dd1-b467-20b92dc9c331" error="could not get application: 556e18b5-f039-4dd1-b467-20b92dc9c331: could not get application from storage; application not found with id: 556e18b5-f039-4dd1-b467-20b92dc9c331"
time="2022-12-08T12:36:30+08:00" level=error msg="namespace<operation> does not exist"
time="2022-12-08T12:37:02+08:00" level=error msg="invalid create submission request" error="verifying submission validity: presentation submission not valid against JSON schema: submission declaration not valid against schema: jsonschema file:///Users/john/Desktop/tmp/ssi-service/pkg/server/schema.json compilation failed: http://identity.foundation/claim-format-registry/schemas/presentation-submission-claim-format-designations.json returned status code 502"
time="2022-12-08T12:37:10+08:00" level=info msg="namespace<presentation_submission> does not exist"
time="2022-12-08T12:37:10+08:00" level=error msg="reading submission with id: f1c223c0-4fed-4d23-a3bf-c189e0b79d9c" error="submission not found"
time="2022-12-08T12:37:16+08:00" level=info msg="namespace<presentation_submission> does not exist"
time="2022-12-08T12:37:16+08:00" level=error msg="reading submission with id: 5d35d02b-c8fb-48d6-8b0f-6f8e12181e2c" error="submission not found"
--- FAIL: TestOperationsAPI (46.82s)
    --- FAIL: TestOperationsAPI/GetOperations (46.82s)
        --- FAIL: TestOperationsAPI/GetOperations/Returns_one_operation_for_every_submission (32.18s)
            server_presentation_test.go:427: 
                        Error Trace:    /Users/john/Desktop/tmp/ssi-service/pkg/server/server_presentation_test.go:427
                                                                /Users/john/Desktop/tmp/ssi-service/pkg/server/server_operation_test.go:45
                        Error:          Received unexpected error:
                                        invalid create submission request: verifying submission validity: presentation submission not valid against JSON schema: submission declaration not valid against schema: jsonschema file:///Users/john/Desktop/tmp/ssi-service/pkg/server/schema.json compilation failed: http://identity.foundation/claim-format-registry/schemas/presentation-submission-claim-format-designations.json returned status code 502
                        Test:           TestOperationsAPI/GetOperations/Returns_one_operation_for_every_submission
time="2022-12-08T12:37:20+08:00" level=error error="presentation definition not found with id: a7eb391d-e4d1-4acd-983d-0aa44e1f3a4b"
time="2022-12-08T12:37:20+08:00" level=error msg="error getting presentation definition: a7eb391d-e4d1-4acd-983d-0aa44e1f3a4b" error="presentation definition not found with id: a7eb391d-e4d1-4acd-983d-0aa44e1f3a4b"
time="2022-12-08T12:37:20+08:00" level=error msg="could not get presentation with id: a7eb391d-e4d1-4acd-983d-0aa44e1f3a4b" error="error getting presentation definition: a7eb391d-e4d1-4acd-983d-0aa44e1f3a4b: presentation definition not found with id: a7eb391d-e4d1-4acd-983d-0aa44e1f3a4b"
time="2022-12-08T12:37:20+08:00" level=error msg="Invalid Presentation Definition Request" error="field validation error"
time="2022-12-08T12:37:21+08:00" level=error msg="cannot get presentation without ID parameter"
time="2022-12-08T12:37:21+08:00" level=error msg="cannot delete a presentation without an ID parameter"
time="2022-12-08T12:37:21+08:00" level=error error="get submission request requires id"
time="2022-12-08T12:37:26+08:00" level=info msg="namespace<presentation_submission> does not exist"
time="2022-12-08T12:37:26+08:00" level=error msg="reading submission with id: b4befade-3be7-4708-9efe-f61809d2d9b7" error="submission not found"
time="2022-12-08T12:37:32+08:00" level=info msg="namespace<presentation_submission> does not exist"
time="2022-12-08T12:37:32+08:00" level=error msg="reading submission with id: ac5fa784-a623-4f50-ae9d-c77870740eb8" error="submission not found"
time="2022-12-08T12:37:33+08:00" level=error msg="namespace<presentation_submission> does not exist"
time="2022-12-08T12:37:38+08:00" level=info msg="namespace<presentation_submission> does not exist"
time="2022-12-08T12:37:38+08:00" level=error msg="reading submission with id: bf0b65ef-8c39-42a1-a18c-da0ac4f65b9c" error="submission not found"
time="2022-12-08T12:37:41+08:00" level=error msg="reading submission with id: b655aaab-9a85-4b92-ab45-8af3127300d8" error="submission not found"
time="2022-12-08T12:37:42+08:00" level=error msg="invalid filter" error="check call expr: check call expr: check call expr: check call expr: check call expr: check call expr: check call expr: check call expr: check call expr: check call expr: check call expr: undeclared identifier 'im'"
time="2022-12-08T12:38:25+08:00" level=error msg="Invalid Presentation Definition Request" error="presentation definition not ready to be built: presentation definition failed json schema validation: presentation definition not valid against schema"
time="2022-12-08T12:38:26+08:00" level=error msg="invalid create submission request" error="verifying submission validity: Key: 'PresentationSubmission.DefinitionID' Error:Field validation for 'DefinitionID' failed on the 'required' tag"
time="2022-12-08T12:38:31+08:00" level=info msg="namespace<presentation_submission> does not exist"
time="2022-12-08T12:38:31+08:00" level=error msg="reading submission with id: 032c806d-9d50-4a67-af2e-0e04cfc72572" error="submission not found"
--- FAIL: TestPresentationAPI (74.77s)
    --- FAIL: TestPresentationAPI/Submission_endpoints (70.94s)
        --- FAIL: TestPresentationAPI/Submission_endpoints/List_submissions_filters_based_on_status (43.77s)
            server_presentation_test.go:536: 
                        Error Trace:    /Users/john/Desktop/tmp/ssi-service/pkg/server/server_presentation_test.go:536
                                                                /Users/john/Desktop/tmp/ssi-service/pkg/server/server_presentation_test.go:320
                        Error:          Received unexpected error:
                                        Invalid Presentation Definition Request: presentation definition not ready to be built: presentation definition failed json schema validation: presentation definition not valid against schema
                        Test:           TestPresentationAPI/Submission_endpoints/List_submissions_filters_based_on_status
            server_presentation_test.go:538: 
                        Error Trace:    /Users/john/Desktop/tmp/ssi-service/pkg/server/server_presentation_test.go:538
                                                                /Users/john/Desktop/tmp/ssi-service/pkg/server/server_presentation_test.go:320
                        Error:          Received unexpected error:
                                        EOF
                        Test:           TestPresentationAPI/Submission_endpoints/List_submissions_filters_based_on_status
            server_presentation_test.go:427: 
                        Error Trace:    /Users/john/Desktop/tmp/ssi-service/pkg/server/server_presentation_test.go:427
                                                                /Users/john/Desktop/tmp/ssi-service/pkg/server/server_presentation_test.go:321
                        Error:          Received unexpected error:
                                        invalid create submission request: verifying submission validity: Key: 'PresentationSubmission.DefinitionID' Error:Field validation for 'DefinitionID' failed on the 'required' tag
                        Test:           TestPresentationAPI/Submission_endpoints/List_submissions_filters_based_on_status
time="2022-12-08T12:38:32+08:00" level=error msg="invalid create schema request" error="field validation error"
time="2022-12-08T12:38:32+08:00" level=error error="could not find key details for key: did:test"
time="2022-12-08T12:38:32+08:00" level=error msg="could not get key for key: did:test" error="could not find key details for key: did:test"
time="2022-12-08T12:38:32+08:00" level=error msg="could not get key for signing schema for author<did:test>" error="could not get key for key: did:test: could not find key details for key: did:test"
time="2022-12-08T12:38:32+08:00" level=error error="could not get key for signing schema for author<did:test>: could not get key for key: did:test: could not find key details for key: did:test"
time="2022-12-08T12:38:32+08:00" level=error msg="could not create schema with authoring DID: did:test" error="could not get key for signing schema for author<did:test>: could not get key for key: did:test: could not find key details for key: did:test"
time="2022-12-08T12:38:32+08:00" level=error msg="could not parse JWT" error="failed to parse token: invalid character 'b' looking for beginning of value"
time="2022-12-08T12:38:32+08:00" level=error msg="cannot get schema without ID parameter"
time="2022-12-08T12:38:32+08:00" level=info msg="namespace<schema> does not exist"
time="2022-12-08T12:38:32+08:00" level=error msg="could not get schema from storage" error="schema not found with id: bad"
time="2022-12-08T12:38:32+08:00" level=error msg="error getting schema: bad" error="schema not found with id: bad"
time="2022-12-08T12:38:32+08:00" level=error msg="could not get schema with id: bad" error="error getting schema: bad: schema not found with id: bad"
time="2022-12-08T12:38:32+08:00" level=error msg="namespace<schema> does not exist"
time="2022-12-08T12:38:32+08:00" level=info msg="no schemas to get"
time="2022-12-08T12:38:32+08:00" level=error error="namespace<schema> does not exist"
time="2022-12-08T12:38:32+08:00" level=error msg="could not delete schema: bad" error="namespace<schema> does not exist"
time="2022-12-08T12:38:32+08:00" level=error msg="could not delete schema with id: bad" error="could not delete schema: bad: namespace<schema> does not exist"
time="2022-12-08T12:38:32+08:00" level=error msg="could not delete schema with id: bad" error="could not delete schema with id: bad: could not delete schema: bad: namespace<schema> does not exist"
time="2022-12-08T12:38:32+08:00" level=error msg="could not get schema from storage" error="schema not found with id: 0989406c-c7ef-453b-bcff-7e31b16fa4dc"
time="2022-12-08T12:38:32+08:00" level=error msg="error getting schema: 0989406c-c7ef-453b-bcff-7e31b16fa4dc" error="schema not found with id: 0989406c-c7ef-453b-bcff-7e31b16fa4dc"
time="2022-12-08T12:38:32+08:00" level=error msg="could not get schema with id: 0989406c-c7ef-453b-bcff-7e31b16fa4dc" error="error getting schema: 0989406c-c7ef-453b-bcff-7e31b16fa4dc: schema not found with id: 0989406c-c7ef-453b-bcff-7e31b16fa4dc"
time="2022-12-08T12:38:32+08:00" level=info msg="no config path provided, loading default config..."
time="2022-12-08T12:38:33+08:00" level=info msg="Starting [7] service routers...\n"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<keystore> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<did> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<schema> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<credential> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<manifest> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<presentation> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<operation> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="no config path provided, loading default config..."
time="2022-12-08T12:38:33+08:00" level=info msg="Starting [7] service routers...\n"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<keystore> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<did> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<schema> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<credential> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<manifest> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<presentation> started successfully"
time="2022-12-08T12:38:33+08:00" level=info msg="Service router<operation> started successfully"
FAIL
FAIL    github.com/tbd54566975/ssi-service/pkg/server   202.722s
?       github.com/tbd54566975/ssi-service/pkg/server/framework [no test files]
?       github.com/tbd54566975/ssi-service/pkg/server/middleware        [no test files]
time="2022-12-08T12:35:12+08:00" level=error error="could not get credential from storage credential not found with id: bad"
time="2022-12-08T12:35:12+08:00" level=error msg="could not get credential: bad" error="could not get credential from storage credential not found with id: bad"
time="2022-12-08T12:35:12+08:00" level=info msg="namespace<schema> does not exist"
time="2022-12-08T12:35:12+08:00" level=error msg="could not get schema from storage" error="schema not found with id: https://test-schema.com"
time="2022-12-08T12:35:12+08:00" level=error msg="error getting schema: https://test-schema.com" error="schema not found with id: https://test-schema.com"
time="2022-12-08T12:35:12+08:00" level=error msg="failed to create credential; could not get schema: https://test-schema.com" error="error getting schema: https://test-schema.com: schema not found with id: https://test-schema.com"
time="2022-12-08T12:35:12+08:00" level=error error="could not get credential from storage credential not found with id: bad"
time="2022-12-08T12:35:12+08:00" level=warning msg="credential does not exist, cannot delete: bad"
time="2022-12-08T12:35:12+08:00" level=error error="could not get credential from storage credential not found with id: 62da112e-a031-4b26-8764-0f6858f1e257"
time="2022-12-08T12:35:12+08:00" level=error msg="could not get credential: 62da112e-a031-4b26-8764-0f6858f1e257" error="could not get credential from storage credential not found with id: 62da112e-a031-4b26-8764-0f6858f1e257"
time="2022-12-08T12:35:13+08:00" level=warning msg="no credentials found for issuer: did:key:z6MkjvpgFK36aq7DJ4sfZ5UX2yvbBEQ2RhYnpi5eg9XQ6ymq and schema ffc6849e-0c8f-4130-a365-c9c793171374"
time="2022-12-08T12:35:13+08:00" level=warning msg="no credentials found for issuer: did:key:z6MkjvpgFK36aq7DJ4sfZ5UX2yvbBEQ2RhYnpi5eg9XQ6ymq and schema ffc6849e-0c8f-4130-a365-c9c793171374"
time="2022-12-08T12:35:14+08:00" level=error error="could not get handler for DID method: bad"
time="2022-12-08T12:35:14+08:00" level=error msg="could not get handler for method<bad>" error="could not get handler for DID method: bad"
time="2022-12-08T12:35:15+08:00" level=error error="could not get handler for DID method: bad"
time="2022-12-08T12:35:15+08:00" level=error msg="could not get handler for method<bad>" error="could not get handler for DID method: bad"
time="2022-12-08T12:35:20+08:00" level=error error="unsupported key type: bad"
time="2022-12-08T12:35:20+08:00" level=error error="could not find key details for key: bad"
time="2022-12-08T12:35:20+08:00" level=error msg="could not get key details for key: bad" error="could not find key details for key: bad"
time="2022-12-08T12:35:20+08:00" level=error msg="could not get key details for key: bad" error="could not get key details for key: bad: could not find key details for key: bad"
time="2022-12-08T12:35:33+08:00" level=warning msg="could not find vc in Credential Application token, looking for `verifiableCredentials`"
--- FAIL: TestPresentationDefinitionService (63.41s)
    --- FAIL: TestPresentationDefinitionService/Get_returns_the_created_definition (61.14s)
        presentation_test.go:95: 
                Error Trace:    /Users/john/Desktop/tmp/ssi-service/pkg/server/router/presentation_test.go:95
                                                        /Users/john/Desktop/tmp/ssi-service/pkg/server/router/presentation_test.go:53
                Error:          Received unexpected error:
                                presentation definition not valid against schema
                                github.com/TBD54566975/ssi-sdk/credential/exchange.IsValidPresentationDefinition
                                        /Users/john/go-workspace/pkg/mod/github.com/!t!b!d54566975/[email protected]/credential/exchange/schema.go:30
                                github.com/TBD54566975/ssi-sdk/credential/exchange.(*PresentationDefinition).IsValid
                                        /Users/john/go-workspace/pkg/mod/github.com/!t!b!d54566975/[email protected]/credential/exchange/model.go:93
                                github.com/TBD54566975/ssi-sdk/credential/exchange.(*PresentationDefinitionBuilder).Build
                                        /Users/john/go-workspace/pkg/mod/github.com/!t!b!d54566975/[email protected]/credential/exchange/builder.go:34
                                github.com/tbd54566975/ssi-service/pkg/server/router.createPresentationDefinition
                                        /Users/john/Desktop/tmp/ssi-service/pkg/server/router/presentation_test.go:94
                                github.com/tbd54566975/ssi-service/pkg/server/router.TestPresentationDefinitionService.func3
                                        /Users/john/Desktop/tmp/ssi-service/pkg/server/router/presentation_test.go:53
                                testing.tRunner
                                        /usr/local/go/src/testing/testing.go:1439
                                runtime.goexit
                                        /usr/local/go/src/runtime/asm_amd64.s:1571
                                presentation definition failed json schema validation
                                github.com/TBD54566975/ssi-sdk/credential/exchange.(*PresentationDefinition).IsValid
                                        /Users/john/go-workspace/pkg/mod/github.com/!t!b!d54566975/[email protected]/credential/exchange/model.go:94
                                github.com/TBD54566975/ssi-sdk/credential/exchange.(*PresentationDefinitionBuilder).Build
                                        /Users/john/go-workspace/pkg/mod/github.com/!t!b!d54566975/[email protected]/credential/exchange/builder.go:34
                                github.com/tbd54566975/ssi-service/pkg/server/router.createPresentationDefinition
                                        /Users/john/Desktop/tmp/ssi-service/pkg/server/router/presentation_test.go:94
                                github.com/tbd54566975/ssi-service/pkg/server/router.TestPresentationDefinitionService.func3
                                        /Users/john/Desktop/tmp/ssi-service/pkg/server/router/presentation_test.go:53
                                testing.tRunner
                                        /usr/local/go/src/testing/testing.go:1439
                                runtime.goexit
                                        /usr/local/go/src/runtime/asm_amd64.s:1571
                                presentation definition not ready to be built
                                github.com/TBD54566975/ssi-sdk/credential/exchange.(*PresentationDefinitionBuilder).Build
                                        /Users/john/go-workspace/pkg/mod/github.com/!t!b!d54566975/[email protected]/credential/exchange/builder.go:35
                                github.com/tbd54566975/ssi-service/pkg/server/router.createPresentationDefinition
                                        /Users/john/Desktop/tmp/ssi-service/pkg/server/router/presentation_test.go:94
                                github.com/tbd54566975/ssi-service/pkg/server/router.TestPresentationDefinitionService.func3
                                        /Users/john/Desktop/tmp/ssi-service/pkg/server/router/presentation_test.go:53
                                testing.tRunner
                                        /usr/local/go/src/testing/testing.go:1439
                                runtime.goexit
                                        /usr/local/go/src/runtime/asm_amd64.s:1571
                Test:           TestPresentationDefinitionService/Get_returns_the_created_definition
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
        panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x1ea0693]

goroutine 303 [running]:
testing.tRunner.func1.2({0x1f60600, 0x2a465c0})
        /usr/local/go/src/testing/testing.go:1389 +0x366
testing.tRunner.func1()
        /usr/local/go/src/testing/testing.go:1392 +0x5d2
panic({0x1f60600, 0x2a465c0})
        /usr/local/go/src/runtime/panic.go:844 +0x258
github.com/tbd54566975/ssi-service/pkg/server/router.TestPresentationDefinitionService.func3(0x0?)
        /Users/john/Desktop/tmp/ssi-service/pkg/server/router/presentation_test.go:54 +0x93
testing.tRunner(0xc0063e76c0, 0xc005dac180)
        /usr/local/go/src/testing/testing.go:1439 +0x214
created by testing.(*T).Run
        /usr/local/go/src/testing/testing.go:1486 +0x725
FAIL    github.com/tbd54566975/ssi-service/pkg/server/router    92.222s
Error: running "go test -tags=jwx_es256k -race -short ./..." failed with exit code 1

Environment (please complete the following information):

• OS: Mac OSX
• Version 12.4
• Golang 1.18.4 darwin/amd64

Additional context
Looks like something timeout? but i did not get any message with timeout. first time run test will have some cache, try agin

[michaelneale]

odd - I cloned latest and it seemed reasonably quick (but I do have an M1 pro)

[suutaku]

It's some kind of network issue? or db lock?

[decentralgabe]

I'm guessing it's a db lock issue. cc: @nitro-neal I know you're looking into similar cases (like for revocations).

[suutaku]

After read some docs, func (t *T Run(name string, f func(t *T)) bool , It runs f in a separate goroutine and blocks until f returns or calls t.Parallel to become a parallel test. ssi-service closed and remove db file at every subtest with t.Run. I think it's the reason why test failed some times. how about split subtests into a single test funciton?

[suutaku]

About time cost, I don't know if there was a db lock issue at now, but network access really cost times in jsonschema's Loader. Maby we should consider add a Loader with cache into jsonschema.

[andresuribe87]

I'm pretty sure that this bug was introduced by me. It was because the DB was being created with the same file. I'm also pretty sure that it was fixed in #201.

I introduced a random file for the creation of the DB within each tests in the code below.

ssi-service/pkg/server/server_operation_test.go

Line 226 in 8f69172

file, err := os.CreateTemp("", "bolt")

RE: the long time to execute each test, 100% agree that it's network access from jsonschema. I'm closing this issue as solved, and opening another one related to tests taking a long time.

Thanks for the insights @suutaku