niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `checks.aarch64-linux.go-unit-tests` · build #281 · raw

1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenEmptyCommand97=== CONT TestShellSplit98=== CONT TestScriptTokenScriptFails99=== CONT TestScriptTokenBadJSON100=== CONT TestScriptTokenEmptyToken101=== CONT TestScriptTokenCachesUntilRefresh102=== CONT TestScriptTokenNoExpiryRerunsEveryCall103=== CONT TestFileTokenEmpty104=== CONT TestEncodeNixBase32105=== RUN TestEncodeNixBase32/test_string_hash106=== CONT TestEncodeNixBase32WithRealHash107=== CONT TestFileTokenMissing108=== CONT TestResolveStorePath109=== CONT TestParsePathInfoJSONMultiplePaths110=== CONT TestFileTokenReadsAndCaches111=== CONT TestParsePathInfoJSON112=== CONT TestStaticToken113=== CONT TestPathInfoHashCompatibility114=== CONT TestSetClientTLSErrors115=== CONT TestGetStorePathHash116=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess117=== CONT TestSetClientTLS118=== CONT TestConvertHashToNix321192026/10/01 07:31:55 WARN Rate limiter enabled after throttle name=server-test rate=5120=== RUN TestConvertHashToNix32/SRI_format_to_Nix32121=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32122=== CONT TestClientSignaturesByStorePath123=== CONT TestPathInfoCACompatibility124=== CONT TestUploadMultipart_SupersededByPeer125--- PASS: TestScriptTokenEmptyCommand (0.00s)126=== CONT TestStreamPushReportsSignatures127=== CONT TestDoWithRetry_BodyReplayedViaGetBody128=== PAUSE TestEncodeNixBase32/test_string_hash129=== CONT TestDumpPathWriterError130=== CONT TestStreamPushRequestLine131=== RUN TestUploadMultipart_SupersededByPeer/exists132--- PASS: TestShellSplit (0.00s)133--- PASS: TestScriptTokenScriptFails (0.00s)134=== CONT TestRateLimiterFeedback135=== RUN TestPathInfoCACompatibility/null_ca_field136=== PAUSE TestPathInfoCACompatibility/null_ca_field137=== RUN TestPathInfoCACompatibility/old_string_format_-_text138=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text139=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive140=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive141=== RUN TestPathInfoCACompatibility/new_structured_format_-_text142=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text143--- PASS: TestResolveStorePath (0.00s)144--- PASS: TestEncodeNixBase32WithRealHash (0.00s)145--- PASS: TestFileTokenEmpty (0.00s)146=== PAUSE TestUploadMultipart_SupersededByPeer/exists147=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== RUN TestParsePathInfoJSON/Nix_format149=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)150=== RUN TestGetStorePathHash/valid_store_path151=== CONT TestSetClientTLSDoesNotMutateDefaultTransport152=== RUN TestConvertHashToNix32/already_Nix32_format153=== CONT TestStreamPushGivesUpOnDeadServer154=== RUN TestRateLimiterFeedback/429_enables_limiter155=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method156=== RUN TestEncodeNixBase32/empty_input157=== PAUSE TestEncodeNixBase32/empty_input158--- PASS: TestStaticToken (0.00s)159--- PASS: TestFileTokenMissing (0.00s)160=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)161=== CONT TestDumpPathSingleFile162=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon163--- PASS: TestClientSignaturesByStorePath (0.00s)164--- PASS: TestScriptTokenBadJSON (0.01s)165=== CONT TestDumpPathMatchesNix166--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)167=== PAUSE TestRateLimiterFeedback/429_enables_limiter168=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon169=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method1702026/10/01 07:31:55 ERROR Upload failed error="connection refused" count=20171=== PAUSE TestGetStorePathHash/valid_store_path1722026/10/01 07:31:55 ERROR Server seems unavailable, giving up on batch untried=17173=== RUN TestUploadMultipart_SupersededByPeer/missing1742026/10/01 07:31:55 WARN Rate limiter enabled after throttle name=server-test rate=51752026/10/01 07:31:55 ERROR Upload failed error=boom count=11762026/10/01 07:31:55 ERROR Upload failed error=boom count=1177=== PAUSE TestConvertHashToNix32/already_Nix32_format178=== RUN TestRateLimiterFeedback/503_enables_limiter179=== PAUSE TestParsePathInfoJSON/Nix_format180=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI181=== CONT TestPartSizeForNAR182=== RUN TestParsePathInfoJSON/Lix_format183=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths184=== RUN TestGetStorePathHash/basename_without_hyphen_should_error185=== PAUSE TestUploadMultipart_SupersededByPeer/missing186=== CONT TestStreamPushBatchesUnderLoad1872026/10/01 07:31:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:46683188--- PASS: TestDoServerRequestAttachesToken (0.01s)189--- PASS: TestStreamPushReportsSignatures (0.01s)190--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)191=== CONT TestCaseHackSuffix192--- PASS: TestScriptTokenEmptyToken (0.01s)193=== CONT TestRegisterUploadedObjectReusesConnections194--- PASS: TestFileTokenReadsAndCaches (0.00s)195=== RUN TestSetClientTLSErrors/missing_cert_file196=== CONT TestShellSplitErrors197=== PAUSE TestSetClientTLSErrors/missing_cert_file198--- PASS: TestShellSplitErrors (0.00s)199=== CONT TestFilterOversizedClosures200=== RUN TestFilterOversizedClosures/no_limit_keeps_everything201=== RUN TestSetClientTLSErrors/missing_key_file202=== PAUSE TestSetClientTLSErrors/missing_key_file203=== RUN TestSetClientTLSErrors/missing_ca_file204=== PAUSE TestSetClientTLSErrors/missing_ca_file205=== RUN TestSetClientTLSErrors/invalid_ca_file206=== PAUSE TestSetClientTLSErrors/invalid_ca_file2072026/10/01 07:31:55 WARN Rate limiter backed off name=server-test rate=5208=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything2092026/10/01 07:31:55 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:46683210=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped211=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped212=== RUN TestSetClientTLS/rejects_connection_without_client_cert213=== RUN TestConvertHashToNix32/invalid_format214=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert215=== RUN TestFilterOversizedClosures/all_closures_skipped216=== PAUSE TestFilterOversizedClosures/all_closures_skipped217=== CONT TestStreamPushIsolatesFailures218=== CONT TestUploadMultipart_PartsInParallel219=== PAUSE TestConvertHashToNix32/invalid_format220=== PAUSE TestRateLimiterFeedback/503_enables_limiter221=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI222=== PAUSE TestParsePathInfoJSON/Lix_format223=== RUN TestPartSizeForNAR/zero_stays_at_minimum224=== CONT TestStreamPushReportsEveryPath225=== CONT TestEncodeNixBase32/test_string_hash226=== CONT TestPathInfoCACompatibility/null_ca_field227=== CONT TestEncodeNixBase32/empty_input228=== CONT TestPathInfoCACompatibility/new_structured_format_-_text229=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method230=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive231=== CONT TestPathInfoCACompatibility/old_string_format_-_text232=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum233=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512234=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512235=== RUN TestParsePathInfoJSON/empty_input236=== PAUSE TestParsePathInfoJSON/empty_input237=== RUN TestParsePathInfoJSON/whitespace_only238--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)239=== RUN TestPartSizeForNAR/small_stays_at_minimum240=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2412026/10/01 07:31:55 ERROR Upload failed error="bad path" count=3242=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter243=== CONT TestUploadMultipart_SupersededByPeer/exists244=== CONT TestUploadMultipart_SupersededByPeer/missing245=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error246=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA247=== PAUSE TestParsePathInfoJSON/whitespace_only248--- PASS: TestStreamPushReportsEveryPath (0.00s)249=== PAUSE TestPartSizeForNAR/small_stays_at_minimum250=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter251=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter252=== CONT TestSetClientTLSErrors/invalid_ca_file253=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths254=== CONT TestSetClientTLSErrors/missing_ca_file255=== CONT TestSetClientTLSErrors/missing_cert_file256=== CONT TestSetClientTLSErrors/missing_key_file257--- PASS: TestStreamPushIsolatesFailures (0.00s)258=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA259=== RUN TestSetClientTLS/preserves_debug_logging_transport260=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter261=== PAUSE TestSetClientTLS/preserves_debug_logging_transport262=== CONT TestConvertHashToNix32/SRI_format_to_Nix32263--- PASS: TestEncodeNixBase32 (0.00s)264 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)265 --- PASS: TestEncodeNixBase32/empty_input (0.00s)266--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)267=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum268=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum269=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts270=== RUN TestParsePathInfoJSON/invalid_JSON271=== CONT TestConvertHashToNix32/invalid_format272=== CONT TestRateLimiterFeedback/429_enables_limiter273=== CONT TestFilterOversizedClosures/no_limit_keeps_everything274=== CONT TestFilterOversizedClosures/all_closures_skipped275=== CONT TestSetClientTLS/rejects_connection_without_client_cert2762026/10/01 07:31:55 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50277=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter278=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2792026/10/01 07:31:55 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000280=== CONT TestSetClientTLS/preserves_debug_logging_transport2812026/10/01 07:31:55 WARN Rate limiter enabled after throttle name=server-test rate=52822026/10/01 07:31:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:468412832026/10/01 07:31:55 WARN Rate limiter backed off name=server-test rate=5284=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA285=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths286=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter287=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error288=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error289=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error290=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error291=== CONT TestGetStorePathHash/valid_store_path292=== CONT TestConvertHashToNix32/already_Nix32_format293=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error294=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512295=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)296--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)297=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI298=== CONT TestGetStorePathHash/basename_without_hyphen_should_error299=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts300=== RUN TestPartSizeForNAR/1_TiB301=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon302=== PAUSE TestParsePathInfoJSON/invalid_JSON303=== CONT TestRateLimiterFeedback/503_enables_limiter304=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error305=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths306--- PASS: TestGetStorePathHash (0.05s)307 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)308 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)309 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)310 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)311--- PASS: TestDumpPathSingleFile (0.05s)312--- PASS: TestParsePathInfoJSONMultiplePaths (0.05s)313 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)314 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)315--- PASS: TestConvertHashToNix32 (0.02s)316 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)317 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)318 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)319--- PASS: TestPathInfoCACompatibility (0.01s)320 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)321 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)322 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)323 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)324 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.03s)325--- PASS: TestFilterOversizedClosures (0.01s)326 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)327 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)328 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)329=== PAUSE TestPartSizeForNAR/1_TiB330=== CONT TestParsePathInfoJSON/Lix_format331=== CONT TestParsePathInfoJSON/empty_input332=== CONT TestParsePathInfoJSON/Nix_format333=== RUN TestPartSizeForNAR/5_TiB_S3_max_object334--- PASS: TestPathInfoHashCompatibility (0.02s)335 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)336 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)337 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)338 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)339=== CONT TestParsePathInfoJSON/invalid_JSON340=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object341--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)342 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.03s)343 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.03s)344=== RUN TestPartSizeForNAR/capped_at_5_GiB345=== PAUSE TestPartSizeForNAR/capped_at_5_GiB346=== CONT TestPartSizeForNAR/zero_stays_at_minimum347=== CONT TestPartSizeForNAR/1_TiB348--- PASS: TestSetClientTLSErrors (0.01s)349 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)350 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)351 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)352 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)353=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts354=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum355=== CONT TestParsePathInfoJSON/whitespace_only356--- PASS: TestParsePathInfoJSON (0.06s)357 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)358 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)359 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)360 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)361 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)362=== CONT TestPartSizeForNAR/small_stays_at_minimum363=== CONT TestPartSizeForNAR/capped_at_5_GiB364=== CONT TestPartSizeForNAR/5_TiB_S3_max_object365--- PASS: TestPartSizeForNAR (0.05s)366 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)368 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)369 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)370 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)372 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)3732026/10/01 07:31:55 WARN Rate limiter enabled after throttle name=server-test rate=53742026/10/01 07:31:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:332693752026/10/01 07:31:55 WARN Rate limiter backed off name=server-test rate=5376--- PASS: TestRateLimiterFeedback (0.05s)377 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)380 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)3812026/10/01 07:31:55 http: TLS handshake error from 127.0.0.1:47042: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.05s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)386--- PASS: TestStreamPushRequestLine (0.07s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.07s)388--- PASS: TestDumpPathWriterError (0.07s)389--- PASS: TestCaseHackSuffix (0.08s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.12s)392--- PASS: TestUploadMultipart_PartsInParallel (0.66s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres1246513783/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres1246513783/data -l logfile start422423/build/postgres1246513783:5432 - no response4242026-10-01 07:31:57.617 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 07:31:57.618 UTC [128] LOG: listening on Unix socket "/build/postgres1246513783/.s.PGSQL.5432"4262026-10-01 07:31:57.622 UTC [135] LOG: database system was shut down at 2026-10-01 07:31:57 UTC4272026-10-01 07:31:57.626 UTC [128] LOG: database system is ready to accept connections428/build/postgres1246513783:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestResolveDBConnectionString466=== PAUSE TestResolveDBConnectionString467=== RUN TestLeadElectsOneAndHandsOver468=== PAUSE TestLeadElectsOneAndHandsOver469=== RUN TestLeadIncumbentWinsAfterRestart4702026-10-01 07:31:58.005 UTC [374] ERROR: relation "goose_db_version" does not exist at character 364712026-10-01 07:31:58.005 UTC [374] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4722026/10/01 07:31:58 OK 20241026095416_initial_model.sql (10.15ms)4732026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)4742026/10/01 07:31:58 OK 20251218171726_add_pins.sql (3.01ms)4752026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (2.73ms)4762026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.13ms)4772026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (2.04ms)4782026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (1.74ms)4792026/10/01 07:31:58 goose: successfully migrated database to version: 202609231200004802026/10/01 07:31:58 OK 1_commit_pending_closure.sql (1.65ms)4812026/10/01 07:31:58 OK 2_object_stats_trigger.sql (644.07µs)4822026/10/01 07:31:58 OK 3_commit_push.sql (612.35µs)4832026/10/01 07:31:58 goose: up to current file version: 34842026/10/01 07:31:58 INFO lead: acquired remote=192.0.2.1:12344852026/10/01 07:31:58 INFO lead: released remote=192.0.2.1:12344862026/10/01 07:31:58 INFO lead: acquired remote=192.0.2.1:12344872026/10/01 07:31:58 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadIncumbentWinsAfterRestart (0.79s)489=== RUN TestLeadEndsOnShutdown490=== PAUSE TestLeadEndsOnShutdown491=== RUN TestGCAdvisoryLockBlocksConcurrentRun4922026-10-01 07:31:58.779 UTC [384] ERROR: relation "goose_db_version" does not exist at character 364932026-10-01 07:31:58.779 UTC [384] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4942026/10/01 07:31:58 OK 20241026095416_initial_model.sql (10.06ms)4952026/10/01 07:31:58 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)4962026/10/01 07:31:58 OK 20251218171726_add_pins.sql (2.99ms)4972026/10/01 07:31:58 OK 20260628120000_add_object_size_and_stats.sql (3.11ms)4982026/10/01 07:31:58 OK 20260905000000_add_claims.sql (3.04ms)4992026/10/01 07:31:58 OK 20260920000000_drop_claims.sql (1.86ms)5002026/10/01 07:31:58 OK 20260923120000_add_pushes.sql (1.44ms)5012026/10/01 07:31:58 goose: successfully migrated database to version: 202609231200005022026/10/01 07:31:58 OK 1_commit_pending_closure.sql (1.65ms)5032026/10/01 07:31:58 OK 2_object_stats_trigger.sql (729.45µs)5042026/10/01 07:31:58 OK 3_commit_push.sql (576.95µs)5052026/10/01 07:31:58 goose: up to current file version: 3506--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestGCTaskStore_StartNew524=== PAUSE TestGCTaskStore_StartNew525=== RUN TestGCTaskStore_DeduplicateSameParams526=== PAUSE TestGCTaskStore_DeduplicateSameParams527=== RUN TestGCTaskStore_ConflictDifferentParams528=== PAUSE TestGCTaskStore_ConflictDifferentParams529=== RUN TestGCTaskStore_GetEmpty530=== PAUSE TestGCTaskStore_GetEmpty531=== RUN TestGCTaskStore_GetReturnsLatest532=== PAUSE TestGCTaskStore_GetReturnsLatest533=== RUN TestGCTaskStore_CompletedAllowsNewTask534=== PAUSE TestGCTaskStore_CompletedAllowsNewTask535=== RUN TestGCTaskStore_PhaseUpdates536=== PAUSE TestGCTaskStore_PhaseUpdates537=== RUN TestGCTaskStore_Fail538=== PAUSE TestGCTaskStore_Fail539=== RUN TestGracefulShutdownDrainsInflight540=== PAUSE TestGracefulShutdownDrainsInflight541=== RUN TestService_healthCheckHandler542=== PAUSE TestService_healthCheckHandler543=== RUN TestService_readinessHandler544=== PAUSE TestService_readinessHandler545=== RUN TestGenerateLandingPage546=== PAUSE TestGenerateLandingPage547=== RUN TestCacheConfigHandlerMaxNarSize548=== PAUSE TestCacheConfigHandlerMaxNarSize549=== RUN TestCreatePendingClosureRejectsOversizedNAR550=== PAUSE TestCreatePendingClosureRejectsOversizedNAR551=== RUN TestNARDeduplicationMetadataUploadBug552=== PAUSE TestNARDeduplicationMetadataUploadBug553=== RUN TestMetricsInventory554=== PAUSE TestMetricsInventory555=== RUN TestService_NativeMTLS556=== PAUSE TestService_NativeMTLS557=== RUN TestServerTLSConfig558=== PAUSE TestServerTLSConfig559=== RUN TestMultipartCleanup560=== PAUSE TestMultipartCleanup561=== RUN TestObjectStatsTrigger562=== PAUSE TestObjectStatsTrigger563=== RUN TestOrphanedObjectsGC564=== PAUSE TestOrphanedObjectsGC565=== RUN TestOrphanedObjectsGCStressTest566=== PAUSE TestOrphanedObjectsGCStressTest567=== RUN TestResurrectedObjectNotDeleted568=== PAUSE TestResurrectedObjectNotDeleted569=== RUN TestCreatePin_ReservedPins570=== PAUSE TestCreatePin_ReservedPins571=== RUN TestParseSingleRange572=== PAUSE TestParseSingleRange573=== RUN TestProxyHeadersOnlyTrustedOnSocket574=== PAUSE TestProxyHeadersOnlyTrustedOnSocket575=== RUN TestIsValidCachePath576=== PAUSE TestIsValidCachePath577=== RUN TestReadProxyNarinfo578=== PAUSE TestReadProxyNarinfo579=== RUN TestReadProxyNarinfoAlreadyDecompressed580=== PAUSE TestReadProxyNarinfoAlreadyDecompressed581=== RUN TestReadProxyNarStreaming582=== PAUSE TestReadProxyNarStreaming583=== RUN TestReadProxy404584=== PAUSE TestReadProxy404585=== RUN TestReadProxyInvalidPath586=== PAUSE TestReadProxyInvalidPath587=== RUN TestReadProxyHead588=== PAUSE TestReadProxyHead589=== RUN TestReadProxyConditionalGet590=== PAUSE TestReadProxyConditionalGet591=== RUN TestReadProxyRootRedirectsToIndexHTML592=== PAUSE TestReadProxyRootRedirectsToIndexHTML593=== RUN TestReadProxyDisabled594=== PAUSE TestReadProxyDisabled595=== RUN TestReadRedirectNar596=== PAUSE TestReadRedirectNar597=== RUN TestReadRedirectKeepsNarinfoProxied598=== PAUSE TestReadRedirectKeepsNarinfoProxied599=== RUN TestReadProxyRangeRequest600=== PAUSE TestReadProxyRangeRequest601=== RUN TestReadRedirectUsesPublicS3URL602=== PAUSE TestReadRedirectUsesPublicS3URL603=== RUN TestPush_OverlappingRootsStoreOneRowPerKey604=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey605=== RUN TestPush_CompleteCommitsEveryRoot606=== PAUSE TestPush_CompleteCommitsEveryRoot607=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit608=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit609=== RUN TestPush_RejectsBadRequests610=== PAUSE TestPush_RejectsBadRequests611=== RUN TestPush_SignsNarinfosOfItsPendingObjects612=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects613=== RUN TestRedundantMultipartUpload614=== PAUSE TestRedundantMultipartUpload615=== RUN TestCompleteMultipartUpload_ErrorButObjectExists616=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists617=== RUN TestCompletedNarNotReofferedAcrossClosures618=== PAUSE TestCompletedNarNotReofferedAcrossClosures619=== RUN TestPresignedUploadRegisteredBeforeCommit620=== PAUSE TestPresignedUploadRegisteredBeforeCommit621=== RUN TestService_Rustfstest622=== PAUSE TestService_Rustfstest623=== RUN TestParseSize624=== PAUSE TestParseSize625=== RUN TestSkippedUploadsHandler626=== PAUSE TestSkippedUploadsHandler627=== RUN TestSystemdListenerNotActivated628--- PASS: TestSystemdListenerNotActivated (0.00s)629=== RUN TestWatchdogBeatsWhenHealthy630--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)631=== RUN TestWatchdogSkipsWhenUnhealthy6322026/10/01 07:31:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6332026/10/01 07:31:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6342026/10/01 07:31:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6352026/10/01 07:31:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 07:31:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 07:31:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 07:31:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 07:31:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 07:31:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 07:31:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"642--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)643=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle644=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle645=== RUN TestProxyWriteTimeout646=== PAUSE TestProxyWriteTimeout647=== RUN TestIsValidUploadKey648=== PAUSE TestIsValidUploadKey649=== RUN TestUploadHandlersRejectInvalidKeys650=== PAUSE TestUploadHandlersRejectInvalidKeys651=== RUN TestUploadHandlersRejectOversizedBody652=== PAUSE TestUploadHandlersRejectOversizedBody653=== RUN TestService_cleanupPendingClosuresHandler654=== PAUSE TestService_cleanupPendingClosuresHandler655=== RUN TestService_createPendingClosureHandler656=== PAUSE TestService_createPendingClosureHandler657=== RUN TestService_verifyS3Integrity658=== PAUSE TestService_verifyS3Integrity659=== RUN TestCompleteMultipartUnregistered660=== PAUSE TestCompleteMultipartUnregistered661=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT662=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT663=== CONT TestIsValidUploadKey664=== RUN TestIsValidUploadKey/narinfo665=== CONT TestService_AuthMiddleware666=== CONT TestReadProxy404667=== CONT TestReadProxyNarStreaming668=== CONT TestReadProxyNarinfoAlreadyDecompressed669=== CONT TestReadProxyNarinfo670=== CONT TestIsValidCachePath671=== RUN TestIsValidCachePath/narinfo672=== CONT TestReadProxyInvalidPath673=== CONT TestProxyHeadersOnlyTrustedOnSocket674=== CONT TestProxyWriteTimeout675=== CONT TestParseSingleRange676=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle677=== CONT TestCreatePin_ReservedPins678=== CONT TestSkippedUploadsHandler679=== RUN TestProxyWriteTimeout/narinfo680=== PAUSE TestProxyWriteTimeout/narinfo681=== RUN TestProxyWriteTimeout/1_GiB_nar682=== PAUSE TestProxyWriteTimeout/1_GiB_nar683=== RUN TestParseSingleRange/none684=== PAUSE TestParseSingleRange/none685=== RUN TestParseSingleRange/unknown_unit686=== PAUSE TestParseSingleRange/unknown_unit687=== RUN TestProxyWriteTimeout/10_GiB_nar688=== PAUSE TestProxyWriteTimeout/10_GiB_nar689=== RUN TestParseSingleRange/multi-range_ignored690=== CONT TestResurrectedObjectNotDeleted6912026/10/01 07:31:59 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000692=== RUN TestProxyWriteTimeout/unknown_size693=== PAUSE TestProxyWriteTimeout/unknown_size694=== CONT TestParseSize695--- PASS: TestParseSize (0.00s)696=== CONT TestRedundantMultipartUpload697=== CONT TestServerTLSConfig698=== CONT TestOrphanedObjectsGCStressTest699=== CONT TestService_Rustfstest700=== CONT TestOrphanedObjectsGC701=== CONT TestPresignedUploadRegisteredBeforeCommit702=== CONT TestObjectStatsTrigger703=== CONT TestCompletedNarNotReofferedAcrossClosures704=== CONT TestMultipartCleanup705=== CONT TestCompleteMultipartUpload_ErrorButObjectExists706=== PAUSE TestIsValidUploadKey/narinfo707=== RUN TestIsValidUploadKey/nar_zst708=== PAUSE TestIsValidCachePath/narinfo709=== PAUSE TestParseSingleRange/multi-range_ignored710=== RUN TestServerTLSConfig/no_client_CA711=== PAUSE TestServerTLSConfig/no_client_CA712=== RUN TestServerTLSConfig/missing_CA_file713=== PAUSE TestServerTLSConfig/missing_CA_file714=== PAUSE TestIsValidUploadKey/nar_zst715=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars716=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars717=== RUN TestIsValidCachePath/nar_zst718=== PAUSE TestIsValidCachePath/nar_zst719=== RUN TestIsValidUploadKey/nar_xz720=== PAUSE TestIsValidUploadKey/nar_xz721=== RUN TestServerTLSConfig/not_a_PEM_file722=== RUN TestIsValidUploadKey/nar_plain723=== PAUSE TestServerTLSConfig/not_a_PEM_file724=== PAUSE TestIsValidUploadKey/nar_plain725=== RUN TestIsValidUploadKey/listing726=== RUN TestIsValidCachePath/nar_xz727=== PAUSE TestIsValidCachePath/nar_xz728=== RUN TestIsValidCachePath/nar_bz2729=== PAUSE TestIsValidCachePath/nar_bz2730=== RUN TestParseSingleRange/malformed_no_dash731=== PAUSE TestParseSingleRange/malformed_no_dash732=== CONT TestService_NativeMTLS733=== PAUSE TestIsValidUploadKey/listing734=== RUN TestIsValidUploadKey/build_log735=== PAUSE TestIsValidUploadKey/build_log736=== RUN TestIsValidUploadKey/build_log_home-manager_file737=== RUN TestIsValidCachePath/nar_uncompressed738=== PAUSE TestIsValidUploadKey/build_log_home-manager_file739=== RUN TestIsValidUploadKey/build_log_plus_in_name740=== PAUSE TestIsValidCachePath/nar_uncompressed741=== RUN TestIsValidCachePath/ls742=== PAUSE TestIsValidCachePath/ls743=== RUN TestIsValidCachePath/log744=== PAUSE TestIsValidCachePath/log745=== RUN TestIsValidCachePath/realisation746=== RUN TestParseSingleRange/malformed_both_empty747=== PAUSE TestIsValidUploadKey/build_log_plus_in_name748=== PAUSE TestIsValidCachePath/realisation749=== PAUSE TestParseSingleRange/malformed_both_empty750=== RUN TestIsValidUploadKey/build_log_question_mark751=== RUN TestIsValidCachePath/nix-cache-info752=== RUN TestParseSingleRange/malformed_end_before_start753=== PAUSE TestIsValidUploadKey/build_log_question_mark754=== RUN TestIsValidUploadKey/build_log_equals755=== PAUSE TestIsValidUploadKey/build_log_equals756=== RUN TestIsValidUploadKey/realisation757=== PAUSE TestIsValidUploadKey/realisation758=== RUN TestIsValidUploadKey/realisation_plus_in_output759=== PAUSE TestIsValidUploadKey/realisation_plus_in_output760=== RUN TestIsValidUploadKey/nix-cache-info761=== PAUSE TestIsValidUploadKey/nix-cache-info762=== RUN TestIsValidUploadKey/index.html763=== PAUSE TestIsValidUploadKey/index.html764=== RUN TestIsValidUploadKey/narinfo_key,_nar_type765=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type766=== RUN TestIsValidUploadKey/nar_key,_narinfo_type767=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type768=== RUN TestIsValidUploadKey/listing_key,_narinfo_type769=== PAUSE TestIsValidCachePath/nix-cache-info770=== RUN TestIsValidCachePath/index.html771=== PAUSE TestParseSingleRange/malformed_end_before_start772=== RUN TestParseSingleRange/closed773=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type774=== PAUSE TestIsValidCachePath/index.html775=== RUN TestIsValidCachePath/traversal_parent776=== PAUSE TestParseSingleRange/closed777=== RUN TestIsValidUploadKey/traversal778=== RUN TestParseSingleRange/open-ended779=== PAUSE TestParseSingleRange/open-ended780=== PAUSE TestIsValidUploadKey/traversal781=== RUN TestIsValidUploadKey/traversal_nar782=== PAUSE TestIsValidCachePath/traversal_parent783=== PAUSE TestIsValidUploadKey/traversal_nar784=== RUN TestIsValidUploadKey/absolute785=== RUN TestParseSingleRange/end_clamped_to_size786--- PASS: TestSkippedUploadsHandler (0.00s)787=== RUN TestIsValidCachePath/traversal_in_middle788=== CONT TestPush_SignsNarinfosOfItsPendingObjects789=== PAUSE TestIsValidUploadKey/absolute790=== PAUSE TestParseSingleRange/end_clamped_to_size791=== RUN TestParseSingleRange/suffix792=== PAUSE TestParseSingleRange/suffix793=== RUN TestParseSingleRange/suffix_exceeds_size794=== PAUSE TestParseSingleRange/suffix_exceeds_size795=== RUN TestParseSingleRange/single_byte796=== PAUSE TestParseSingleRange/single_byte797=== PAUSE TestIsValidCachePath/traversal_in_middle798=== RUN TestIsValidUploadKey/empty_key799=== RUN TestParseSingleRange/start_past_EOF800=== RUN TestIsValidCachePath/invalid_char_e801=== PAUSE TestIsValidCachePath/invalid_char_e802=== RUN TestIsValidCachePath/invalid_char_u803=== PAUSE TestIsValidCachePath/invalid_char_u804=== PAUSE TestIsValidUploadKey/empty_key805=== RUN TestIsValidUploadKey/unknown_type806=== PAUSE TestIsValidUploadKey/unknown_type807=== PAUSE TestParseSingleRange/start_past_EOF808=== RUN TestParseSingleRange/start_far_past_EOF809=== PAUSE TestParseSingleRange/start_far_past_EOF810=== RUN TestIsValidCachePath/random_path811=== CONT TestPush_RejectsBadRequests812=== PAUSE TestIsValidCachePath/random_path813=== RUN TestIsValidCachePath/empty814=== CONT TestMetricsInventory815=== PAUSE TestIsValidCachePath/empty816=== RUN TestIsValidCachePath/leading_slash817=== PAUSE TestIsValidCachePath/leading_slash818=== RUN TestIsValidCachePath/wrong_extension819=== PAUSE TestIsValidCachePath/wrong_extension820=== RUN TestIsValidCachePath/short_hash821=== PAUSE TestIsValidCachePath/short_hash822=== CONT TestNARDeduplicationMetadataUploadBug8232026/10/01 07:31:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42443/oidc8242026-10-01 07:31:59.199 UTC [452] ERROR: relation "goose_db_version" does not exist at character 368252026-10-01 07:31:59.199 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8262026-10-01 07:31:59.212 UTC [453] ERROR: relation "goose_db_version" does not exist at character 368272026-10-01 07:31:59.212 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8282026-10-01 07:31:59.214 UTC [454] ERROR: relation "goose_db_version" does not exist at character 368292026-10-01 07:31:59.214 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8302026-10-01 07:31:59.217 UTC [455] ERROR: relation "goose_db_version" does not exist at character 368312026-10-01 07:31:59.217 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8322026-10-01 07:31:59.242 UTC [456] ERROR: relation "goose_db_version" does not exist at character 368332026-10-01 07:31:59.242 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8342026-10-01 07:31:59.244 UTC [457] ERROR: relation "goose_db_version" does not exist at character 368352026-10-01 07:31:59.244 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8362026/10/01 07:31:59 OK 20241026095416_initial_model.sql (35.22ms)8372026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)8382026/10/01 07:31:59 OK 20241026095416_initial_model.sql (51.45ms)8392026/10/01 07:31:59 OK 20251218171726_add_pins.sql (44.94ms)8402026/10/01 07:31:59 OK 20241026095416_initial_model.sql (62.91ms)8412026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (11.61ms)8422026/10/01 07:31:59 OK 20241026095416_initial_model.sql (66.89ms)8432026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (12.08ms)8442026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (10.88ms)8452026/10/01 07:31:59 OK 20251218171726_add_pins.sql (20.12ms)8462026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (24.98ms)8472026/10/01 07:31:59 OK 20251218171726_add_pins.sql (10.55ms)8482026/10/01 07:31:59 OK 20241026095416_initial_model.sql (74ms)8492026/10/01 07:31:59 OK 20241026095416_initial_model.sql (73.89ms)8502026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (9.94ms)8512026/10/01 07:31:59 OK 20260905000000_add_claims.sql (13.44ms)8522026/10/01 07:31:59 OK 20251218171726_add_pins.sql (16.99ms)8532026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (11.3ms)8542026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (13.59ms)8552026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (11.37ms)8562026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.78ms)8572026/10/01 07:31:59 OK 20251218171726_add_pins.sql (6.58ms)8582026/10/01 07:31:59 OK 20260905000000_add_claims.sql (6.47ms)8592026/10/01 07:31:59 OK 20251218171726_add_pins.sql (6.32ms)8602026/10/01 07:31:59 OK 20260905000000_add_claims.sql (6.45ms)8612026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (6.57ms)8622026/10/01 07:31:59 goose: successfully migrated database to version: 202609231200008632026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (10.49ms)8642026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (6.24ms)8652026-10-01 07:31:59.353 UTC [460] ERROR: relation "goose_db_version" does not exist at character 368662026-10-01 07:31:59.353 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8672026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (6.61ms)8682026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (6.47ms)8692026-10-01 07:31:59.354 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368702026-10-01 07:31:59.354 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8712026-10-01 07:31:59.354 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368722026-10-01 07:31:59.354 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8732026-10-01 07:31:59.354 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368742026-10-01 07:31:59.354 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8752026-10-01 07:31:59.354 UTC [464] ERROR: relation "goose_db_version" does not exist at character 368762026-10-01 07:31:59.354 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8772026-10-01 07:31:59.355 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368782026-10-01 07:31:59.355 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8792026/10/01 07:31:59 OK 1_commit_pending_closure.sql (4.68ms)8802026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (8.52ms)8812026-10-01 07:31:59.356 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368822026-10-01 07:31:59.356 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8832026-10-01 07:31:59.356 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368842026-10-01 07:31:59.356 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8852026/10/01 07:31:59 OK 20260905000000_add_claims.sql (5.66ms)8862026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (3.55ms)8872026/10/01 07:31:59 goose: successfully migrated database to version: 202609231200008882026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.81ms)8892026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.2ms)8902026/10/01 07:31:59 goose: successfully migrated database to version: 202609231200008912026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.21ms)8922026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.44ms)8932026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.15ms)8942026/10/01 07:31:59 OK 3_commit_push.sql (790.75µs)8952026/10/01 07:31:59 goose: up to current file version: 38962026/10/01 07:31:59 OK 1_commit_pending_closure.sql (1.92ms)8972026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.27ms)8982026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.23ms)8992026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.12ms)9002026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.49ms)9012026/10/01 07:31:59 goose: successfully migrated database to version: 202609231200009022026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.09ms)9032026-10-01 07:31:59.363 UTC [468] ERROR: relation "goose_db_version" does not exist at character 369042026-10-01 07:31:59.363 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9052026-10-01 07:31:59.364 UTC [469] ERROR: relation "goose_db_version" does not exist at character 369062026-10-01 07:31:59.364 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9072026/10/01 07:31:59 OK 3_commit_push.sql (3.25ms)9082026-10-01 07:31:59.365 UTC [471] ERROR: relation "goose_db_version" does not exist at character 369092026-10-01 07:31:59.365 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9102026-10-01 07:31:59.365 UTC [472] ERROR: relation "goose_db_version" does not exist at character 369112026-10-01 07:31:59.365 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9122026/10/01 07:31:59 goose: up to current file version: 39132026-10-01 07:31:59.365 UTC [470] ERROR: relation "goose_db_version" does not exist at character 369142026-10-01 07:31:59.365 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026/10/01 07:31:59 OK 3_commit_push.sql (2.16ms)9162026/10/01 07:31:59 goose: up to current file version: 39172026/10/01 07:31:59 OK 1_commit_pending_closure.sql (3.8ms)9182026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (4.69ms)9192026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (3.63ms)9202026/10/01 07:31:59 goose: successfully migrated database to version: 202609231200009212026-10-01 07:31:59.367 UTC [473] ERROR: relation "goose_db_version" does not exist at character 369222026-10-01 07:31:59.367 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9232026-10-01 07:31:59.369 UTC [474] ERROR: relation "goose_db_version" does not exist at character 369242026-10-01 07:31:59.369 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9252026-10-01 07:31:59.370 UTC [475] ERROR: relation "goose_db_version" does not exist at character 369262026-10-01 07:31:59.370 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9272026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (3.14ms)9282026/10/01 07:31:59 goose: successfully migrated database to version: 202609231200009292026/10/01 07:31:59 OK 1_commit_pending_closure.sql (3.98ms)9302026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.39ms)9312026-10-01 07:31:59.372 UTC [476] ERROR: relation "goose_db_version" does not exist at character 369322026-10-01 07:31:59.372 UTC [476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9332026-10-01 07:31:59.372 UTC [477] ERROR: relation "goose_db_version" does not exist at character 369342026-10-01 07:31:59.372 UTC [477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9352026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.97ms)9362026/10/01 07:31:59 OK 3_commit_push.sql (2.03ms)9372026/10/01 07:31:59 goose: up to current file version: 39382026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.09ms)9392026/10/01 07:31:59 OK 20241026095416_initial_model.sql (12.45ms)9402026/10/01 07:31:59 OK 3_commit_push.sql (2.45ms)9412026/10/01 07:31:59 goose: up to current file version: 39422026/10/01 07:31:59 OK 20241026095416_initial_model.sql (13.2ms)9432026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.59ms)9442026/10/01 07:31:59 OK 20241026095416_initial_model.sql (14.23ms)9452026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)9462026/10/01 07:31:59 OK 3_commit_push.sql (2.12ms)9472026/10/01 07:31:59 goose: up to current file version: 39482026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)9492026/10/01 07:31:59 OK 20241026095416_initial_model.sql (13.89ms)9502026/10/01 07:31:59 OK 20241026095416_initial_model.sql (13.69ms)9512026/10/01 07:31:59 OK 20241026095416_initial_model.sql (13.29ms)9522026/10/01 07:31:59 OK 20241026095416_initial_model.sql (12.91ms)9532026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)9542026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)9552026/10/01 07:31:59 OK 20251218171726_add_pins.sql (5.34ms)9562026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)9572026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (3.23ms)9582026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (3.75ms)9592026/10/01 07:31:59 OK 20241026095416_initial_model.sql (16.6ms)9602026/10/01 07:31:59 OK 20251218171726_add_pins.sql (6.09ms)9612026/10/01 07:31:59 OK 20251218171726_add_pins.sql (5.26ms)9622026/10/01 07:31:59 OK 20251218171726_add_pins.sql (3.91ms)9632026/10/01 07:31:59 OK 20241026095416_initial_model.sql (15.29ms)9642026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (3.56ms)9652026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.64ms)9662026/10/01 07:31:59 OK 20241026095416_initial_model.sql (15.8ms)9672026/10/01 07:31:59 OK 20241026095416_initial_model.sql (15.72ms)9682026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (6.49ms)9692026/10/01 07:31:59 OK 20251218171726_add_pins.sql (6.23ms)9702026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (5.67ms)9712026/10/01 07:31:59 OK 20241026095416_initial_model.sql (13.76ms)9722026/10/01 07:31:59 OK 20241026095416_initial_model.sql (16.38ms)9732026/10/01 07:31:59 OK 20241026095416_initial_model.sql (16.66ms)9742026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)9752026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (5.56ms)9762026/10/01 07:31:59 OK 20251218171726_add_pins.sql (7.84ms)9772026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (5.31ms)9782026/10/01 07:31:59 OK 20241026095416_initial_model.sql (15.5ms)9792026/10/01 07:31:59 OK 20241026095416_initial_model.sql (16.04ms)9802026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (3.29ms)9812026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)9822026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.72ms)9832026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)9842026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)9852026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (5.32ms)9862026/10/01 07:31:59 OK 20241026095416_initial_model.sql (13.16ms)9872026/10/01 07:31:59 OK 20251218171726_add_pins.sql (5.41ms)9882026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.75ms)989--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.33s)990=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit9912026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.59ms)9922026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (5.49ms)9932026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.16ms)9942026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.91ms)9952026/10/01 07:31:59 OK 20241026095416_initial_model.sql (14.26ms)9962026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)9972026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)9982026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.18ms)9992026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.86ms)10002026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)10012026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.25ms)10022026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.92ms)10032026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.1ms)10042026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.37ms)10052026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.34ms)10062026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.45ms)10072026/10/01 07:31:59 OK 20251218171726_add_pins.sql (5.01ms)10082026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.85ms)10092026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.81ms)10102026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.02ms)10112026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)10122026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.62ms)10132026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.01ms)10142026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.31ms)10152026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000010162026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.66ms)10172026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.95ms)10182026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.68ms)10192026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.26ms)10202026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.49ms)10212026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (3.09ms)10222026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)10232026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000010242026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.97ms)10252026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000010262026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.73ms)10272026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.27ms)10282026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.3ms)10292026/10/01 07:31:59 OK 20251218171726_add_pins.sql (3.94ms)10302026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.09ms)10312026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)10322026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000010332026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)10342026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.49ms)10352026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.97ms)10362026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.38ms)10372026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.68ms)10382026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000010392026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.22ms)10402026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.1ms)10412026/10/01 07:31:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1042--- PASS: TestService_AuthMiddleware (0.34s)1043=== CONT TestCreatePendingClosureRejectsOversizedNAR10442026/10/01 07:31:59 INFO Received uploads request method=POST path=/api/pending_closures10452026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.49ms)10462026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000010472026/10/01 07:31:59 OK 1_commit_pending_closure.sql (3.03ms)1048--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)10492026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.94ms)1050=== CONT TestPush_CompleteCommitsEveryRoot10512026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.28ms)10522026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)10532026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)10542026/10/01 07:31:59 OK 1_commit_pending_closure.sql (3.1ms)10552026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.05ms)10562026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.7ms)10572026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.92ms)10582026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.83ms)10592026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.53ms)10602026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.01ms)10612026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)10622026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.02ms)10632026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.4ms)10642026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.98ms)10652026/10/01 07:31:59 OK 3_commit_push.sql (1.92ms)10662026/10/01 07:31:59 goose: up to current file version: 310672026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.91ms)10682026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000010692026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.08ms)10702026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.75ms)10712026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.39ms)10722026/10/01 07:31:59 OK 3_commit_push.sql (1.45ms)10732026/10/01 07:31:59 goose: up to current file version: 310742026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4ms)10752026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.8ms)10762026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000010772026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.04ms)10782026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.77ms)10792026/10/01 07:31:59 OK 3_commit_push.sql (1.51ms)10802026/10/01 07:31:59 goose: up to current file version: 310812026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.79ms)10822026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.32ms)10832026/10/01 07:31:59 OK 3_commit_push.sql (2.27ms)10842026/10/01 07:31:59 goose: up to current file version: 310852026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.25ms)10862026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000010872026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.74ms)10882026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.38ms)10892026/10/01 07:31:59 OK 3_commit_push.sql (1.2ms)10902026/10/01 07:31:59 goose: up to current file version: 310912026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.15ms)10922026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.93ms)10932026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.14ms)10942026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.2ms)10952026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.46ms)10962026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.4ms)10972026/10/01 07:31:59 OK 3_commit_push.sql (1.43ms)10982026/10/01 07:31:59 goose: up to current file version: 310992026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.09ms)11002026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.18ms)11012026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.73ms)11022026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000011032026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.15ms)11042026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.69ms)11052026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.27ms)11062026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.33ms)11072026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.27ms)11082026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000011092026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.54ms)11102026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000011112026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.13ms)11122026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000011132026/10/01 07:31:59 OK 3_commit_push.sql (1.15ms)11142026/10/01 07:31:59 goose: up to current file version: 311152026/10/01 07:31:59 OK 3_commit_push.sql (885.97µs)11162026/10/01 07:31:59 goose: up to current file version: 311172026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.52ms)11182026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000011192026/10/01 07:31:59 OK 2_object_stats_trigger.sql (987.59µs)11202026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.97ms)11212026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.36ms)11222026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.31ms)11232026/10/01 07:31:59 OK 3_commit_push.sql (1.14ms)11242026/10/01 07:31:59 goose: up to current file version: 311252026/10/01 07:31:59 OK 1_commit_pending_closure.sql (1.65ms)11262026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.2ms)11272026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000011282026/10/01 07:31:59 OK 1_commit_pending_closure.sql (1.92ms)11292026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.3ms)11302026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000011312026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.32ms)11322026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.12ms)11332026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.82ms)11342026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.05ms)11352026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.23ms)11362026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (3.41ms)11372026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000011382026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.71ms)11392026/10/01 07:31:59 OK 3_commit_push.sql (948.31µs)11402026/10/01 07:31:59 goose: up to current file version: 311412026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.36ms)11422026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000011432026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.73ms)11442026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.64ms)11452026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.25ms)11462026/10/01 07:31:59 OK 3_commit_push.sql (785.17µs)11472026/10/01 07:31:59 goose: up to current file version: 311482026/10/01 07:31:59 OK 3_commit_push.sql (952.41µs)11492026/10/01 07:31:59 goose: up to current file version: 311502026/10/01 07:31:59 OK 3_commit_push.sql (829.47µs)11512026/10/01 07:31:59 goose: up to current file version: 311522026/10/01 07:31:59 OK 2_object_stats_trigger.sql (910.35µs)11532026/10/01 07:31:59 OK 3_commit_push.sql (1.07ms)11542026/10/01 07:31:59 goose: up to current file version: 311552026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.32ms)11562026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.11ms)11572026/10/01 07:31:59 OK 3_commit_push.sql (1.19ms)11582026/10/01 07:31:59 goose: up to current file version: 311592026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.58ms)11602026/10/01 07:31:59 OK 3_commit_push.sql (1.46ms)11612026/10/01 07:31:59 goose: up to current file version: 311622026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.5ms)11632026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.79ms)11642026/10/01 07:31:59 OK 3_commit_push.sql (2.03ms)11652026/10/01 07:31:59 goose: up to current file version: 311662026/10/01 07:31:59 OK 3_commit_push.sql (1.27ms)11672026/10/01 07:31:59 goose: up to current file version: 31168--- PASS: TestReadProxyNarinfo (0.37s)1169=== CONT TestCacheConfigHandlerMaxNarSize1170--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1171=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1172--- PASS: TestReadProxyNarStreaming (0.38s)1173=== CONT TestReadRedirectUsesPublicS3URL11742026/10/01 07:31:59 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket773622883/001/proxy.sock11752026/10/01 07:31:59 INFO Starting HTTP server address=127.0.0.1:4135511762026/10/01 07:31:59 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11772026/10/01 07:31:59 INFO Shutdown signal received, draining in-flight requests timeout=10s1178--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.40s)1179=== CONT TestGenerateLandingPage1180--- PASS: TestGenerateLandingPage (0.00s)1181=== CONT TestReadProxyRangeRequest1182--- PASS: TestReadProxyInvalidPath (0.42s)1183=== CONT TestService_readinessHandler11842026-10-01 07:31:59.499 UTC [492] ERROR: relation "goose_db_version" does not exist at character 3611852026-10-01 07:31:59.499 UTC [492] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11862026-10-01 07:31:59.499 UTC [493] ERROR: relation "goose_db_version" does not exist at character 3611872026-10-01 07:31:59.499 UTC [493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11882026/10/01 07:31:59 INFO Received uploads request method=POST path=/api/pending_closures11892026/10/01 07:31:59 OK 20241026095416_initial_model.sql (18.74ms)11902026/10/01 07:31:59 OK 20241026095416_initial_model.sql (19.44ms)11912026-10-01 07:31:59.530 UTC [494] ERROR: relation "goose_db_version" does not exist at character 3611922026-10-01 07:31:59.530 UTC [494] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11932026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)11942026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)11952026/10/01 07:31:59 OK 20251218171726_add_pins.sql (3.72ms)11962026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.83ms)11972026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)11982026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)11992026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.8ms)12002026-10-01 07:31:59.544 UTC [495] ERROR: relation "goose_db_version" does not exist at character 3612012026-10-01 07:31:59.544 UTC [495] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12022026/10/01 07:31:59 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12032026/10/01 07:31:59 INFO Received uploads request method=POST path=/api/pending_closures12042026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.79ms)12052026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.54ms)1206--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.48s)1207=== CONT TestReadRedirectKeepsNarinfoProxied12082026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.52ms)12092026/10/01 07:31:59 goose: successfully migrated database to version: 202609231200001210--- PASS: TestReadProxy404 (0.48s)1211=== CONT TestService_healthCheckHandler12122026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.27ms)12132026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.04ms)12142026/10/01 07:31:59 OK 20241026095416_initial_model.sql (12.84ms)12152026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.34ms)12162026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.05ms)12172026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000012182026-10-01 07:31:59.552 UTC [496] ERROR: relation "goose_db_version" does not exist at character 3612192026-10-01 07:31:59.552 UTC [496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12202026/10/01 07:31:59 OK 3_commit_push.sql (1.09ms)12212026/10/01 07:31:59 goose: up to current file version: 312222026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)12232026/10/01 07:31:59 OK 1_commit_pending_closure.sql (1.83ms)12242026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.42ms)12252026/10/01 07:31:59 OK 3_commit_push.sql (1.04ms)12262026/10/01 07:31:59 goose: up to current file version: 312272026/10/01 07:31:59 OK 20251218171726_add_pins.sql (3.43ms)12282026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)12292026/10/01 07:31:59 OK 20241026095416_initial_model.sql (11.68ms)12302026-10-01 07:31:59.562 UTC [501] ERROR: relation "goose_db_version" does not exist at character 3612312026-10-01 07:31:59.562 UTC [501] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12322026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)12332026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.79ms)12342026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.61ms)12352026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.95ms)12362026/10/01 07:31:59 OK 20241026095416_initial_model.sql (12.2ms)12372026/10/01 07:31:59 INFO Received uploads request method=POST path=/api/pending_closures12382026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.71ms)12392026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000012402026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)12412026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)12422026/10/01 07:31:59 OK 1_commit_pending_closure.sql (3.35ms)12432026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.33ms)12442026/10/01 07:31:59 OK 2_object_stats_trigger.sql (2.83ms)12452026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.8ms)12462026/10/01 07:31:59 OK 3_commit_push.sql (1.7ms)12472026/10/01 07:31:59 goose: up to current file version: 312482026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.67ms)12492026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.95ms)12502026/10/01 07:31:59 OK 20241026095416_initial_model.sql (12.75ms)12512026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (3.16ms)12522026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.4ms)12532026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (4.33ms)12542026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000012552026/10/01 07:31:59 INFO Received uploads request method=POST path=/api/pending_closures12562026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.86ms)12572026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.1ms)12582026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.42ms)12592026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.84ms)12602026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (3.2ms)12612026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000012622026/10/01 07:31:59 OK 3_commit_push.sql (1.92ms)12632026/10/01 07:31:59 goose: up to current file version: 312642026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)12652026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.35ms)12662026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.44ms)12672026/10/01 07:31:59 OK 3_commit_push.sql (1.32ms)12682026/10/01 07:31:59 goose: up to current file version: 312692026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.99ms)12702026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.83ms)12712026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.42ms)12722026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000012732026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.62ms)12742026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.68ms)12752026/10/01 07:31:59 OK 3_commit_push.sql (1.69ms)12762026/10/01 07:31:59 goose: up to current file version: 31277=== RUN TestPush_RejectsBadRequests/no_roots1278=== PAUSE TestPush_RejectsBadRequests/no_roots1279=== RUN TestPush_RejectsBadRequests/no_objects1280=== PAUSE TestPush_RejectsBadRequests/no_objects1281=== RUN TestPush_RejectsBadRequests/bad_root1282=== PAUSE TestPush_RejectsBadRequests/bad_root1283=== RUN TestPush_RejectsBadRequests/root_not_in_objects1284=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1285=== CONT TestReadRedirectNar12862026-10-01 07:31:59.626 UTC [502] ERROR: relation "goose_db_version" does not exist at character 3612872026-10-01 07:31:59.626 UTC [502] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12882026-10-01 07:31:59.636 UTC [505] ERROR: relation "goose_db_version" does not exist at character 3612892026-10-01 07:31:59.636 UTC [505] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12902026/10/01 07:31:59 OK 20241026095416_initial_model.sql (11.49ms)12912026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (7.71ms)12922026/10/01 07:31:59 OK 20241026095416_initial_model.sql (10.16ms)12932026/10/01 07:31:59 OK 20251218171726_add_pins.sql (3.52ms)12942026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)12952026/10/01 07:31:59 OK 20251218171726_add_pins.sql (3.44ms)12962026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)12972026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)12982026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.69ms)1299--- PASS: TestObjectStatsTrigger (0.60s)1300=== CONT TestReadProxyDisabled13012026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.02ms)13022026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.15ms)13032026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.65ms)13042026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000013052026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.28ms)1306--- PASS: TestService_Rustfstest (0.60s)1307=== CONT TestGracefulShutdownDrainsInflight13082026/10/01 07:31:59 INFO Starting HTTP server address=127.0.0.1:3879313092026/10/01 07:31:59 INFO Shutdown signal received, draining in-flight requests timeout=10s13102026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.42ms)13112026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.64ms)13122026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000013132026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.76ms)13142026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.64ms)13152026/10/01 07:31:59 OK 3_commit_push.sql (1.78ms)13162026/10/01 07:31:59 goose: up to current file version: 313172026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.03ms)13182026/10/01 07:31:59 OK 3_commit_push.sql (1.43ms)13192026/10/01 07:31:59 goose: up to current file version: 313202026/10/01 07:31:59 INFO Received uploads request method=POST path=/api/pending_closures13212026-10-01 07:31:59.692 UTC [508] ERROR: relation "goose_db_version" does not exist at character 3613222026-10-01 07:31:59.692 UTC [508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13232026/10/01 07:31:59 OK 20241026095416_initial_model.sql (10.27ms)13242026/10/01 07:31:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13252026/10/01 07:31:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1326--- PASS: TestService_NativeMTLS (0.64s)1327=== CONT TestReadProxyRootRedirectsToIndexHTML13282026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)13292026/10/01 07:31:59 OK 20251218171726_add_pins.sql (3.79ms)13302026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)13312026/10/01 07:31:59 OK 20260905000000_add_claims.sql (2.98ms)13322026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.61ms)13332026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.54ms)13342026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000013352026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.55ms)13362026/10/01 07:31:59 OK 2_object_stats_trigger.sql (914.53µs)13372026-10-01 07:31:59.732 UTC [511] ERROR: relation "goose_db_version" does not exist at character 3613382026-10-01 07:31:59.732 UTC [511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13392026/10/01 07:31:59 OK 3_commit_push.sql (1.44ms)13402026/10/01 07:31:59 goose: up to current file version: 313412026/10/01 07:31:59 INFO Received uploads request method=POST path=/api/pending_closures1342--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1343=== CONT TestGCTaskStore_Fail1344--- PASS: TestGCTaskStore_Fail (0.00s)1345=== CONT TestReadProxyConditionalGet13462026/10/01 07:31:59 OK 20241026095416_initial_model.sql (11.51ms)13472026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)13482026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.95ms)13492026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)13502026/10/01 07:31:59 OK 20260905000000_add_claims.sql (4.02ms)13512026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.25ms)13522026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.77ms)13532026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000013542026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.47ms)13552026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.73ms)13562026/10/01 07:31:59 OK 3_commit_push.sql (1.36ms)13572026/10/01 07:31:59 goose: up to current file version: 313582026/10/01 07:31:59 INFO Received push request method=POST path=/api/pushes13592026-10-01 07:31:59.791 UTC [515] ERROR: relation "goose_db_version" does not exist at character 3613602026-10-01 07:31:59.791 UTC [515] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13612026/10/01 07:31:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13622026/10/01 07:31:59 INFO Signed narinfos id=1 count=11363--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.72s)1364=== CONT TestGCTaskStore_PhaseUpdates1365--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1366=== CONT TestReadProxyHead1367=== NAME TestNARDeduplicationMetadataUploadBug1368 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4198449246/001/store/yj84wd223qn2gzz13w26siqva4d8iab8-file1.txt13692026/10/01 07:31:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13702026/10/01 07:31:59 OK 20241026095416_initial_model.sql (16.2ms)13712026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)13722026/10/01 07:31:59 OK 20251218171726_add_pins.sql (2.93ms)13732026-10-01 07:31:59.822 UTC [540] ERROR: relation "goose_db_version" does not exist at character 3613742026-10-01 07:31:59.822 UTC [540] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13752026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)13762026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.27ms)1377--- PASS: TestMetricsInventory (0.76s)1378=== CONT TestGCTaskStore_CompletedAllowsNewTask1379--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1380=== CONT TestService_createPendingClosureHandler1381=== NAME TestOrphanedObjectsGC1382 orphaned_objects_gc_test.go:290: GC Test Summary:1383 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1384 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1385 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1386 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1387 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1388--- PASS: TestOrphanedObjectsGC (0.76s)1389=== CONT TestGCTaskStore_GetReturnsLatest1390--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1391=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT13922026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.57ms)13932026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.61ms)13942026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000013952026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.13ms)13962026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.43ms)13972026/10/01 07:31:59 OK 3_commit_push.sql (1.31ms)13982026/10/01 07:31:59 goose: up to current file version: 313992026/10/01 07:31:59 OK 20241026095416_initial_model.sql (9.52ms)14002026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (1.21ms)14012026/10/01 07:31:59 OK 20251218171726_add_pins.sql (3.53ms)14022026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)14032026/10/01 07:31:59 INFO Received uploads request method=POST path=/api/pending_closures14042026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.54ms)14052026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.48ms)14062026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.53ms)14072026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000014082026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.87ms)14092026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.69ms)14102026/10/01 07:31:59 OK 3_commit_push.sql (1.59ms)14112026/10/01 07:31:59 goose: up to current file version: 31412--- PASS: TestResurrectedObjectNotDeleted (0.81s)1413=== CONT TestGCTaskStore_GetEmpty1414--- PASS: TestGCTaskStore_GetEmpty (0.00s)1415=== CONT TestCompleteMultipartUnregistered14162026/10/01 07:31:59 INFO Received uploads request method=POST path=/api/pending_closures14172026-10-01 07:31:59.883 UTC [564] ERROR: relation "goose_db_version" does not exist at character 3614182026-10-01 07:31:59.883 UTC [564] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14192026/10/01 07:31:59 INFO Received push request method=POST path=/api/pushes14202026/10/01 07:31:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14212026/10/01 07:31:59 INFO Uploading yj84wd223qn2gzz13w26siqva4d8iab8-file1.txt (160B)14222026/10/01 07:31:59 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14232026/10/01 07:31:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14242026/10/01 07:31:59 WARN Failed to register uploaded object key=yj84wd223qn2gzz13w26siqva4d8iab8.ls error="server returned 404: 404 page not found\n"14252026/10/01 07:31:59 INFO Signed narinfos id=1 count=114262026/10/01 07:31:59 INFO Uploading 1 narinfos14272026/10/01 07:31:59 OK 20241026095416_initial_model.sql (12.35ms)14282026/10/01 07:31:59 INFO Received complete push request method=POST path=/api/pushes/1/complete14292026/10/01 07:31:59 WARN Failed to register uploaded object key=yj84wd223qn2gzz13w26siqva4d8iab8.narinfo error="server returned 404: 404 page not found\n"14302026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)14312026-10-01 07:31:59.907 UTC [583] ERROR: relation "goose_db_version" does not exist at character 3614322026-10-01 07:31:59.907 UTC [583] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14332026/10/01 07:31:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14342026/10/01 07:31:59 WARN Refused reserved pin name=worker-x86_64-linux14352026/10/01 07:31:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14362026/10/01 07:31:59 INFO Received create pin request method=POST path=/api/pins/my-app14372026/10/01 07:31:59 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14382026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.03ms)14392026-10-01 07:31:59.909 UTC [584] ERROR: relation "goose_db_version" does not exist at character 3614402026-10-01 07:31:59.909 UTC [584] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1441--- PASS: TestCreatePin_ReservedPins (0.84s)1442=== CONT TestGCTaskStore_ConflictDifferentParams1443--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1444=== CONT TestService_verifyS3Integrity14452026/10/01 07:31:59 INFO Upload complete. (66ms)14462026/10/01 07:31:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1447=== NAME TestNARDeduplicationMetadataUploadBug14482026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)1449 metadata_upload_test.go:54: Retrieved narinfo from S3:1450 StorePath: /build/TestNARDeduplicationMetadataUploadBug4198449246/001/store/yj84wd223qn2gzz13w26siqva4d8iab8-file1.txt1451 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1452 Compression: zstd1453 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1454 NarSize: 1601455 References: 1456 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1457 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1458 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1459 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14602026/10/01 07:31:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWU5NDI5N2EtZDk3OC00ZTk4LWI2MWMtNDA4ODMzODgxZTZhLmUzOWRlY2E0LWM1MjctNGMxYi1iNWEwLTAwOGU4MWFiMmRiNXgxNzkwODM5OTE5ODg1NzM4MDg014612026/10/01 07:31:59 INFO Received push request method=POST path=/api/pushes14622026/10/01 07:31:59 OK 20260905000000_add_claims.sql (9.91ms)14632026/10/01 07:31:59 OK 20241026095416_initial_model.sql (11.63ms)14642026/10/01 07:31:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWU5NDI5N2EtZDk3OC00ZTk4LWI2MWMtNDA4ODMzODgxZTZhLmUzOWRlY2E0LWM1MjctNGMxYi1iNWEwLTAwOGU4MWFiMmRiNXgxNzkwODM5OTE5ODg1NzM4MDg0 parts=11465--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.86s)1466=== CONT TestGCTaskStore_DeduplicateSameParams1467--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1468=== CONT TestClientSharedPathCommittedMidPush14692026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (3.06ms)14702026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)14712026/10/01 07:31:59 OK 20241026095416_initial_model.sql (11.41ms)14722026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.84ms)14732026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000014742026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)14752026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.11ms)14762026/10/01 07:31:59 OK 1_commit_pending_closure.sql (3.08ms)14772026/10/01 07:31:59 OK 20251218171726_add_pins.sql (3.63ms)14782026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.65ms)14792026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (3.85ms)14802026/10/01 07:31:59 OK 3_commit_push.sql (1.74ms)14812026/10/01 07:31:59 goose: up to current file version: 314822026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)14832026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.56ms)14842026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.7ms)14852026/10/01 07:31:59 INFO Received complete push request method=POST path=/api/pushes/1/complete14862026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.68ms)14872026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.35ms)14882026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000014892026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.91ms)14902026/10/01 07:31:59 INFO Received push request method=POST path=/api/pushes14912026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.61ms)14922026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.79ms)14932026/10/01 07:31:59 goose: successfully migrated database to version: 2026092312000014942026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.98ms)14952026/10/01 07:31:59 OK 3_commit_push.sql (1.03ms)14962026/10/01 07:31:59 goose: up to current file version: 314972026/10/01 07:31:59 OK 1_commit_pending_closure.sql (1.81ms)14982026-10-01 07:31:59.951 UTC [594] ERROR: relation "goose_db_version" does not exist at character 3614992026-10-01 07:31:59.951 UTC [594] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1500--- PASS: TestPush_CompleteCommitsEveryRoot (0.55s)1501=== CONT TestPinProtectsFromGC15022026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.83ms)1503=== NAME TestNARDeduplicationMetadataUploadBug1504 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4198449246/001/store/97kprizknrnjdpyg2zpsqhs0xghh22va-file2.txt15052026/10/01 07:31:59 OK 3_commit_push.sql (1.58ms)15062026/10/01 07:31:59 goose: up to current file version: 315072026/10/01 07:31:59 INFO Received cleanup request method=DELETE path=/api/pending_closures15082026/10/01 07:31:59 INFO Received complete push request method=POST path=/api/pushes/1/complete15092026/10/01 07:31:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15102026/10/01 07:31:59 INFO Aborted multipart uploads count=115112026/10/01 07:31:59 INFO Received push request method=POST path=/api/pushes15122026/10/01 07:31:59 OK 20241026095416_initial_model.sql (12.45ms)15132026/10/01 07:31:59 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)1514--- PASS: TestMultipartCleanup (0.91s)1515=== CONT TestClientWithDependencies15162026/10/01 07:31:59 INFO Received push request method=POST path=/api/pushes15172026/10/01 07:31:59 OK 20251218171726_add_pins.sql (4.61ms)15182026/10/01 07:31:59 OK 20260628120000_add_object_size_and_stats.sql (4.27ms)15192026/10/01 07:31:59 OK 20260905000000_add_claims.sql (3.67ms)15202026-10-01 07:31:59.988 UTC [639] ERROR: relation "goose_db_version" does not exist at character 3615212026-10-01 07:31:59.988 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15222026/10/01 07:31:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NWU5NDI5N2EtZDk3OC00ZTk4LWI2MWMtNDA4ODMzODgxZTZhLjMxNTNhNmZhLTc0YWMtNDM2Yi04NDIxLTM3MjM4YmQ4N2UyM3gxNzkwODM5OTE5NTgxMjM2ODAx parts=1215232026/10/01 07:31:59 OK 20260920000000_drop_claims.sql (2.86ms)1524--- PASS: TestRedundantMultipartUpload (0.92s)1525=== CONT TestGCTaskStore_StartNew1526--- PASS: TestGCTaskStore_StartNew (0.00s)1527=== CONT TestClientMultipleUploads15282026/10/01 07:31:59 OK 20260923120000_add_pushes.sql (2.69ms)15292026/10/01 07:31:59 goose: successfully migrated database to version: 202609231200001530--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.56s)1531=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection15322026/10/01 07:31:59 OK 1_commit_pending_closure.sql (2.77ms)15332026/10/01 07:31:59 OK 2_object_stats_trigger.sql (1.68ms)15342026/10/01 07:31:59 OK 3_commit_push.sql (1.44ms)15352026/10/01 07:31:59 goose: up to current file version: 315362026/10/01 07:32:00 OK 20241026095416_initial_model.sql (12.19ms)1537--- PASS: TestReadRedirectUsesPublicS3URL (0.56s)1538=== CONT TestClientIntegration15392026-10-01 07:32:00.015 UTC [664] ERROR: relation "goose_db_version" does not exist at character 3615402026-10-01 07:32:00.015 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15412026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (8.98ms)15422026/10/01 07:32:00 OK 20251218171726_add_pins.sql (4.1ms)15432026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.64ms)15442026/10/01 07:32:00 OK 20260905000000_add_claims.sql (4.52ms)15452026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes15462026/10/01 07:32:00 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1547--- PASS: TestReadProxyRangeRequest (0.57s)1548=== CONT TestGCSweepDeliversEachKeyOnce15492026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (4.14ms)15502026/10/01 07:32:00 OK 20241026095416_initial_model.sql (13.87ms)15512026/10/01 07:32:00 INFO Aborted multipart uploads count=015522026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.79ms)15532026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000015542026/10/01 07:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15552026/10/01 07:32:00 WARN Failed to register uploaded object key=97kprizknrnjdpyg2zpsqhs0xghh22va.ls error="server returned 404: 404 page not found\n"15562026/10/01 07:32:00 INFO Signed narinfos id=2 count=115572026/10/01 07:32:00 INFO Uploading 1 narinfos15582026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)15592026-10-01 07:32:00.039 UTC [684] ERROR: relation "goose_db_version" does not exist at character 3615602026-10-01 07:32:00.039 UTC [684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15612026/10/01 07:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period15622026/10/01 07:32:00 OK 1_commit_pending_closure.sql (3.03ms)15632026/10/01 07:32:00 WARN Failed to register uploaded object key=97kprizknrnjdpyg2zpsqhs0xghh22va.narinfo error="server returned 404: 404 page not found\n"15642026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.94ms)15652026/10/01 07:32:00 INFO Received complete push request method=POST path=/api/pushes/2/complete15662026/10/01 07:32:00 OK 20251218171726_add_pins.sql (4.91ms)15672026/10/01 07:32:00 OK 3_commit_push.sql (2.68ms)15682026/10/01 07:32:00 goose: up to current file version: 315692026/10/01 07:32:00 INFO Upload complete. (53ms)1570=== NAME TestNARDeduplicationMetadataUploadBug1571 metadata_upload_test.go:76: Retrieved narinfo from S3:1572 StorePath: /build/TestNARDeduplicationMetadataUploadBug4198449246/001/store/97kprizknrnjdpyg2zpsqhs0xghh22va-file2.txt1573 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1574 Compression: zstd1575 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1576 NarSize: 1601577 References: 1578 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15792026/10/01 07:32:00 WARN readiness check failed error="closed pool"1580--- PASS: TestService_readinessHandler (0.57s)1581=== CONT TestClientErrorHandling1582=== RUN TestClientErrorHandling/InvalidStorePath1583=== PAUSE TestClientErrorHandling/InvalidStorePath1584=== RUN TestClientErrorHandling/InvalidAuthToken1585=== PAUSE TestClientErrorHandling/InvalidAuthToken1586=== RUN TestClientErrorHandling/ServerNotAvailable1587=== PAUSE TestClientErrorHandling/ServerNotAvailable1588=== CONT TestTombstonedObjectOfferedWithoutWaiting15892026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (5.28ms)1590=== NAME TestNARDeduplicationMetadataUploadBug1591 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1592 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1593 {"version":1,"root":{"type":"regular","size":44}}15942026/10/01 07:32:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=01595--- PASS: TestNARDeduplicationMetadataUploadBug (0.98s)1596=== CONT TestClientCADerivations15972026/10/01 07:32:00 OK 20260905000000_add_claims.sql (5.79ms)15982026/10/01 07:32:00 INFO Vacuumed table table=pending_closures15992026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.18ms)16002026/10/01 07:32:00 OK 20241026095416_initial_model.sql (13.01ms)16012026/10/01 07:32:00 INFO Vacuumed table table=pending_objects16022026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.52ms)16032026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000016042026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)16052026/10/01 07:32:00 INFO Vacuumed table table=multipart_uploads16062026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.44ms)16072026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.89ms)16082026-10-01 07:32:00.067 UTC [691] ERROR: relation "goose_db_version" does not exist at character 3616092026-10-01 07:32:00.067 UTC [691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1610--- PASS: TestService_healthCheckHandler (0.52s)1611=== CONT TestGCSweepSkipsPendingObjects16122026/10/01 07:32:00 OK 20251218171726_add_pins.sql (9.83ms)16132026/10/01 07:32:00 INFO Vacuumed table table=closures16142026/10/01 07:32:00 OK 3_commit_push.sql (8.54ms)16152026/10/01 07:32:00 goose: up to current file version: 316162026/10/01 07:32:00 INFO Vacuumed table table=objects16172026/10/01 07:32:00 INFO Received complete push request method=POST path=/api/pushes/2/complete16182026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)16192026/10/01 07:32:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16202026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.94ms)1621--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.69s)1622=== CONT TestCacheStatsHandler16232026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.58ms)16242026-10-01 07:32:00.085 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3616252026-10-01 07:32:00.085 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16262026/10/01 07:32:00 OK 20241026095416_initial_model.sql (10.39ms)16272026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (3.4ms)16282026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000016292026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)16302026-10-01 07:32:00.089 UTC [696] ERROR: relation "goose_db_version" does not exist at character 3616312026-10-01 07:32:00.089 UTC [696] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16322026/10/01 07:32:00 OK 1_commit_pending_closure.sql (3.22ms)16332026/10/01 07:32:00 OK 20251218171726_add_pins.sql (4.7ms)16342026/10/01 07:32:00 OK 2_object_stats_trigger.sql (2.53ms)16352026/10/01 07:32:00 OK 3_commit_push.sql (1.47ms)16362026/10/01 07:32:00 goose: up to current file version: 316372026/10/01 07:32:00 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NWU5NDI5N2EtZDk3OC00ZTk4LWI2MWMtNDA4ODMzODgxZTZhLjkyMDExM2YzLTVjZjMtNDMxNy1hOWE1LWIwOTFmNDcwYTAzMHgxNzkwODM5OTE5Njk4NjI5ODUz parts=1216382026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures16392026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)1640--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.03s)1641=== CONT TestDeduplicatedObjectsRecordedAsPending16422026/10/01 07:32:00 OK 20241026095416_initial_model.sql (11.38ms)16432026-10-01 07:32:00.102 UTC [698] ERROR: relation "goose_db_version" does not exist at character 3616442026-10-01 07:32:00.102 UTC [698] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16452026/10/01 07:32:00 OK 20260905000000_add_claims.sql (5.37ms)16462026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)16472026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.02ms)16482026/10/01 07:32:00 OK 20241026095416_initial_model.sql (12.43ms)16492026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.93ms)16502026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.73ms)16512026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000016522026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.68ms)16532026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)16542026-10-01 07:32:00.120 UTC [701] ERROR: relation "goose_db_version" does not exist at character 3616552026-10-01 07:32:00.120 UTC [701] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1656--- PASS: TestReadRedirectKeepsNarinfoProxied (0.57s)1657=== CONT TestCacheConfigHandler16582026/10/01 07:32:00 OK 2_object_stats_trigger.sql (8.92ms)1659=== RUN TestCacheConfigHandler/full_config,_no_issuer1660=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1661=== RUN TestCacheConfigHandler/no_cache_url_configured1662=== PAUSE TestCacheConfigHandler/no_cache_url_configured1663=== RUN TestCacheConfigHandler/no_signing_keys1664=== PAUSE TestCacheConfigHandler/no_signing_keys1665=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1666=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1667=== CONT TestPushDedupSurvivesConcurrentGC16682026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (9.78ms)16692026/10/01 07:32:00 OK 20260905000000_add_claims.sql (9.34ms)16702026/10/01 07:32:00 OK 20241026095416_initial_model.sql (14.14ms)16712026/10/01 07:32:00 OK 3_commit_push.sql (2.57ms)16722026/10/01 07:32:00 goose: up to current file version: 316732026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)16742026/10/01 07:32:00 OK 20251218171726_add_pins.sql (4.31ms)16752026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.83ms)16762026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.62ms)1677--- PASS: TestReadRedirectNar (0.51s)1678=== CONT TestService_ReadScope_PublicByDefault16792026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (3.42ms)16802026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000016812026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)16822026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.44ms)16832026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.65ms)16842026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.85ms)16852026/10/01 07:32:00 OK 20260905000000_add_claims.sql (4.53ms)16862026/10/01 07:32:00 OK 3_commit_push.sql (1.47ms)16872026/10/01 07:32:00 goose: up to current file version: 316882026-10-01 07:32:00.137 UTC [704] ERROR: relation "goose_db_version" does not exist at character 3616892026-10-01 07:32:00.137 UTC [704] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16902026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.91ms)16912026/10/01 07:32:00 OK 20260905000000_add_claims.sql (4.78ms)16922026/10/01 07:32:00 OK 20241026095416_initial_model.sql (12.18ms)16932026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.64ms)16942026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000016952026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)16962026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.49ms)16972026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.18ms)16982026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.78ms)16992026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000017002026/10/01 07:32:00 OK 2_object_stats_trigger.sql (2.33ms)17012026/10/01 07:32:00 OK 20251218171726_add_pins.sql (4.46ms)17022026-10-01 07:32:00.147 UTC [707] ERROR: relation "goose_db_version" does not exist at character 3617032026-10-01 07:32:00.147 UTC [707] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1704--- PASS: TestReadProxyDisabled (0.48s)1705=== CONT TestGCMetrics17062026/10/01 07:32:00 OK 3_commit_push.sql (1.72ms)17072026/10/01 07:32:00 goose: up to current file version: 317082026/10/01 07:32:00 OK 1_commit_pending_closure.sql (3.36ms)17092026/10/01 07:32:00 OK 2_object_stats_trigger.sql (2.03ms)17102026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (5.63ms)17112026/10/01 07:32:00 OK 3_commit_push.sql (1.58ms)17122026/10/01 07:32:00 goose: up to current file version: 317132026/10/01 07:32:00 OK 20241026095416_initial_model.sql (12.09ms)17142026/10/01 07:32:00 OK 20260905000000_add_claims.sql (4.37ms)17152026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)17162026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.06ms)17172026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.89ms)17182026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000017192026/10/01 07:32:00 OK 20251218171726_add_pins.sql (5.18ms)17202026-10-01 07:32:00.164 UTC [710] ERROR: relation "goose_db_version" does not exist at character 3617212026-10-01 07:32:00.164 UTC [710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17222026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.61ms)17232026/10/01 07:32:00 OK 20241026095416_initial_model.sql (13.11ms)17242026-10-01 07:32:00.169 UTC [711] ERROR: relation "goose_db_version" does not exist at character 3617252026-10-01 07:32:00.169 UTC [711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17262026/10/01 07:32:00 OK 2_object_stats_trigger.sql (9.12ms)17272026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (12.49ms)17282026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (9.09ms)17292026/10/01 07:32:00 OK 3_commit_push.sql (2.32ms)17302026/10/01 07:32:00 goose: up to current file version: 31731--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.47s)1732=== CONT TestService_RequireScope_OIDC17332026/10/01 07:32:00 OK 20260905000000_add_claims.sql (4.08ms)17342026/10/01 07:32:00 OK 20251218171726_add_pins.sql (4.83ms)17352026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.26ms)17362026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.83ms)17372026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (3.21ms)17382026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000017392026-10-01 07:32:00.190 UTC [712] ERROR: relation "goose_db_version" does not exist at character 3617402026-10-01 07:32:00.190 UTC [712] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17412026/10/01 07:32:00 OK 20241026095416_initial_model.sql (12.48ms)17422026/10/01 07:32:00 OK 1_commit_pending_closure.sql (3.73ms)17432026/10/01 07:32:00 OK 20260905000000_add_claims.sql (4.64ms)17442026/10/01 07:32:00 OK 20241026095416_initial_model.sql (14.64ms)17452026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.47ms)17462026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)17472026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)17482026/10/01 07:32:00 OK 3_commit_push.sql (1.73ms)17492026/10/01 07:32:00 goose: up to current file version: 317502026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.62ms)17512026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.93ms)17522026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.56ms)17532026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000017542026/10/01 07:32:00 OK 20251218171726_add_pins.sql (4.45ms)17552026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.93ms)17562026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)17572026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.56ms)17582026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)17592026/10/01 07:32:00 OK 3_commit_push.sql (1.35ms)17602026/10/01 07:32:00 goose: up to current file version: 317612026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.84ms)17622026-10-01 07:32:00.205 UTC [713] ERROR: relation "goose_db_version" does not exist at character 3617632026-10-01 07:32:00.205 UTC [713] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1764--- PASS: TestReadProxyConditionalGet (0.47s)1765=== CONT TestGCBugBareHashReferences17662026/10/01 07:32:00 OK 20241026095416_initial_model.sql (11.11ms)17672026/10/01 07:32:00 OK 20260905000000_add_claims.sql (4.94ms)17682026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.68ms)17692026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)17702026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.71ms)17712026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (3.3ms)17722026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000017732026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.13ms)17742026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000017752026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.86ms)17762026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.68ms)17772026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.2ms)17782026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.22ms)17792026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.09ms)17802026/10/01 07:32:00 OK 3_commit_push.sql (730.19µs)17812026/10/01 07:32:00 goose: up to current file version: 317822026/10/01 07:32:00 OK 3_commit_push.sql (1.07ms)17832026/10/01 07:32:00 goose: up to current file version: 317842026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.36ms)17852026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.87ms)17862026/10/01 07:32:00 OK 20241026095416_initial_model.sql (11.45ms)17872026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.35ms)17882026-10-01 07:32:00.226 UTC [716] ERROR: relation "goose_db_version" does not exist at character 3617892026-10-01 07:32:00.226 UTC [716] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17902026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)1791--- PASS: TestReadProxyHead (0.43s)1792=== CONT TestService_AuthMiddleware_OIDC17932026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.93ms)17942026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000017952026-10-01 07:32:00.228 UTC [717] ERROR: relation "goose_db_version" does not exist at character 3617962026-10-01 07:32:00.228 UTC [717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17972026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.21ms)17982026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.4ms)17992026/10/01 07:32:00 OK 2_object_stats_trigger.sql (2.2ms)18002026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (5.19ms)18012026/10/01 07:32:00 OK 3_commit_push.sql (1.69ms)18022026/10/01 07:32:00 goose: up to current file version: 318032026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.8ms)18042026/10/01 07:32:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34115/oidc18052026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.93ms)18062026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures18072026/10/01 07:32:00 OK 20241026095416_initial_model.sql (10.31ms)18082026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.88ms)18092026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000018102026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)18112026/10/01 07:32:00 OK 20241026095416_initial_model.sql (10.54ms)18122026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.27ms)18132026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.44ms)18142026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)18152026/10/01 07:32:00 OK 20251218171726_add_pins.sql (4.07ms)18162026/10/01 07:32:00 OK 3_commit_push.sql (1.89ms)18172026/10/01 07:32:00 goose: up to current file version: 318182026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.65ms)18192026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)1820--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.43s)1821=== CONT TestLeadEndsOnShutdown18222026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)18232026/10/01 07:32:00 OK 20260905000000_add_claims.sql (4.42ms)18242026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.78ms)18252026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.64ms)18262026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.5ms)18272026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.52ms)18282026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000018292026/10/01 07:32:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33113/oidc18302026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.58ms)18312026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000018322026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.71ms)18332026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.12ms)18342026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.48ms)18352026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures18362026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures18372026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures18382026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.78ms)18392026/10/01 07:32:00 OK 3_commit_push.sql (1.33ms)18402026/10/01 07:32:00 goose: up to current file version: 318412026/10/01 07:32:00 OK 3_commit_push.sql (1.17ms)18422026/10/01 07:32:00 goose: up to current file version: 318432026/10/01 07:32:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18442026-10-01 07:32:00.292 UTC [724] ERROR: relation "goose_db_version" does not exist at character 3618452026-10-01 07:32:00.292 UTC [724] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18462026/10/01 07:32:00 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1847--- PASS: TestCompleteMultipartUnregistered (0.42s)1848=== CONT TestService_ReadAuthMiddleware18492026/10/01 07:32:00 OK 20241026095416_initial_model.sql (13.28ms)18502026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)18512026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures18522026-10-01 07:32:00.318 UTC [727] ERROR: relation "goose_db_version" does not exist at character 3618532026-10-01 07:32:00.318 UTC [727] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18542026/10/01 07:32:00 OK 20251218171726_add_pins.sql (5.42ms)18552026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)18562026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.51ms)18572026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.12ms)18582026/10/01 07:32:00 OK 20241026095416_initial_model.sql (10.03ms)18592026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (3.31ms)18602026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000018612026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)18622026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.15ms)18632026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.53ms)18642026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.6ms)18652026/10/01 07:32:00 OK 3_commit_push.sql (1.55ms)18662026/10/01 07:32:00 goose: up to current file version: 318672026-10-01 07:32:00.341 UTC [728] ERROR: relation "goose_db_version" does not exist at character 3618682026-10-01 07:32:00.341 UTC [728] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18692026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)18702026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.55ms)18712026-10-01 07:32:00.347 UTC [729] ERROR: relation "goose_db_version" does not exist at character 3618722026-10-01 07:32:00.347 UTC [729] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18732026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.69ms)18742026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.42ms)18752026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000018762026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.43ms)18772026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.18ms)18782026/10/01 07:32:00 OK 3_commit_push.sql (6.49ms)18792026/10/01 07:32:00 goose: up to current file version: 318802026/10/01 07:32:00 OK 20241026095416_initial_model.sql (14.96ms)18812026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)18822026/10/01 07:32:00 OK 20241026095416_initial_model.sql (13.6ms)18832026-10-01 07:32:00.367 UTC [731] ERROR: relation "goose_db_version" does not exist at character 3618842026-10-01 07:32:00.367 UTC [731] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18852026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.46ms)18862026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)18872026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.64ms)18882026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.07ms)18892026/10/01 07:32:00 OK 20260905000000_add_claims.sql (4.47ms)18902026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.95ms)18912026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.91ms)18922026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.98ms)18932026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.76ms)18942026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000018952026/10/01 07:32:00 OK 20241026095416_initial_model.sql (10.15ms)18962026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.68ms)18972026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)18982026/10/01 07:32:00 OK 1_commit_pending_closure.sql (1.95ms)18992026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (1.96ms)19002026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000019012026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.11ms)19022026/10/01 07:32:00 OK 3_commit_push.sql (782.29µs)19032026/10/01 07:32:00 goose: up to current file version: 319042026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.17ms)19052026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.14ms)19062026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.31ms)19072026/10/01 07:32:00 OK 3_commit_push.sql (674.81µs)19082026/10/01 07:32:00 goose: up to current file version: 319092026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)19102026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.49ms)19112026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.31ms)19122026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (1.9ms)19132026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000019142026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.28ms)19152026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.05ms)19162026/10/01 07:32:00 OK 3_commit_push.sql (920.03µs)19172026/10/01 07:32:00 goose: up to current file version: 319182026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures1919=== NAME TestPinProtectsFromGC1920 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4118302586/001/store/13yj62ladk5ih99xnxs7699xmrrx0aih-pinned-file.txt1921 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4118302586/001/store/j7i13cszp1xf2a15qay6160hv2z3klia-unpinned-file.txt1922=== NAME TestClientMultipleUploads1923 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3167794124/001/store/lyj79xlxwcsap2d6f0ikb3x0zhgz2mwc-test-file-0.txt1924=== NAME TestClientWithDependencies1925 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3438556382/001/store/7w0jgj8qs7xscpnv6hrxg4asfm3bwbjy-test-script1926=== NAME TestClientIntegration1927 client_integration_test.go:286: Created store path: /build/TestClientIntegration821489730/002/store/ghbaqq999d68rypf2gcn0m6dnbwif9lp-test-file.txt19282026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes1929=== NAME TestClientWithDependencies1930 client_integration_test.go:615: Found 1 dependencies (including self)19312026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures19322026/10/01 07:32:00 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19332026/10/01 07:32:00 INFO Uploading a5pqqfsh83x3acic71d9z3h9i1bdjdwi-shared-dep (136B)19342026/10/01 07:32:00 INFO Uploading aa2lsgha4kpjyyh7mdqm88qf3pjc7lys-top (224B)19352026/10/01 07:32:00 INFO Aborted multipart uploads count=01936=== NAME TestClientMultipleUploads1937 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3167794124/001/store/ilc8vm853v36zcrf9a1061y45ydcm1nq-test-file-1.txt19382026/10/01 07:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period1939--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.47s)1940=== CONT TestLeadElectsOneAndHandsOver19412026/10/01 07:32:00 WARN Failed to register uploaded object key=nar/1mvkq58adlazsr7svg03ib8zhvb80pr7sajj217036kl1rvdp0wj.nar.zst error="server returned 404: 404 page not found\n"19422026/10/01 07:32:00 WARN Failed to register uploaded object key=aa2lsgha4kpjyyh7mdqm88qf3pjc7lys.ls error="server returned 404: 404 page not found\n"19432026/10/01 07:32:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19442026/10/01 07:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19452026/10/01 07:32:00 WARN Failed to register uploaded object key=a5pqqfsh83x3acic71d9z3h9i1bdjdwi.ls error="server returned 404: 404 page not found\n"19462026/10/01 07:32:00 INFO Signed narinfos id=1 count=219472026/10/01 07:32:00 INFO Uploading 2 narinfos19482026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes19492026/10/01 07:32:00 WARN Failed to register uploaded object key=a5pqqfsh83x3acic71d9z3h9i1bdjdwi.narinfo error="server returned 404: 404 page not found\n"19502026/10/01 07:32:00 WARN Failed to register uploaded object key=aa2lsgha4kpjyyh7mdqm88qf3pjc7lys.narinfo error="server returned 404: 404 page not found\n"19512026/10/01 07:32:00 INFO Received complete push request method=POST path=/api/pushes/1/complete19522026/10/01 07:32:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19532026/10/01 07:32:00 INFO Uploading 13yj62ladk5ih99xnxs7699xmrrx0aih-pinned-file.txt (128B)19542026/10/01 07:32:00 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"19552026/10/01 07:32:00 INFO Upload complete. (72ms)19562026/10/01 07:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19572026/10/01 07:32:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=019582026/10/01 07:32:00 WARN Failed to register uploaded object key=13yj62ladk5ih99xnxs7699xmrrx0aih.ls error="server returned 404: 404 page not found\n"19592026/10/01 07:32:00 INFO Signed narinfos id=1 count=119602026/10/01 07:32:00 INFO Uploading 1 narinfos1961=== NAME TestClientSharedPathCommittedMidPush1962 client_integration_test.go:680: Retrieved narinfo from S3:1963 StorePath: /build/TestClientSharedPathCommittedMidPush3242132456/001/store/a5pqqfsh83x3acic71d9z3h9i1bdjdwi-shared-dep1964 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1965 Compression: zstd1966 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821967 NarSize: 1361968 References: 1969 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19702026/10/01 07:32:00 INFO Vacuumed table table=pending_closures19712026/10/01 07:32:00 INFO Vacuumed table table=pending_objects19722026/10/01 07:32:00 INFO Vacuumed table table=multipart_uploads19732026/10/01 07:32:00 INFO Vacuumed table table=closures1974 client_integration_test.go:680: Retrieved narinfo from S3:1975 StorePath: /build/TestClientSharedPathCommittedMidPush3242132456/001/store/aa2lsgha4kpjyyh7mdqm88qf3pjc7lys-top1976 URL: nar/1mvkq58adlazsr7svg03ib8zhvb80pr7sajj217036kl1rvdp0wj.nar.zst1977 Compression: zstd1978 NarHash: sha256:1mvkq58adlazsr7svg03ib8zhvb80pr7sajj217036kl1rvdp0wj1979 NarSize: 2241980 References: /build/TestClientSharedPathCommittedMidPush3242132456/001/store/a5pqqfsh83x3acic71d9z3h9i1bdjdwi-shared-dep1981 CA: text:sha256:0wvl4xcsgg44yfjli98p1y2d3zcil1q1r8h53qsx7qq7a033j6xb19822026/10/01 07:32:00 INFO Received complete push request method=POST path=/api/pushes/1/complete19832026/10/01 07:32:00 WARN Failed to register uploaded object key=13yj62ladk5ih99xnxs7699xmrrx0aih.narinfo error="server returned 404: 404 page not found\n"19842026/10/01 07:32:00 INFO Vacuumed table table=objects1985--- PASS: TestGCSweepDeliversEachKeyOnce (0.50s)1986=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1987--- PASS: TestClientSharedPathCommittedMidPush (0.61s)1988=== CONT TestResolveDBConnectionString1989=== RUN TestResolveDBConnectionString/flag_wins1990=== PAUSE TestResolveDBConnectionString/flag_wins1991=== RUN TestResolveDBConnectionString/file_when_flag_empty1992=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1993=== RUN TestResolveDBConnectionString/missing_file_is_an_error1994=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1995=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1996=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1997=== RUN TestResolveDBConnectionString/nothing_configured1998=== PAUSE TestResolveDBConnectionString/nothing_configured1999=== CONT TestService_AuthMiddleware_MTLSProxyHeader20002026/10/01 07:32:00 INFO Upload complete. (62ms)2001=== NAME TestClientMultipleUploads2002 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3167794124/001/store/va5sl6im6257vmvvv1g8vq5ksjwh6m16-test-file-2.txt20032026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures20042026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes20052026/10/01 07:32:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20062026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes20072026/10/01 07:32:00 INFO Uploading ghbaqq999d68rypf2gcn0m6dnbwif9lp-test-file.txt (152B)20082026/10/01 07:32:00 INFO Aborted multipart uploads count=020092026/10/01 07:32:00 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"20102026/10/01 07:32:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20112026/10/01 07:32:00 INFO Uploading 7w0jgj8qs7xscpnv6hrxg4asfm3bwbjy-test-script (136B)20122026/10/01 07:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20132026/10/01 07:32:00 WARN Failed to register uploaded object key=ghbaqq999d68rypf2gcn0m6dnbwif9lp.ls error="server returned 404: 404 page not found\n"20142026/10/01 07:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period20152026/10/01 07:32:00 INFO Signed narinfos id=1 count=120162026/10/01 07:32:00 INFO Uploading 1 narinfos20172026/10/01 07:32:00 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"20182026/10/01 07:32:00 WARN Failed to register uploaded object key=7w0jgj8qs7xscpnv6hrxg4asfm3bwbjy.ls error="server returned 404: 404 page not found\n"20192026/10/01 07:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20202026/10/01 07:32:00 WARN Failed to register uploaded object key=log/32sc0qn8ildyx48g7vr3nps4qwg8y7j6-test-script.drv error="server returned 404: 404 page not found\n"20212026/10/01 07:32:00 INFO Signed narinfos id=1 count=120222026/10/01 07:32:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020232026/10/01 07:32:00 INFO Uploading 1 narinfos20242026/10/01 07:32:00 INFO Received complete push request method=POST path=/api/pushes/1/complete20252026/10/01 07:32:00 WARN Failed to register uploaded object key=ghbaqq999d68rypf2gcn0m6dnbwif9lp.narinfo error="server returned 404: 404 page not found\n"20262026/10/01 07:32:00 INFO Received complete push request method=POST path=/api/pushes/1/complete20272026/10/01 07:32:00 WARN Failed to register uploaded object key=7w0jgj8qs7xscpnv6hrxg4asfm3bwbjy.narinfo error="server returned 404: 404 page not found\n"20282026/10/01 07:32:00 INFO Vacuumed table table=pending_closures2029--- PASS: TestCacheStatsHandler (0.51s)2030=== CONT TestClientFallsBackToClosures20312026/10/01 07:32:00 INFO Vacuumed table table=pending_objects20322026/10/01 07:32:00 INFO Vacuumed table table=multipart_uploads20332026/10/01 07:32:00 INFO Vacuumed table table=closures20342026/10/01 07:32:00 INFO Upload complete. (64ms)20352026/10/01 07:32:00 INFO Vacuumed table table=objects20362026/10/01 07:32:00 INFO Upload complete. (60ms)2037=== NAME TestClientWithDependencies2038 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3438556382/001/store) requires matching store prefix20392026-10-01 07:32:00.605 UTC [1130] ERROR: relation "goose_db_version" does not exist at character 3620402026-10-01 07:32:00.605 UTC [1130] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2041--- PASS: TestGCSweepSkipsPendingObjects (0.53s)2042=== CONT TestUploadHandlersRejectOversizedBody2043--- PASS: TestClientWithDependencies (0.63s)2044=== CONT TestService_cleanupPendingClosuresHandler20452026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures20462026/10/01 07:32:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2047--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.62s)2048=== CONT TestClientPushesUseOnePush2049--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.52s)2050=== CONT TestUploadHandlersRejectInvalidKeys2051=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2052=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2053=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2054=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20552026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes2056=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2057=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2058=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2059=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2060=== CONT TestProxyWriteTimeout/narinfo2061=== CONT TestProxyWriteTimeout/1_GiB_nar2062=== CONT TestProxyWriteTimeout/unknown_size2063=== CONT TestProxyWriteTimeout/10_GiB_nar2064--- PASS: TestProxyWriteTimeout (0.00s)2065 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2066 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2067 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2068 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2069=== CONT TestServerTLSConfig/no_client_CA2070=== CONT TestServerTLSConfig/not_a_PEM_file2071=== CONT TestServerTLSConfig/missing_CA_file2072=== CONT TestIsValidUploadKey/narinfo2073--- PASS: TestServerTLSConfig (0.00s)2074 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2075 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2076 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2077=== CONT TestIsValidUploadKey/unknown_type2078=== CONT TestIsValidUploadKey/empty_key2079=== CONT TestIsValidUploadKey/absolute2080=== CONT TestIsValidUploadKey/traversal_nar2081=== CONT TestIsValidUploadKey/traversal2082=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2083=== CONT TestIsValidUploadKey/build_log_question_mark2084=== CONT TestIsValidUploadKey/build_log_plus_in_name2085=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2086=== CONT TestIsValidUploadKey/nar_plain2087=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2088=== CONT TestIsValidUploadKey/nar_xz2089=== CONT TestIsValidUploadKey/index.html2090=== CONT TestIsValidUploadKey/nar_zst2091=== CONT TestIsValidUploadKey/nix-cache-info2092=== CONT TestIsValidUploadKey/realisation_plus_in_output2093=== CONT TestIsValidUploadKey/realisation2094=== CONT TestIsValidUploadKey/build_log_equals2095=== CONT TestIsValidUploadKey/build_log_home-manager_file2096=== CONT TestIsValidUploadKey/build_log2097=== CONT TestParseSingleRange/none2098=== CONT TestParseSingleRange/end_clamped_to_size2099=== CONT TestParseSingleRange/malformed_both_empty2100=== CONT TestParseSingleRange/open-ended2101=== CONT TestParseSingleRange/closed2102=== CONT TestParseSingleRange/malformed_end_before_start2103=== CONT TestParseSingleRange/single_byte2104=== CONT TestParseSingleRange/start_far_past_EOF2105=== CONT TestParseSingleRange/start_past_EOF2106=== CONT TestParseSingleRange/multi-range_ignored2107=== CONT TestParseSingleRange/malformed_no_dash2108=== CONT TestParseSingleRange/unknown_unit2109=== CONT TestParseSingleRange/suffix_exceeds_size2110=== CONT TestParseSingleRange/suffix2111--- PASS: TestParseSingleRange (0.01s)2112 --- PASS: TestParseSingleRange/none (0.00s)2113 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2114 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2115 --- PASS: TestParseSingleRange/open-ended (0.00s)2116 --- PASS: TestParseSingleRange/closed (0.00s)2117 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2118 --- PASS: TestParseSingleRange/single_byte (0.00s)2119 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2120 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2121 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2122 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2123 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2124 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2125 --- PASS: TestParseSingleRange/suffix (0.00s)2126=== CONT TestIsValidUploadKey/listing2127--- PASS: TestIsValidUploadKey (0.01s)2128 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2129 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2130 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2131 --- PASS: TestIsValidUploadKey/absolute (0.00s)2132 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2133 --- PASS: TestIsValidUploadKey/traversal (0.00s)2134 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2135 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2136 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2137 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2138 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2139 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2140 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2141 --- PASS: TestIsValidUploadKey/index.html (0.00s)2142 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2143 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2144 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2145 --- PASS: TestIsValidUploadKey/realisation (0.00s)2146 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2147 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2148 --- PASS: TestIsValidUploadKey/build_log (0.00s)2149 --- PASS: TestIsValidUploadKey/listing (0.00s)2150=== CONT TestIsValidCachePath/narinfo2151=== CONT TestIsValidCachePath/index.html2152=== CONT TestIsValidCachePath/short_hash2153=== CONT TestIsValidCachePath/wrong_extension2154=== CONT TestIsValidCachePath/leading_slash2155=== CONT TestIsValidCachePath/invalid_char_e2156=== CONT TestIsValidCachePath/traversal_in_middle2157=== CONT TestIsValidCachePath/traversal_parent2158=== CONT TestIsValidCachePath/nar_uncompressed2159=== CONT TestIsValidCachePath/nix-cache-info2160=== CONT TestIsValidCachePath/realisation2161=== CONT TestIsValidCachePath/log2162=== CONT TestIsValidCachePath/ls2163=== CONT TestIsValidCachePath/nar_xz2164=== CONT TestIsValidCachePath/nar_bz22165=== CONT TestIsValidCachePath/nar_zst2166=== CONT TestIsValidCachePath/empty2167=== CONT TestIsValidCachePath/random_path2168=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2169=== CONT TestIsValidCachePath/invalid_char_u2170--- PASS: TestIsValidCachePath (0.01s)2171 --- PASS: TestIsValidCachePath/narinfo (0.00s)2172 --- PASS: TestIsValidCachePath/index.html (0.00s)2173 --- PASS: TestIsValidCachePath/short_hash (0.00s)2174 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2175 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2176 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2177 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2178 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2179 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2180 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2181 --- PASS: TestIsValidCachePath/realisation (0.00s)2182 --- PASS: TestIsValidCachePath/log (0.00s)2183 --- PASS: TestIsValidCachePath/ls (0.00s)2184 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2185 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2186 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2187 --- PASS: TestIsValidCachePath/empty (0.00s)2188 --- PASS: TestIsValidCachePath/random_path (0.00s)2189 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2190 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2191=== CONT TestPush_RejectsBadRequests/no_roots21922026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes2193=== CONT TestPush_RejectsBadRequests/bad_root21942026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes2195=== CONT TestPush_RejectsBadRequests/root_not_in_objects21962026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes2197=== CONT TestPush_RejectsBadRequests/no_objects21982026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes2199--- PASS: TestPush_RejectsBadRequests (0.55s)2200 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2201 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2202 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2203 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2204=== CONT TestClientErrorHandling/InvalidStorePath22052026/10/01 07:32:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22062026/10/01 07:32:00 INFO Uploading j7i13cszp1xf2a15qay6160hv2z3klia-unpinned-file.txt (128B)2207=== NAME TestClientCADerivations2208 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3202428597/001/store/j5d9nnzg8j4chwildbl2672m9jhzd5q0-ca-test22092026/10/01 07:32:00 OK 20241026095416_initial_model.sql (11.65ms)22102026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)22112026/10/01 07:32:00 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"22122026/10/01 07:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign22132026/10/01 07:32:00 WARN Failed to register uploaded object key=j7i13cszp1xf2a15qay6160hv2z3klia.ls error="server returned 404: 404 page not found\n"22142026/10/01 07:32:00 INFO Signed narinfos id=2 count=122152026/10/01 07:32:00 INFO Uploading 1 narinfos22162026-10-01 07:32:00.630 UTC [1174] ERROR: relation "goose_db_version" does not exist at character 3622172026-10-01 07:32:00.630 UTC [1174] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22182026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes22192026/10/01 07:32:00 OK 20251218171726_add_pins.sql (4.42ms)22202026/10/01 07:32:00 INFO Received complete push request method=POST path=/api/pushes/2/complete22212026/10/01 07:32:00 WARN Failed to register uploaded object key=j7i13cszp1xf2a15qay6160hv2z3klia.narinfo error="server returned 404: 404 page not found\n"22222026/10/01 07:32:00 INFO All 1 paths already cached22232026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (9.96ms)22242026/10/01 07:32:00 INFO Upload complete. (60ms)2225=== NAME TestClientIntegration2226 client_integration_test.go:312: Retrieved narinfo from S3:2227 StorePath: /build/TestClientIntegration821489730/002/store/ghbaqq999d68rypf2gcn0m6dnbwif9lp-test-file.txt2228 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2229 Compression: zstd2230 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12231 NarSize: 1522232 References: 2233 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk122342026/10/01 07:32:00 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)22352026/10/01 07:32:00 INFO Uploading va5sl6im6257vmvvv1g8vq5ksjwh6m16-test-file-2.txt (160B)22362026/10/01 07:32:00 INFO Uploading ilc8vm853v36zcrf9a1061y45ydcm1nq-test-file-1.txt (160B)22372026/10/01 07:32:00 INFO Uploading lyj79xlxwcsap2d6f0ikb3x0zhgz2mwc-test-file-0.txt (160B)22382026/10/01 07:32:00 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NWU5NDI5N2EtZDk3OC00ZTk4LWI2MWMtNDA4ODMzODgxZTZhLmNiNTc4OTJmLWZmNDctNDZjZC1hNzdhLTQ4MDUwNzBmODZlOHgxNzkwODM5OTIwMjgyODk5OTA2 parts=1022392026/10/01 07:32:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2240 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2241 client_integration_test.go:313: Decompressed .ls content (64 bytes):2242 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2243 client_integration_test.go:316: Testing garbage collection...22442026/10/01 07:32:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22452026-10-01 07:32:00.647 UTC [1210] ERROR: relation "goose_db_version" does not exist at character 3622462026-10-01 07:32:00.647 UTC [1210] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22472026/10/01 07:32:00 OK 20260905000000_add_claims.sql (7.35ms)22482026/10/01 07:32:00 WARN Failed to register uploaded object key=va5sl6im6257vmvvv1g8vq5ksjwh6m16.ls error="server returned 404: 404 page not found\n"22492026/10/01 07:32:00 WARN Failed to register uploaded object key=lyj79xlxwcsap2d6f0ikb3x0zhgz2mwc.ls error="server returned 404: 404 page not found\n"22502026/10/01 07:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22512026/10/01 07:32:00 WARN Failed to register uploaded object key=ilc8vm853v36zcrf9a1061y45ydcm1nq.ls error="server returned 404: 404 page not found\n"22522026/10/01 07:32:00 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"22532026/10/01 07:32:00 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"22542026/10/01 07:32:00 INFO Completed upload id=122552026/10/01 07:32:00 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"22562026/10/01 07:32:00 INFO Signed narinfos id=1 count=322572026/10/01 07:32:00 INFO Uploading 3 narinfos22582026/10/01 07:32:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000022592026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures22602026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.7ms)22612026/10/01 07:32:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures22622026/10/01 07:32:00 WARN Failed to register uploaded object key=ilc8vm853v36zcrf9a1061y45ydcm1nq.narinfo error="server returned 404: 404 page not found\n"22632026/10/01 07:32:00 WARN Failed to register uploaded object key=va5sl6im6257vmvvv1g8vq5ksjwh6m16.narinfo error="server returned 404: 404 page not found\n"22642026/10/01 07:32:00 WARN Failed to register uploaded object key=lyj79xlxwcsap2d6f0ikb3x0zhgz2mwc.narinfo error="server returned 404: 404 page not found\n"22652026/10/01 07:32:00 INFO Received complete push request method=POST path=/api/pushes/1/complete22662026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (3.07ms)22672026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000022682026/10/01 07:32:00 OK 20241026095416_initial_model.sql (13.45ms)22692026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)22702026/10/01 07:32:00 OK 1_commit_pending_closure.sql (3.08ms)22712026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures22722026/10/01 07:32:00 OK 2_object_stats_trigger.sql (2.05ms)2273=== NAME TestClientCADerivations2274 client_ca_test.go:139: Found 1 dependencies (including self)2275--- PASS: TestService_ReadScope_PublicByDefault (0.53s)2276=== CONT TestClientErrorHandling/InvalidAuthToken22772026/10/01 07:32:00 INFO Upload complete. (74ms)2278=== NAME TestClientMultipleUploads2279 client_integration_test.go:369: Uploaded 3 paths in 114.246344ms22802026/10/01 07:32:00 OK 3_commit_push.sql (2.54ms)22812026/10/01 07:32:00 goose: up to current file version: 322822026/10/01 07:32:00 INFO Aborted multipart uploads count=022832026/10/01 07:32:00 OK 20251218171726_add_pins.sql (5.4ms)22842026/10/01 07:32:00 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NWU5NDI5N2EtZDk3OC00ZTk4LWI2MWMtNDA4ODMzODgxZTZhLmNiY2I0MTZiLWY1Y2EtNDhmNS1iOWM3LTUzNDU5OTU5MzIwMngxNzkwODM5OTIwMzIzNzU5NTU4 parts=1022852026/10/01 07:32:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22862026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)22872026/10/01 07:32:00 INFO Completed upload id=122882026/10/01 07:32:00 OK 20241026095416_initial_model.sql (14.83ms)22892026/10/01 07:32:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022902026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.95ms)22912026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures22922026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)2293--- PASS: TestClientMultipleUploads (0.68s)2294=== CONT TestClientErrorHandling/ServerNotAvailable22952026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures22962026/10/01 07:32:00 INFO Vacuumed table table=pending_closures22972026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.51ms)22982026/10/01 07:32:00 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo22992026/10/01 07:32:00 WARN Found objects in DB but missing from S3, will re-upload count=123002026/10/01 07:32:00 INFO Vacuumed table table=pending_objects23012026/10/01 07:32:00 OK 20251218171726_add_pins.sql (5.09ms)23022026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (3.47ms)23032026/10/01 07:32:00 goose: successfully migrated database to version: 202609231200002304--- PASS: TestService_verifyS3Integrity (0.77s)2305=== CONT TestCacheConfigHandler/full_config,_no_issuer2306=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2307=== CONT TestCacheConfigHandler/no_signing_keys2308=== CONT TestCacheConfigHandler/no_cache_url_configured2309--- PASS: TestCacheConfigHandler (0.00s)2310 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2311 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2312 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2313 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2314=== CONT TestResolveDBConnectionString/flag_wins2315=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2316=== CONT TestResolveDBConnectionString/missing_file_is_an_error2317=== CONT TestResolveDBConnectionString/file_when_flag_empty2318=== CONT TestResolveDBConnectionString/nothing_configured2319=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info23202026/10/01 07:32:00 INFO Received uploads request method=POST path=/2321=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23222026/10/01 07:32:00 INFO Received complete multipart upload request method=POST path=/2323=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23242026/10/01 07:32:00 INFO Received request for more parts method=POST path=/2325--- PASS: TestResolveDBConnectionString (0.00s)2326 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2327 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2328 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2329 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2330 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2331=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23322026/10/01 07:32:00 INFO Received uploads request method=POST path=/23332026/10/01 07:32:00 INFO Received create pin request method=POST path=/api/pins/myapp2334--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2335 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2336 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2337 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2338 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)23392026/10/01 07:32:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures23402026/10/01 07:32:00 INFO Garbage collection started23412026/10/01 07:32:00 INFO Vacuumed table table=multipart_uploads23422026/10/01 07:32:00 OK 1_commit_pending_closure.sql (3.33ms)23432026-10-01 07:32:00.683 UTC [1268] ERROR: relation "goose_db_version" does not exist at character 3623442026-10-01 07:32:00.683 UTC [1268] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23452026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (5.32ms)23462026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.99ms)23472026/10/01 07:32:00 INFO Vacuumed table table=closures23482026/10/01 07:32:00 OK 3_commit_push.sql (1.79ms)23492026/10/01 07:32:00 goose: up to current file version: 323502026/10/01 07:32:00 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4118302586/001/store/13yj62ladk5ih99xnxs7699xmrrx0aih-pinned-file.txt narinfo_key=13yj62ladk5ih99xnxs7699xmrrx0aih.narinfo23512026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.99ms)23522026/10/01 07:32:00 INFO Vacuumed table table=objects23532026/10/01 07:32:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures23542026/10/01 07:32:00 INFO Garbage collection started23552026/10/01 07:32:00 INFO Aborted multipart uploads count=023562026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (3.52ms)23572026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.46ms)23582026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000023592026/10/01 07:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period23602026/10/01 07:32:00 OK 1_commit_pending_closure.sql (3.08ms)23612026/10/01 07:32:00 INFO Aborted multipart uploads count=023622026/10/01 07:32:00 INFO Aborted multipart uploads count=023632026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.93ms)23642026/10/01 07:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period23652026-10-01 07:32:00.702 UTC [1289] ERROR: relation "goose_db_version" does not exist at character 3623662026-10-01 07:32:00.702 UTC [1289] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23672026/10/01 07:32:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023682026/10/01 07:32:00 INFO Vacuumed table table=pending_closures23692026/10/01 07:32:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000023702026/10/01 07:32:00 INFO Vacuumed table table=pending_objects2371--- PASS: TestService_createPendingClosureHandler (0.88s)23722026/10/01 07:32:00 INFO Vacuumed table table=multipart_uploads23732026/10/01 07:32:00 OK 20241026095416_initial_model.sql (15.85ms)23742026/10/01 07:32:00 INFO Vacuumed table table=closures23752026/10/01 07:32:00 INFO Vacuumed table table=objects23762026/10/01 07:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period23772026/10/01 07:32:00 OK 3_commit_push.sql (8.04ms)23782026/10/01 07:32:00 goose: up to current file version: 323792026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)2380--- PASS: TestGCMetrics (0.56s)23812026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.65ms)23822026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)23832026-10-01 07:32:00.717 UTC [1307] ERROR: relation "goose_db_version" does not exist at character 3623842026-10-01 07:32:00.717 UTC [1307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23852026/10/01 07:32:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=023862026/10/01 07:32:00 OK 20241026095416_initial_model.sql (11.4ms)23872026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.34ms)23882026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)23892026/10/01 07:32:00 INFO Vacuumed table table=pending_closures23902026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.85ms)23912026/10/01 07:32:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=023922026-10-01 07:32:00.724 UTC [1309] ERROR: relation "goose_db_version" does not exist at character 3623932026-10-01 07:32:00.724 UTC [1309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23942026/10/01 07:32:00 INFO Vacuumed table table=pending_objects23952026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.9ms)23962026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000023972026/10/01 07:32:00 OK 20251218171726_add_pins.sql (4.17ms)23982026/10/01 07:32:00 INFO Vacuumed table table=multipart_uploads23992026/10/01 07:32:00 INFO Vacuumed table table=pending_closures24002026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.05ms)24012026/10/01 07:32:00 INFO Vacuumed table table=closures24022026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.41ms)24032026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (3.45ms)24042026/10/01 07:32:00 OK 3_commit_push.sql (956.27µs)24052026/10/01 07:32:00 goose: up to current file version: 324062026/10/01 07:32:00 INFO Vacuumed table table=pending_objects24072026/10/01 07:32:00 INFO Vacuumed table table=objects24082026/10/01 07:32:00 INFO Vacuumed table table=multipart_uploads24092026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.45ms)24102026/10/01 07:32:00 INFO Aborted multipart uploads count=024112026/10/01 07:32:00 INFO Vacuumed table table=closures24122026/10/01 07:32:00 INFO Vacuumed table table=objects24132026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.57ms)24142026/10/01 07:32:00 OK 20241026095416_initial_model.sql (12.72ms)24152026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (1.77ms)24162026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000024172026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)24182026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.05ms)24192026/10/01 07:32:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=024202026/10/01 07:32:00 OK 20241026095416_initial_model.sql (10.69ms)24212026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.71ms)24222026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.48ms)24232026/10/01 07:32:00 OK 3_commit_push.sql (1.13ms)24242026/10/01 07:32:00 goose: up to current file version: 324252026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)24262026/10/01 07:32:00 INFO Vacuumed table table=pending_closures24272026/10/01 07:32:00 INFO Vacuumed table table=pending_objects24282026/10/01 07:32:00 INFO Vacuumed table table=multipart_uploads24292026/10/01 07:32:00 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24302026-10-01 07:32:00.745 UTC [1345] ERROR: relation "goose_db_version" does not exist at character 3624312026-10-01 07:32:00.745 UTC [1345] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24322026/10/01 07:32:00 OK 20251218171726_add_pins.sql (3.3ms)24332026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)24342026/10/01 07:32:00 INFO Vacuumed table table=closures24352026/10/01 07:32:00 INFO Vacuumed table table=objects24362026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)24372026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.53ms)24382026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.38ms)24392026/10/01 07:32:00 INFO Aborted multipart uploads count=024402026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.14ms)24412026/10/01 07:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period24422026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (1.95ms)24432026/10/01 07:32:00 goose: successfully migrated database to version: 202609231200002444=== RUN TestService_RequireScope_OIDC/builder_may_write2445=== PAUSE TestService_RequireScope_OIDC/builder_may_write2446=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2447=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2448=== RUN TestService_RequireScope_OIDC/ops_may_admin2449=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2450=== RUN TestService_RequireScope_OIDC/ops_may_not_write2451=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2452=== RUN TestService_RequireScope_OIDC/reader_may_not_write2453=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2454=== RUN TestService_RequireScope_OIDC/static_token_may_admin24552026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.14ms)2456=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2457=== RUN TestService_RequireScope_OIDC/static_token_may_write2458=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2459=== RUN TestService_RequireScope_OIDC/reader_may_read2460=== PAUSE TestService_RequireScope_OIDC/reader_may_read2461=== RUN TestService_RequireScope_OIDC/writer_implies_read2462=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2463=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2464=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2465=== CONT TestService_RequireScope_OIDC/builder_may_write2466=== CONT TestService_RequireScope_OIDC/static_token_may_admin2467=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2468=== CONT TestService_RequireScope_OIDC/writer_implies_read24692026/10/01 07:32:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=02470=== CONT TestService_RequireScope_OIDC/reader_may_read2471=== CONT TestService_RequireScope_OIDC/ops_may_not_write2472=== CONT TestService_RequireScope_OIDC/static_token_may_write2473=== CONT TestService_RequireScope_OIDC/ops_may_admin24742026/10/01 07:32:00 OK 1_commit_pending_closure.sql (2.22ms)2475=== CONT TestService_RequireScope_OIDC/reader_may_not_write2476=== CONT TestService_RequireScope_OIDC/builder_may_not_admin24772026/10/01 07:32:00 INFO lead: acquired remote=192.0.2.1:123424782026/10/01 07:32:00 INFO lead: released remote=192.0.2.1:12342479--- PASS: TestLeadEndsOnShutdown (0.50s)24802026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.31ms)24812026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000024822026/10/01 07:32:00 INFO Vacuumed table table=pending_closures2483--- PASS: TestService_RequireScope_OIDC (0.58s)2484 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2485 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2486 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2487 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2488 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2489 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2490 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2491 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2492 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2493 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2494=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure2495=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure2496=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart2497=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart2498=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts2499=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts2500=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure2501=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart25022026/10/01 07:32:00 INFO Received uploads request method=POST path=/25032026/10/01 07:32:00 INFO Received complete multipart upload request method=POST path=/2504=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts25052026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.42ms)25062026/10/01 07:32:00 INFO Received request for more parts method=POST path=/25072026/10/01 07:32:00 INFO Vacuumed table table=pending_objects25082026/10/01 07:32:00 INFO Vacuumed table table=multipart_uploads25092026/10/01 07:32:00 OK 1_commit_pending_closure.sql (1.63ms)25102026/10/01 07:32:00 OK 3_commit_push.sql (1.44ms)25112026/10/01 07:32:00 goose: up to current file version: 325122026/10/01 07:32:00 OK 2_object_stats_trigger.sql (937.01µs)25132026/10/01 07:32:00 INFO Vacuumed table table=closures25142026/10/01 07:32:00 OK 3_commit_push.sql (613.29µs)25152026/10/01 07:32:00 goose: up to current file version: 325162026/10/01 07:32:00 INFO Vacuumed table table=objects25172026/10/01 07:32:00 OK 20241026095416_initial_model.sql (11.42ms)2518--- PASS: TestPushDedupSurvivesConcurrentGC (0.64s)25192026/10/01 07:32:00 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)25202026/10/01 07:32:00 INFO Received push request method=POST path=/api/pushes25212026/10/01 07:32:00 OK 20251218171726_add_pins.sql (2.98ms)25222026/10/01 07:32:00 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)25232026/10/01 07:32:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25242026/10/01 07:32:00 INFO Uploading j5d9nnzg8j4chwildbl2672m9jhzd5q0-ca-test (144B)25252026/10/01 07:32:00 OK 20260905000000_add_claims.sql (3.53ms)25262026/10/01 07:32:00 WARN Failed to register uploaded object key=j5d9nnzg8j4chwildbl2672m9jhzd5q0.ls error="server returned 404: 404 page not found\n"25272026/10/01 07:32:00 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"25282026/10/01 07:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign25292026/10/01 07:32:00 OK 20260920000000_drop_claims.sql (2.15ms)25302026/10/01 07:32:00 WARN Failed to register uploaded object key=log/b7s4y8ifzbhb874hyfd3mn5xa10d83k1-ca-test.drv error="server returned 404: 404 page not found\n"25312026/10/01 07:32:00 INFO Signed narinfos id=1 count=125322026/10/01 07:32:00 INFO Uploading 1 narinfos2533=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2534=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2535=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2536=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2537=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2538=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2539=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2540=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2541=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2542=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2543=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2544=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected25452026/10/01 07:32:00 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]25462026/10/01 07:32:00 OK 20260923120000_add_pushes.sql (2.72ms)25472026/10/01 07:32:00 goose: successfully migrated database to version: 2026092312000025482026/10/01 07:32:00 OK 1_commit_pending_closure.sql (1.98ms)25492026/10/01 07:32:00 WARN Authentication failed token_preview=eyJhbGciOi...InKVLh3p8Q token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]25502026/10/01 07:32:00 INFO Received complete push request method=POST path=/api/pushes/1/complete25512026/10/01 07:32:00 WARN Failed to register uploaded object key=j5d9nnzg8j4chwildbl2672m9jhzd5q0.narinfo error="server returned 404: 404 page not found\n"2552--- PASS: TestService_AuthMiddleware_OIDC (0.55s)2553 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2554 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2555 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2556 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)25572026/10/01 07:32:00 OK 2_object_stats_trigger.sql (1.26ms)25582026/10/01 07:32:00 OK 3_commit_push.sql (935.95µs)25592026/10/01 07:32:00 goose: up to current file version: 325602026/10/01 07:32:00 INFO Upload complete. (91ms)2561=== NAME TestClientCADerivations2562 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3202428597/001/store/j5d9nnzg8j4chwildbl2672m9jhzd5q0-ca-test2563 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2564 Compression: zstd2565 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2566 NarSize: 1442567 References: 2568 Deriver: /build/TestClientCADerivations3202428597/001/store/b7s4y8ifzbhb874hyfd3mn5xa10d83k1-ca-test.drv2569 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2570 client_ca_test.go:185: Checking for realisation files in S3...2571 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2572 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2573--- PASS: TestService_ReadAuthMiddleware (0.51s)25742026/10/01 07:32:00 INFO lead: acquired remote=192.0.2.1:12342575--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.30s)25762026/10/01 07:32:00 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.760821ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25772026/10/01 07:32:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"25782026/10/01 07:32:00 WARN mTLS auth: bound subjects configured but subject DN unavailable25792026/10/01 07:32:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2580--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.33s)2581=== NAME TestClientCADerivations2582 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2583 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2584 error: binary cache 's3://bucket52?endpoint=http://localhost:36677&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3202428597/001/store'2585 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12586--- PASS: TestClientCADerivations (0.85s)25872026/10/01 07:32:00 INFO Received cleanup request method=DELETE path=/api/pending_closures25882026/10/01 07:32:00 INFO Aborted multipart uploads count=025892026/10/01 07:32:00 INFO Received uploads request method=POST path=/api/pending_closures25902026/10/01 07:32:00 INFO Received cleanup request method=DELETE path=/api/pending_closures25912026/10/01 07:32:00 INFO Aborted multipart uploads count=125922026/10/01 07:32:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25932026-10-01 07:32:00.923 UTC [1289] ERROR: Closure does not exist: id=125942026-10-01 07:32:00.923 UTC [1289] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE25952026-10-01 07:32:00.923 UTC [1289] STATEMENT: -- name: CommitPendingClosure :exec2596 SELECT commit_pending_closure($1::bigint)2597 2598--- PASS: TestService_cleanupPendingClosuresHandler (0.32s)2599--- PASS: TestGCBugBareHashReferences (0.73s)26002026/10/01 07:32:00 INFO lead: released remote=192.0.2.1:123426012026/10/01 07:32:01 INFO lead: acquired remote=192.0.2.1:123426022026/10/01 07:32:01 INFO lead: released remote=192.0.2.1:12342603--- PASS: TestLeadElectsOneAndHandsOver (0.51s)26042026/10/01 07:32:01 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"26052026/10/01 07:32:01 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.795533ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26062026/10/01 07:32:01 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"26072026/10/01 07:32:01 INFO Received uploads request method=POST path=/api/pending_closures26082026/10/01 07:32:01 INFO Received uploads request method=POST path=/api/pending_closures26092026/10/01 07:32:01 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)26102026/10/01 07:32:01 INFO Uploading r6d58l8d48rwm7ny5lh3sgpdkmk2wsfj-b (216B)26112026/10/01 07:32:01 INFO Uploading a22nni2gbb5mgydkgg3mvbi89ls3142f-shared-dep (136B)26122026/10/01 07:32:01 WARN Failed to register uploaded object key=a22nni2gbb5mgydkgg3mvbi89ls3142f.ls error="server returned 404: 404 page not found\n"26132026/10/01 07:32:01 WARN Failed to register uploaded object key=7za0wwax6l9326fy1qzghnm7sx3ivqka.ls error="server returned 404: 404 page not found\n"26142026/10/01 07:32:01 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"26152026/10/01 07:32:01 WARN Failed to register uploaded object key=nar/11af66r52q86lqzxadp7s7n6bhh2fy5k9z3rawcgszphaimdrl8c.nar.zst error="server returned 404: 404 page not found\n"26162026/10/01 07:32:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign26172026/10/01 07:32:01 WARN Failed to register uploaded object key=r6d58l8d48rwm7ny5lh3sgpdkmk2wsfj.ls error="server returned 404: 404 page not found\n"26182026/10/01 07:32:01 INFO Signed narinfos id=1 count=226192026/10/01 07:32:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign26202026/10/01 07:32:01 INFO Signed narinfos id=2 count=226212026/10/01 07:32:01 INFO Uploading 4 narinfos26222026/10/01 07:32:01 WARN Failed to register uploaded object key=7za0wwax6l9326fy1qzghnm7sx3ivqka.narinfo error="server returned 404: 404 page not found\n"26232026/10/01 07:32:01 WARN Failed to register uploaded object key=a22nni2gbb5mgydkgg3mvbi89ls3142f.narinfo error="server returned 404: 404 page not found\n"26242026/10/01 07:32:01 WARN Failed to register uploaded object key=r6d58l8d48rwm7ny5lh3sgpdkmk2wsfj.narinfo error="server returned 404: 404 page not found\n"26252026/10/01 07:32:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete26262026/10/01 07:32:01 WARN Failed to register uploaded object key=a22nni2gbb5mgydkgg3mvbi89ls3142f.narinfo error="server returned 404: 404 page not found\n"26272026/10/01 07:32:01 INFO Completed upload id=126282026/10/01 07:32:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete26292026/10/01 07:32:01 INFO Completed upload id=226302026/10/01 07:32:01 INFO Upload complete. (60ms)2631=== NAME TestClientFallsBackToClosures2632 client_pushes_test.go:112: Retrieved narinfo from S3:2633 StorePath: /build/TestClientFallsBackToClosures2799478277/001/store/a22nni2gbb5mgydkgg3mvbi89ls3142f-shared-dep2634 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2635 Compression: zstd2636 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822637 NarSize: 1362638 References: 2639 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2640 client_pushes_test.go:112: Retrieved narinfo from S3:2641 StorePath: /build/TestClientFallsBackToClosures2799478277/001/store/7za0wwax6l9326fy1qzghnm7sx3ivqka-a2642 URL: nar/11af66r52q86lqzxadp7s7n6bhh2fy5k9z3rawcgszphaimdrl8c.nar.zst2643 Compression: zstd2644 NarHash: sha256:11af66r52q86lqzxadp7s7n6bhh2fy5k9z3rawcgszphaimdrl8c2645 NarSize: 2162646 References: /build/TestClientFallsBackToClosures2799478277/001/store/a22nni2gbb5mgydkgg3mvbi89ls3142f-shared-dep2647 CA: text:sha256:1j0f6c19bq3l23d2kri01nasxs0ddk0jrcfllv0gcwsvk9z1m56g2648 client_pushes_test.go:112: Retrieved narinfo from S3:2649 StorePath: /build/TestClientFallsBackToClosures2799478277/001/store/r6d58l8d48rwm7ny5lh3sgpdkmk2wsfj-b2650 URL: nar/11af66r52q86lqzxadp7s7n6bhh2fy5k9z3rawcgszphaimdrl8c.nar.zst2651 Compression: zstd2652 NarHash: sha256:11af66r52q86lqzxadp7s7n6bhh2fy5k9z3rawcgszphaimdrl8c2653 NarSize: 2162654 References: /build/TestClientFallsBackToClosures2799478277/001/store/a22nni2gbb5mgydkgg3mvbi89ls3142f-shared-dep2655 CA: text:sha256:1j0f6c19bq3l23d2kri01nasxs0ddk0jrcfllv0gcwsvk9z1m56g2656--- PASS: TestClientFallsBackToClosures (0.51s)26572026/10/01 07:32:01 INFO Received push request method=POST path=/api/pushes26582026/10/01 07:32:01 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)26592026/10/01 07:32:01 INFO Uploading 6gbkfngd46kbg408d5sdxbqd684ygwv1-shared-dep (136B)26602026/10/01 07:32:01 INFO Uploading xcmy0b8ybc7vdyrz6cwsn6q8yq3x2mjh-b (216B)26612026/10/01 07:32:01 WARN Failed to register uploaded object key=nar/1zixpdydp4ybwf6p5iq9lgjfnldb117hcykwldi0q3mk3y0ddvnc.nar.zst error="server returned 404: 404 page not found\n"26622026/10/01 07:32:01 WARN Failed to register uploaded object key=xcmy0b8ybc7vdyrz6cwsn6q8yq3x2mjh.ls error="server returned 404: 404 page not found\n"26632026/10/01 07:32:01 WARN Failed to register uploaded object key=icgcgy83n3cw55jy5n9nzmh3ix5x75cw.ls error="server returned 404: 404 page not found\n"26642026/10/01 07:32:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26652026/10/01 07:32:01 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"26662026/10/01 07:32:01 WARN Failed to register uploaded object key=6gbkfngd46kbg408d5sdxbqd684ygwv1.ls error="server returned 404: 404 page not found\n"26672026/10/01 07:32:01 INFO Signed narinfos id=1 count=326682026/10/01 07:32:01 INFO Uploading 3 narinfos26692026/10/01 07:32:01 WARN Failed to register uploaded object key=icgcgy83n3cw55jy5n9nzmh3ix5x75cw.narinfo error="server returned 404: 404 page not found\n"26702026/10/01 07:32:01 WARN Failed to register uploaded object key=xcmy0b8ybc7vdyrz6cwsn6q8yq3x2mjh.narinfo error="server returned 404: 404 page not found\n"26712026/10/01 07:32:01 INFO Received complete push request method=POST path=/api/pushes/1/complete26722026/10/01 07:32:01 WARN Failed to register uploaded object key=6gbkfngd46kbg408d5sdxbqd684ygwv1.narinfo error="server returned 404: 404 page not found\n"26732026/10/01 07:32:01 INFO Upload complete. (59ms)2674=== NAME TestClientPushesUseOnePush2675 client_pushes_test.go:97: Retrieved narinfo from S3:2676 StorePath: /build/TestClientPushesUseOnePush1189384246/001/store/6gbkfngd46kbg408d5sdxbqd684ygwv1-shared-dep2677 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2678 Compression: zstd2679 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822680 NarSize: 1362681 References: 2682 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2683 client_pushes_test.go:97: Retrieved narinfo from S3:2684 StorePath: /build/TestClientPushesUseOnePush1189384246/001/store/icgcgy83n3cw55jy5n9nzmh3ix5x75cw-a2685 URL: nar/1zixpdydp4ybwf6p5iq9lgjfnldb117hcykwldi0q3mk3y0ddvnc.nar.zst2686 Compression: zstd2687 NarHash: sha256:1zixpdydp4ybwf6p5iq9lgjfnldb117hcykwldi0q3mk3y0ddvnc2688 NarSize: 2162689 References: /build/TestClientPushesUseOnePush1189384246/001/store/6gbkfngd46kbg408d5sdxbqd684ygwv1-shared-dep2690 CA: text:sha256:09ssyypm4jny1b848d786yrgfm1zfii1kycxsmcc3k4s0rbpdv892691 client_pushes_test.go:97: Retrieved narinfo from S3:2692 StorePath: /build/TestClientPushesUseOnePush1189384246/001/store/xcmy0b8ybc7vdyrz6cwsn6q8yq3x2mjh-b2693 URL: nar/1zixpdydp4ybwf6p5iq9lgjfnldb117hcykwldi0q3mk3y0ddvnc.nar.zst2694 Compression: zstd2695 NarHash: sha256:1zixpdydp4ybwf6p5iq9lgjfnldb117hcykwldi0q3mk3y0ddvnc2696 NarSize: 2162697 References: /build/TestClientPushesUseOnePush1189384246/001/store/6gbkfngd46kbg408d5sdxbqd684ygwv1-shared-dep2698 CA: text:sha256:09ssyypm4jny1b848d786yrgfm1zfii1kycxsmcc3k4s0rbpdv892699--- PASS: TestClientPushesUseOnePush (0.53s)2700=== NAME TestOrphanedObjectsGCStressTest2701 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2702 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2703 orphaned_objects_gc_test.go:509: Stress test completed successfully:2704 orphaned_objects_gc_test.go:510: - Active objects preserved: 202705 orphaned_objects_gc_test.go:511: - Objects deleted: 2102706 orphaned_objects_gc_test.go:512: - Total GC'd: 2102707--- PASS: TestOrphanedObjectsGCStressTest (2.35s)27082026/10/01 07:32:01 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=812.567427ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2709--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2710 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2711 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2712 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.94s)27132026/10/01 07:32:02 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.686807213s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27142026/10/01 07:32:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02715=== NAME TestClientIntegration2716 client_integration_test.go:323: Objects in database after GC:2717 client_integration_test.go:323: Successfully deleted all objects with GC --force2718--- PASS: TestClientIntegration (2.68s)27192026/10/01 07:32:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02720=== NAME TestPinProtectsFromGC2721 client_integration_test.go:794: Pin successfully protected closure from garbage collection2722--- PASS: TestPinProtectsFromGC (2.74s)27232026/10/01 07:32:04 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27242026/10/01 07:32:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.676472ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27252026/10/01 07:32:04 WARN Rate limiter enabled after throttle name=s3-test rate=527262026/10/01 07:32:04 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2727=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2728 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102729 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002730--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.20s)27312026/10/01 07:32:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=420.049458ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27322026/10/01 07:32:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=773.060579ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27332026/10/01 07:32:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.582254328s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27342026/10/01 07:32:07 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"27352026/10/01 07:32:07 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27362026/10/01 07:32:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.395783ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27372026/10/01 07:32:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=422.98489ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27382026/10/01 07:32:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=757.804256ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27392026/10/01 07:32:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.523297557s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27402026/10/01 07:32:10 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27412026/10/01 07:32:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.810901ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27422026/10/01 07:32:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=427.551033ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27432026/10/01 07:32:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=748.523539ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27442026/10/01 07:32:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.572599178s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2745--- PASS: TestClientErrorHandling (0.00s)2746 --- PASS: TestClientErrorHandling/InvalidStorePath (0.37s)2747 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.41s)2748 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.48s)2749PASS27502026-10-01 07:32:13.373 UTC [128] LOG: received smart shutdown request27512026-10-01 07:32:13.378 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 127522026-10-01 07:32:13.390 UTC [133] LOG: shutting down27532026-10-01 07:32:13.390 UTC [133] LOG: checkpoint starting: shutdown immediate27542026-10-01 07:32:14.375 UTC [133] LOG: checkpoint complete: wrote 10233 buffers (62.5%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 20 recycled; write=0.183 s, sync=0.779 s, total=0.986 s; sync files=23917, longest=0.002 s, average=0.001 s; distance=325415 kB, estimate=325415 kB; lsn=0/1552FB50, redo lsn=0/1552FB5027552026-10-01 07:32:14.452 UTC [128] LOG: database system is shut down2756Running OIDC tests...2757=== RUN TestAudienceForIssuer2758=== PAUSE TestAudienceForIssuer2759=== RUN TestGlobMatch2760=== PAUSE TestGlobMatch2761=== RUN TestValidateToken_ValidToken2762=== PAUSE TestValidateToken_ValidToken2763=== RUN TestValidateToken_WrongAudience2764=== PAUSE TestValidateToken_WrongAudience2765=== RUN TestValidateToken_Expired2766=== PAUSE TestValidateToken_Expired2767=== RUN TestValidateToken_BoundClaimsMismatch2768=== PAUSE TestValidateToken_BoundClaimsMismatch2769=== RUN TestValidateToken_BoundSubjectMismatch2770=== PAUSE TestValidateToken_BoundSubjectMismatch2771=== RUN TestValidateToken_MultipleProviders2772=== PAUSE TestValidateToken_MultipleProviders2773=== RUN TestValidateToken_NoMatchingProvider2774=== PAUSE TestValidateToken_NoMatchingProvider2775=== RUN TestValidateToken_KubernetesServiceAccount2776=== PAUSE TestValidateToken_KubernetesServiceAccount2777=== RUN TestNewValidator_KubernetesRequiresCA2778=== PAUSE TestNewValidator_KubernetesRequiresCA2779=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2780=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2781=== RUN TestPins_ReservedForMatchingRule2782=== PAUSE TestPins_ReservedForMatchingRule2783=== RUN TestPins_TopLevelShorthand2784=== PAUSE TestPins_TopLevelShorthand2785=== RUN TestPins_ConfigValidation2786=== PAUSE TestPins_ConfigValidation2787=== RUN TestScopes_LegacyProviderDefaultsToWrite2788=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2789=== RUN TestScopes_Rules2790=== PAUSE TestScopes_Rules2791=== RUN TestScopes_ConfigValidation2792=== PAUSE TestScopes_ConfigValidation2793=== CONT TestAudienceForIssuer2794=== CONT TestValidateToken_MultipleProviders2795=== CONT TestValidateToken_BoundSubjectMismatch2796=== CONT TestValidateToken_KubernetesServiceAccount2797--- PASS: TestAudienceForIssuer (0.00s)2798=== CONT TestValidateToken_BoundClaimsMismatch2799=== CONT TestValidateToken_Expired2800=== CONT TestValidateToken_WrongAudience2801=== CONT TestValidateToken_ValidToken2802=== CONT TestGlobMatch2803=== RUN TestGlobMatch/foo_foo2804=== PAUSE TestGlobMatch/foo_foo2805=== RUN TestGlobMatch/foo_bar2806=== PAUSE TestGlobMatch/foo_bar2807=== RUN TestGlobMatch/*_2808=== PAUSE TestGlobMatch/*_2809=== RUN TestGlobMatch/*_anything2810=== PAUSE TestGlobMatch/*_anything2811=== CONT TestValidateToken_NoMatchingProvider2812=== CONT TestPins_ReservedForMatchingRule2813=== CONT TestPins_TopLevelShorthand2814=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2815=== CONT TestScopes_Rules2816=== CONT TestScopes_ConfigValidation2817=== CONT TestNewValidator_KubernetesRequiresCA2818=== CONT TestScopes_LegacyProviderDefaultsToWrite2819=== CONT TestPins_ConfigValidation2820=== RUN TestGlobMatch/foo*_foo2821=== PAUSE TestGlobMatch/foo*_foo2822=== RUN TestGlobMatch/foo*_foobar2823=== PAUSE TestGlobMatch/foo*_foobar2824=== RUN TestGlobMatch/foo*_bar2825=== PAUSE TestGlobMatch/foo*_bar2826=== RUN TestGlobMatch/*bar_bar2827=== PAUSE TestGlobMatch/*bar_bar2828=== RUN TestGlobMatch/*bar_foobar2829=== PAUSE TestGlobMatch/*bar_foobar2830=== RUN TestGlobMatch/*bar_foo2831=== PAUSE TestGlobMatch/*bar_foo2832=== RUN TestGlobMatch/foo*bar_foobar2833=== PAUSE TestGlobMatch/foo*bar_foobar2834=== RUN TestGlobMatch/foo*bar_foo123bar2835=== PAUSE TestGlobMatch/foo*bar_foo123bar2836=== RUN TestGlobMatch/foo*bar_foobarbaz2837=== PAUSE TestGlobMatch/foo*bar_foobarbaz2838=== RUN TestGlobMatch/*/*_foo/bar2839--- PASS: TestPins_ConfigValidation (0.00s)2840=== PAUSE TestGlobMatch/*/*_foo/bar2841=== RUN TestGlobMatch/*/*_foo2842=== PAUSE TestGlobMatch/*/*_foo2843=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2844=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2845=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02846=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02847=== RUN TestGlobMatch/refs/*/main_refs/heads/main2848=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2849=== RUN TestGlobMatch/fo?_foo2850=== PAUSE TestGlobMatch/fo?_foo2851=== RUN TestGlobMatch/fo?_fo2852=== PAUSE TestGlobMatch/fo?_fo2853=== RUN TestGlobMatch/fo?_fooo2854=== PAUSE TestGlobMatch/fo?_fooo2855=== RUN TestGlobMatch/?oo_foo2856=== PAUSE TestGlobMatch/?oo_foo2857=== RUN TestGlobMatch/?oo_boo2858--- PASS: TestScopes_ConfigValidation (0.00s)2859=== PAUSE TestGlobMatch/?oo_boo2860=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2861=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2862=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2863=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2864=== CONT TestGlobMatch/foo_foo2865=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2866=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02867=== CONT TestGlobMatch/fo?_foo2868=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2869=== CONT TestGlobMatch/*bar_foo2870=== CONT TestGlobMatch/*_2871=== CONT TestGlobMatch/refs/*/main_refs/heads/main2872=== CONT TestGlobMatch/foo_bar2873=== CONT TestGlobMatch/?oo_boo2874=== CONT TestGlobMatch/foo*bar_foobar2875=== CONT TestGlobMatch/*/*_foo/bar2876=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2877=== CONT TestGlobMatch/*bar_foobar2878=== CONT TestGlobMatch/*bar_bar2879=== CONT TestGlobMatch/foo*_bar2880=== CONT TestGlobMatch/*/*_foo2881=== CONT TestGlobMatch/?oo_foo2882=== CONT TestGlobMatch/foo*_foobar2883=== CONT TestGlobMatch/fo?_fooo2884=== CONT TestGlobMatch/foo*_foo2885=== CONT TestGlobMatch/fo?_fo2886=== CONT TestGlobMatch/*_anything2887=== CONT TestGlobMatch/foo*bar_foo123bar2888=== CONT TestGlobMatch/foo*bar_foobarbaz2889--- PASS: TestGlobMatch (0.00s)2890 --- PASS: TestGlobMatch/foo_foo (0.00s)2891 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2892 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2893 --- PASS: TestGlobMatch/fo?_foo (0.00s)2894 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2895 --- PASS: TestGlobMatch/*bar_foo (0.00s)2896 --- PASS: TestGlobMatch/*_ (0.00s)2897 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2898 --- PASS: TestGlobMatch/foo_bar (0.00s)2899 --- PASS: TestGlobMatch/?oo_boo (0.00s)2900 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2901 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2902 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2903 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2904 --- PASS: TestGlobMatch/*bar_bar (0.00s)2905 --- PASS: TestGlobMatch/foo*_bar (0.00s)2906 --- PASS: TestGlobMatch/*/*_foo (0.00s)2907 --- PASS: TestGlobMatch/?oo_foo (0.00s)2908 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2909 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2910 --- PASS: TestGlobMatch/foo*_foo (0.00s)2911 --- PASS: TestGlobMatch/fo?_fo (0.00s)2912 --- PASS: TestGlobMatch/*_anything (0.00s)2913 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2914 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)29152026/10/01 07:32:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36063/oidc2916--- PASS: TestValidateToken_Expired (0.04s)29172026/10/01 07:32:15 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232918--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)29192026/10/01 07:32:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38521/oidc29202026/10/01 07:32:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34851/oidc2921--- PASS: TestValidateToken_ValidToken (0.10s)29222026/10/01 07:32:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43859/oidc29232026/10/01 07:32:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40415/oidc2924--- PASS: TestValidateToken_BoundClaimsMismatch (0.10s)2925--- PASS: TestScopes_Rules (0.11s)2926--- PASS: TestPins_TopLevelShorthand (0.11s)29272026/10/01 07:32:15 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3747729282026/10/01 07:32:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37247/oidc2929--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)2930--- PASS: TestValidateToken_BoundSubjectMismatch (0.13s)29312026/10/01 07:32:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34617/oidc2932--- PASS: TestPins_ReservedForMatchingRule (0.16s)29332026/10/01 07:32:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33859/oidc2934--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.17s)29352026/10/01 07:32:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33327/oidc2936--- PASS: TestValidateToken_WrongAudience (0.20s)29372026/10/01 07:32:15 http: TLS handshake error from 127.0.0.1:41882: remote error: tls: bad certificate2938--- PASS: TestNewValidator_KubernetesRequiresCA (0.32s)29392026/10/01 07:32:16 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37925/oidc2940--- PASS: TestValidateToken_NoMatchingProvider (0.35s)29412026/10/01 07:32:16 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36963/oidc29422026/10/01 07:32:16 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37435/oidc2943--- PASS: TestValidateToken_MultipleProviders (0.44s)2944PASS2945Running hook tests...2946=== RUN TestSendPathsEmpty2947=== PAUSE TestSendPathsEmpty2948=== RUN TestQueueEnqueueAndFetch2949=== PAUSE TestQueueEnqueueAndFetch2950=== RUN TestQueueDeduplication2951=== PAUSE TestQueueDeduplication2952=== RUN TestQueueRemove2953=== PAUSE TestQueueRemove2954=== RUN TestQueueFetchBatchLimit2955=== PAUSE TestQueueFetchBatchLimit2956=== RUN TestQueueRetryMovesToBack2957=== PAUSE TestQueueRetryMovesToBack2958=== RUN TestQueueFetchRemoveLifecycle2959=== PAUSE TestQueueFetchRemoveLifecycle2960=== RUN TestQueueConcurrentWriters2961=== PAUSE TestQueueConcurrentWriters2962=== RUN TestQueueRemoveLargeClosure2963=== PAUSE TestQueueRemoveLargeClosure2964=== RUN TestServerClientIntegration2965=== PAUSE TestServerClientIntegration2966=== RUN TestServerQueueError2967=== PAUSE TestServerQueueError2968=== RUN TestGetListenerSocketActivation2969 server_test.go:210: === RUN TestGetListenerSocketActivation2970 --- PASS: TestGetListenerSocketActivation (0.00s)2971 PASS2972 2973--- PASS: TestGetListenerSocketActivation (0.01s)2974=== RUN TestDrainIsolatesPoisonPath2975=== PAUSE TestDrainIsolatesPoisonPath2976=== RUN TestRunNotBlockedByPoisonHead2977=== PAUSE TestRunNotBlockedByPoisonHead2978=== RUN TestDrainGivesUpWhenServerDown2979=== PAUSE TestDrainGivesUpWhenServerDown2980=== RUN TestFailedPathPrunedByLaterClosure2981=== PAUSE TestFailedPathPrunedByLaterClosure2982=== RUN TestWorkerUploadsAndRemoves2983=== PAUSE TestWorkerUploadsAndRemoves2984=== RUN TestWorkerSkipsGCdPaths2985=== PAUSE TestWorkerSkipsGCdPaths2986=== RUN TestWorkerPrunesClosureDeps2987=== PAUSE TestWorkerPrunesClosureDeps2988=== RUN TestDrainTimeout2989=== PAUSE TestDrainTimeout2990=== CONT TestSendPathsEmpty2991=== CONT TestServerQueueError2992=== CONT TestWorkerPrunesClosureDeps2993--- PASS: TestSendPathsEmpty (0.00s)2994=== CONT TestServerClientIntegration2995=== CONT TestQueueRemoveLargeClosure2996=== CONT TestQueueConcurrentWriters2997=== CONT TestQueueFetchRemoveLifecycle29982026/10/01 07:32:16 ERROR Failed to queue paths error="permission denied" count=12999=== CONT TestQueueRetryMovesToBack3000=== CONT TestQueueFetchBatchLimit3001=== CONT TestQueueRemove3002=== CONT TestQueueDeduplication3003=== CONT TestQueueEnqueueAndFetch3004=== CONT TestDrainGivesUpWhenServerDown3005=== CONT TestFailedPathPrunedByLaterClosure3006=== CONT TestDrainTimeout3007=== CONT TestRunNotBlockedByPoisonHead3008=== CONT TestDrainIsolatesPoisonPath3009=== CONT TestWorkerSkipsGCdPaths3010=== CONT TestWorkerUploadsAndRemoves3011--- PASS: TestServerQueueError (0.00s)3012--- PASS: TestServerClientIntegration (0.00s)30132026/10/01 07:32:16 INFO Upload queue status pending=230142026/10/01 07:32:16 INFO Uploading batch count=130152026/10/01 07:32:16 ERROR Upload failed error="upload failed" count=130162026/10/01 07:32:16 INFO Uploading batch count=130172026/10/01 07:32:16 INFO Uploading batch count=230182026/10/01 07:32:16 INFO Uploading batch count=430192026/10/01 07:32:16 ERROR Upload failed error="upload failed" count=430202026/10/01 07:32:16 INFO Uploading batch count=130212026/10/01 07:32:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1012932252/002/bbb3022--- PASS: TestQueueFetchBatchLimit (0.01s)30232026/10/01 07:32:16 INFO Uploading batch count=230242026/10/01 07:32:16 ERROR Upload failed error="upload failed" count=230252026/10/01 07:32:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2848024192/002/a3026--- PASS: TestQueueRemove (0.01s)30272026/10/01 07:32:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2848024192/002/b3028--- PASS: TestQueueDeduplication (0.01s)30292026/10/01 07:32:16 INFO Uploading batch count=230302026/10/01 07:32:16 ERROR Upload failed error="upload failed" count=230312026/10/01 07:32:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2848024192/002/c30322026/10/01 07:32:16 INFO Uploading batch count=130332026/10/01 07:32:16 INFO Upload queue status pending=33034--- PASS: TestQueueEnqueueAndFetch (0.01s)30352026/10/01 07:32:16 INFO Uploading batch count=130362026/10/01 07:32:16 ERROR Upload failed error="upload failed" count=130372026/10/01 07:32:16 INFO Upload queue status pending=230382026/10/01 07:32:16 INFO Upload queue status pending=23039--- PASS: TestWorkerPrunesClosureDeps (0.02s)30402026/10/01 07:32:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2438551781/002/nonexistent30412026/10/01 07:32:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2848024192/002/d30422026/10/01 07:32:16 INFO Uploading batch count=23043--- PASS: TestQueueRetryMovesToBack (0.02s)30442026/10/01 07:32:16 INFO Uploading batch count=130452026/10/01 07:32:16 INFO Uploading batch count=230462026/10/01 07:32:16 ERROR Upload failed error="upload failed" count=230472026/10/01 07:32:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2848024192/002/e3048--- PASS: TestQueueFetchRemoveLifecycle (0.02s)30492026/10/01 07:32:16 INFO Uploading batch count=130502026/10/01 07:32:16 ERROR Upload failed error="upload failed" count=130512026/10/01 07:32:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2848024192/002/f30522026/10/01 07:32:16 INFO Uploading batch count=130532026/10/01 07:32:16 ERROR Upload failed error="upload failed" count=130542026/10/01 07:32:16 ERROR Drain finished with paths left in queue remaining=103055--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)30562026/10/01 07:32:16 INFO Uploading batch count=130572026/10/01 07:32:16 ERROR Upload failed error="upload failed" count=130582026/10/01 07:32:16 ERROR Drain finished with paths left in queue remaining=13059--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3060--- PASS: TestDrainIsolatesPoisonPath (0.02s)3061--- PASS: TestWorkerSkipsGCdPaths (0.03s)3062--- PASS: TestWorkerUploadsAndRemoves (0.03s)3063--- PASS: TestQueueConcurrentWriters (0.13s)3064--- PASS: TestQueueRemoveLargeClosure (0.15s)30652026/10/01 07:32:16 ERROR Upload failed error="context deadline exceeded" count=230662026/10/01 07:32:16 ERROR Drain finished with paths left in queue remaining=43067--- PASS: TestDrainTimeout (0.21s)30682026/10/01 07:32:17 INFO Uploading batch count=130692026/10/01 07:32:17 INFO Uploading batch count=130702026/10/01 07:32:17 INFO Uploading batch count=130712026/10/01 07:32:17 ERROR Upload failed error="upload failed" count=130722026/10/01 07:32:17 INFO Uploading batch count=130732026/10/01 07:32:17 ERROR Upload failed error="upload failed" count=130742026/10/01 07:32:17 INFO Uploading batch count=130752026/10/01 07:32:17 ERROR Upload failed error="upload failed" count=130762026/10/01 07:32:17 INFO Uploading batch count=130772026/10/01 07:32:17 ERROR Upload failed error="upload failed" count=130782026/10/01 07:32:17 ERROR Drain finished with paths left in queue remaining=13079--- PASS: TestRunNotBlockedByPoisonHead (1.02s)3080PASS

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #281 · raw

succeeded `niks3-go-unit-tests` `checks.aarch64-linux.go-unit-tests` · build #281 · raw