niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `checks.aarch64-darwin.go-unit-tests` · build #330 · raw

1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.07s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.03s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestEncodeNixBase32WithRealHash97=== CONT TestUploadMultipart_SupersededByPeer98=== RUN TestUploadMultipart_SupersededByPeer/exists99--- PASS: TestEncodeNixBase32WithRealHash (0.00s)100--- PASS: TestShellSplit (0.00s)101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102=== CONT TestResolveStorePath103=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1042026/10/01 10:03:44 WARN Rate limiter enabled after throttle name=server-test rate=5105=== CONT TestRateLimiterFeedback106=== RUN TestRateLimiterFeedback/429_enables_limiter107=== PAUSE TestRateLimiterFeedback/429_enables_limiter108=== RUN TestRateLimiterFeedback/503_enables_limiter109=== PAUSE TestRateLimiterFeedback/503_enables_limiter110=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter111=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter112=== CONT TestPathInfoCACompatibility113=== RUN TestPathInfoCACompatibility/null_ca_field114=== PAUSE TestPathInfoCACompatibility/null_ca_field115=== RUN TestPathInfoCACompatibility/old_string_format_-_text116=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text117=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive118=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive119=== RUN TestPathInfoCACompatibility/new_structured_format_-_text120=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text121=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method122=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method123=== CONT TestParsePathInfoJSONMultiplePaths124=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths125=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths126=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths127=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths128=== CONT TestGetStorePathHash129=== RUN TestGetStorePathHash/valid_store_path130=== PAUSE TestGetStorePathHash/valid_store_path131=== RUN TestGetStorePathHash/basename_without_hyphen_should_error132=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error133=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error134=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error135=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error136=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error137=== CONT TestParsePathInfoJSON138=== RUN TestParsePathInfoJSON/Nix_format139=== PAUSE TestParsePathInfoJSON/Nix_format140=== RUN TestParsePathInfoJSON/Lix_format141=== PAUSE TestParsePathInfoJSON/Lix_format142=== RUN TestParsePathInfoJSON/empty_input143=== PAUSE TestParsePathInfoJSON/empty_input144=== RUN TestParsePathInfoJSON/whitespace_only145=== PAUSE TestParsePathInfoJSON/whitespace_only146=== RUN TestParsePathInfoJSON/invalid_JSON147=== PAUSE TestParsePathInfoJSON/invalid_JSON148=== CONT TestConvertHashToNix32149=== RUN TestConvertHashToNix32/SRI_format_to_Nix32150=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32151=== RUN TestConvertHashToNix32/already_Nix32_format152=== CONT TestPathInfoHashCompatibility153=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)154=== PAUSE TestUploadMultipart_SupersededByPeer/exists155=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)156=== PAUSE TestConvertHashToNix32/already_Nix32_format157=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon158=== RUN TestConvertHashToNix32/invalid_format159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon160=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI161=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI162=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512163=== PAUSE TestConvertHashToNix32/invalid_format164=== CONT TestDumpPathWriterError165=== CONT TestDumpPathSingleFile166=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter167=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter168=== CONT TestEncodeNixBase32169=== RUN TestEncodeNixBase32/test_string_hash170=== PAUSE TestEncodeNixBase32/test_string_hash171=== CONT TestScriptTokenCachesUntilRefresh172=== RUN TestUploadMultipart_SupersededByPeer/missing173=== PAUSE TestUploadMultipart_SupersededByPeer/missing174=== RUN TestEncodeNixBase32/empty_input175=== PAUSE TestEncodeNixBase32/empty_input176=== CONT TestScriptTokenEmptyCommand177--- PASS: TestScriptTokenEmptyCommand (0.00s)178=== CONT TestScriptTokenBadJSON179=== CONT TestScriptTokenScriptFails180=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512181=== CONT TestScriptTokenEmptyToken1822026/10/01 10:03:44 WARN Rate limiter enabled after throttle name=server-test rate=51832026/10/01 10:03:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57724184--- PASS: TestDoServerRequestAttachesToken (0.00s)185=== CONT TestFileTokenMissing1862026/10/01 10:03:44 WARN Rate limiter backed off name=server-test rate=51872026/10/01 10:03:44 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57724188--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)189=== CONT TestScriptTokenNoExpiryRerunsEveryCall190--- PASS: TestScriptTokenScriptFails (0.00s)191=== CONT TestFileTokenEmpty192--- PASS: TestFileTokenMissing (0.01s)193=== CONT TestFileTokenReadsAndCaches194--- PASS: TestScriptTokenEmptyToken (0.03s)195=== CONT TestDumpPathMatchesNix196--- PASS: TestScriptTokenBadJSON (0.03s)197=== CONT TestFilterOversizedClosures198--- PASS: TestFileTokenEmpty (0.03s)199=== CONT TestPartSizeForNAR200=== RUN TestFilterOversizedClosures/no_limit_keeps_everything201=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything202=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped203=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped204=== RUN TestFilterOversizedClosures/all_closures_skipped205=== PAUSE TestFilterOversizedClosures/all_closures_skipped206=== CONT TestUploadMultipart_PartsInParallel207=== RUN TestPartSizeForNAR/zero_stays_at_minimum208=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum209=== RUN TestPartSizeForNAR/small_stays_at_minimum210=== PAUSE TestPartSizeForNAR/small_stays_at_minimum211=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum212=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum213=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts214=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts215=== RUN TestPartSizeForNAR/1_TiB216=== PAUSE TestPartSizeForNAR/1_TiB217=== RUN TestPartSizeForNAR/5_TiB_S3_max_object218=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object219=== RUN TestPartSizeForNAR/capped_at_5_GiB220=== PAUSE TestPartSizeForNAR/capped_at_5_GiB221=== CONT TestCaseHackSuffix222--- PASS: TestResolveStorePath (0.03s)223=== CONT TestRegisterUploadedObjectReusesConnections224--- PASS: TestFileTokenReadsAndCaches (0.02s)225=== CONT TestStaticToken226--- PASS: TestStaticToken (0.00s)227=== CONT TestStreamPushRequestLine2282026/10/01 10:03:44 ERROR Upload failed error=boom count=1229--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)230=== CONT TestSetClientTLSDoesNotMutateDefaultTransport231--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)232=== CONT TestSetClientTLS233--- PASS: TestStreamPushRequestLine (0.01s)234=== CONT TestClientSignaturesByStorePath235--- PASS: TestClientSignaturesByStorePath (0.00s)236=== CONT TestStreamPushReportsSignatures2372026/10/01 10:03:44 ERROR Upload failed error=boom count=1238--- PASS: TestStreamPushReportsSignatures (0.00s)239=== CONT TestStreamPushBatchesUnderLoad240=== RUN TestSetClientTLS/rejects_connection_without_client_cert241=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert242=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA243=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA244=== RUN TestSetClientTLS/preserves_debug_logging_transport245=== PAUSE TestSetClientTLS/preserves_debug_logging_transport246=== CONT TestStreamPushGivesUpOnDeadServer2472026/10/01 10:03:44 ERROR Upload failed error="connection refused" count=202482026/10/01 10:03:44 ERROR Server seems unavailable, giving up on batch untried=17249--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)250=== CONT TestStreamPushIsolatesFailures2512026/10/01 10:03:44 ERROR Upload failed error="bad path" count=3252--- PASS: TestStreamPushIsolatesFailures (0.00s)253=== CONT TestStreamPushReportsEveryPath254--- PASS: TestStreamPushReportsEveryPath (0.00s)255=== CONT TestShellSplitErrors256--- PASS: TestShellSplitErrors (0.00s)257=== CONT TestSetClientTLSErrors258=== RUN TestSetClientTLSErrors/missing_cert_file259=== PAUSE TestSetClientTLSErrors/missing_cert_file260=== RUN TestSetClientTLSErrors/missing_key_file261=== PAUSE TestSetClientTLSErrors/missing_key_file262=== RUN TestSetClientTLSErrors/missing_ca_file263=== PAUSE TestSetClientTLSErrors/missing_ca_file264=== RUN TestSetClientTLSErrors/invalid_ca_file265=== PAUSE TestSetClientTLSErrors/invalid_ca_file266=== CONT TestPathInfoCACompatibility/null_ca_field267=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths268=== CONT TestGetStorePathHash/valid_store_path269=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method270=== CONT TestPathInfoCACompatibility/new_structured_format_-_text271=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive272=== CONT TestPathInfoCACompatibility/old_string_format_-_text273--- PASS: TestPathInfoCACompatibility (0.00s)274 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)275 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)276 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)277 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)278 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)279=== CONT TestParsePathInfoJSON/Nix_format280=== CONT TestParsePathInfoJSON/invalid_JSON281=== CONT TestParsePathInfoJSON/whitespace_only282=== CONT TestParsePathInfoJSON/empty_input283=== CONT TestParsePathInfoJSON/Lix_format284--- PASS: TestParsePathInfoJSON (0.00s)285 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)286 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)287 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)288 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)289 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)290=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error291=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths292--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)293 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)294 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)295=== CONT TestGetStorePathHash/basename_without_hyphen_should_error296=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error297--- PASS: TestGetStorePathHash (0.00s)298 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)299 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)300 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)301 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)302=== CONT TestConvertHashToNix32/SRI_format_to_Nix32303=== CONT TestConvertHashToNix32/invalid_format304=== CONT TestConvertHashToNix32/already_Nix32_format305--- PASS: TestConvertHashToNix32 (0.00s)306 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)307 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)308 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)309=== CONT TestRateLimiterFeedback/429_enables_limiter3102026/10/01 10:03:44 WARN Rate limiter enabled after throttle name=server-test rate=53112026/10/01 10:03:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:577993122026/10/01 10:03:44 WARN Rate limiter backed off name=server-test rate=5313=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter314=== CONT TestRateLimiterFeedback/503_enables_limiter3152026/10/01 10:03:44 WARN Rate limiter enabled after throttle name=server-test rate=53162026/10/01 10:03:44 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:578033172026/10/01 10:03:44 WARN Rate limiter backed off name=server-test rate=5318=== CONT TestUploadMultipart_SupersededByPeer/exists319--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)320=== CONT TestEncodeNixBase32/test_string_hash321=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter322--- PASS: TestRateLimiterFeedback (0.00s)323 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)325 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)326 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)327=== CONT TestEncodeNixBase32/empty_input328--- PASS: TestEncodeNixBase32 (0.00s)329 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)330 --- PASS: TestEncodeNixBase32/empty_input (0.00s)331=== CONT TestUploadMultipart_SupersededByPeer/missing332=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)333--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)334 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)335 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)336=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512337=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI338=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon339=== CONT TestFilterOversizedClosures/no_limit_keeps_everything340=== CONT TestFilterOversizedClosures/all_closures_skipped341=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3422026/10/01 10:03:44 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=2000343--- PASS: TestPathInfoHashCompatibility (0.00s)344 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)345 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)346 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)347 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)3482026/10/01 10:03:44 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50349=== CONT TestPartSizeForNAR/zero_stays_at_minimum350--- PASS: TestFilterOversizedClosures (0.00s)351 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)352 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)353 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)354=== CONT TestPartSizeForNAR/capped_at_5_GiB355=== CONT TestPartSizeForNAR/5_TiB_S3_max_object356=== CONT TestPartSizeForNAR/1_TiB357=== CONT TestPartSizeForNAR/small_stays_at_minimum358=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts359=== CONT TestSetClientTLS/rejects_connection_without_client_cert360=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum361--- PASS: TestPartSizeForNAR (0.00s)362 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)364 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)365 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)366 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)368 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)369=== CONT TestSetClientTLS/preserves_debug_logging_transport370=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA371=== CONT TestSetClientTLSErrors/missing_cert_file372=== CONT TestSetClientTLSErrors/invalid_ca_file373=== CONT TestSetClientTLSErrors/missing_ca_file374=== CONT TestSetClientTLSErrors/missing_key_file3752026/10/01 10:03:44 http: TLS handshake error from 127.0.0.1:57811: remote error: tls: bad certificate376--- PASS: TestDumpPathSingleFile (0.08s)377--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.08s)378--- PASS: TestSetClientTLSErrors (0.01s)379 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)380 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)381 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)382 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)383--- PASS: TestSetClientTLS (0.02s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestCaseHackSuffix (0.07s)388--- PASS: TestStreamPushBatchesUnderLoad (0.10s)389--- PASS: TestDumpPathMatchesNix (0.18s)390--- PASS: TestDumpPathWriterError (0.22s)391--- PASS: TestUploadMultipart_PartsInParallel (0.62s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld10".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-7135-908923472/postgres2239580999/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: 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.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-7135-908923472/postgres2239580999/data -l logfile start421422/nix/var/nix/builds/nix-7135-908923472/postgres2239580999:5432 - no response4232026-10-01 10:03:50.529 UTC [7457] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 10:03:50.533 UTC [7457] LOG: listening on Unix socket "/nix/var/nix/builds/nix-7135-908923472/postgres2239580999/.s.PGSQL.5432"4252026-10-01 10:03:50.554 UTC [7465] LOG: database system was shut down at 2026-10-01 10:03:50 UTC4262026-10-01 10:03:50.558 UTC [7457] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-7135-908923472/postgres2239580999:5432 - accepting connections428{"timestamp":"2026-10-01T10:03:50.787Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"38b83e90-54fe-4d59-9cf8-4178e0947302","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}429{"timestamp":"2026-10-01T10:03:50.890585Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8f91b060-248c-4145-a91e-41ad14ccbe68","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}430{"timestamp":"2026-10-01T10:03:50.994173Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"5ff94e0c-dcae-4262-a473-1a20c4a1cc58","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}431{"timestamp":"2026-10-01T10:03:51.097669Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"5ac0fd20-e58d-4c53-a5ee-f84932074a64","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}432=== RUN TestService_AuthMiddleware433=== PAUSE TestService_AuthMiddleware434=== RUN TestService_AuthMiddleware_MTLSProxyHeader435=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader436=== RUN TestService_AuthMiddleware_MTLSBoundSubjects437=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects438=== RUN TestService_ReadAuthMiddleware439=== PAUSE TestService_ReadAuthMiddleware440=== RUN TestService_AuthMiddleware_OIDC441=== PAUSE TestService_AuthMiddleware_OIDC442=== RUN TestService_RequireScope_OIDC443=== PAUSE TestService_RequireScope_OIDC444=== RUN TestService_ReadScope_PublicByDefault445=== PAUSE TestService_ReadScope_PublicByDefault446=== RUN TestCacheConfigHandler447=== PAUSE TestCacheConfigHandler448=== RUN TestCacheStatsHandler449=== PAUSE TestCacheStatsHandler450=== RUN TestClientCADerivations451=== PAUSE TestClientCADerivations452=== RUN TestClientErrorHandling453=== PAUSE TestClientErrorHandling454=== RUN TestClientIntegration455=== PAUSE TestClientIntegration456=== RUN TestClientMultipleUploads457=== PAUSE TestClientMultipleUploads458=== RUN TestClientWithDependencies459=== PAUSE TestClientWithDependencies460=== RUN TestClientSharedPathCommittedMidPush461=== PAUSE TestClientSharedPathCommittedMidPush462=== RUN TestPinProtectsFromGC463=== PAUSE TestPinProtectsFromGC464=== RUN TestClientPushesUseOnePush465=== PAUSE TestClientPushesUseOnePush466=== RUN TestClientFallsBackToClosures467=== PAUSE TestClientFallsBackToClosures468=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock469=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock470=== RUN TestResolveDBConnectionString471=== PAUSE TestResolveDBConnectionString472=== RUN TestLeadElectsOneAndHandsOver473=== PAUSE TestLeadElectsOneAndHandsOver474=== RUN TestLeadIncumbentWinsAfterRestart4752026-10-01 10:03:53.761 UTC [7552] ERROR: relation "goose_db_version" does not exist at character 364762026-10-01 10:03:53.761 UTC [7552] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4772026/10/01 10:03:53 OK 20241026095416_initial_model.sql (101.36ms)4782026/10/01 10:03:53 OK 20251210153512_drop_unused_gin_index.sql (8.5ms)4792026/10/01 10:03:53 OK 20251218171726_add_pins.sql (19.88ms)4802026/10/01 10:03:53 OK 20260628120000_add_object_size_and_stats.sql (11.78ms)4812026/10/01 10:03:53 OK 20260905000000_add_claims.sql (4.25ms)4822026/10/01 10:03:53 OK 20260920000000_drop_claims.sql (1.61ms)4832026/10/01 10:03:53 OK 20260923120000_add_pushes.sql (1.99ms)4842026/10/01 10:03:53 goose: successfully migrated database to version: 202609231200004852026/10/01 10:03:53 OK 1_commit_pending_closure.sql (1.91ms)4862026/10/01 10:03:53 OK 2_object_stats_trigger.sql (592.29µs)4872026/10/01 10:03:53 OK 3_commit_push.sql (317.58µs)4882026/10/01 10:03:53 goose: up to current file version: 34892026/10/01 10:03:54 INFO lead: acquired remote=192.0.2.1:12344902026/10/01 10:03:54 INFO lead: released remote=192.0.2.1:12344912026/10/01 10:03:54 INFO lead: acquired remote=192.0.2.1:12344922026/10/01 10:03:54 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (3.64s)494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestGCAdvisoryLockBlocksConcurrentRun4972026-10-01 10:03:55.524 UTC [7583] ERROR: relation "goose_db_version" does not exist at character 364982026-10-01 10:03:55.524 UTC [7583] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4992026/10/01 10:03:55 OK 20241026095416_initial_model.sql (112.69ms)5002026/10/01 10:03:55 OK 20251210153512_drop_unused_gin_index.sql (12.11ms)5012026/10/01 10:03:55 OK 20251218171726_add_pins.sql (15.41ms)5022026/10/01 10:03:55 OK 20260628120000_add_object_size_and_stats.sql (8.21ms)5032026/10/01 10:03:55 OK 20260905000000_add_claims.sql (6.55ms)5042026/10/01 10:03:55 OK 20260920000000_drop_claims.sql (33.38ms)5052026/10/01 10:03:55 OK 20260923120000_add_pushes.sql (17.33ms)5062026/10/01 10:03:55 goose: successfully migrated database to version: 202609231200005072026/10/01 10:03:55 OK 1_commit_pending_closure.sql (929.92µs)5082026/10/01 10:03:55 OK 2_object_stats_trigger.sql (204.5µs)5092026/10/01 10:03:55 OK 3_commit_push.sql (175.75µs)5102026/10/01 10:03:55 goose: up to current file version: 3511--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.21s)512=== RUN TestGCBugBareHashReferences513=== PAUSE TestGCBugBareHashReferences514=== RUN TestGCMetrics515=== PAUSE TestGCMetrics516=== RUN TestPushDedupSurvivesConcurrentGC517=== PAUSE TestPushDedupSurvivesConcurrentGC518=== RUN TestDeduplicatedObjectsRecordedAsPending519=== PAUSE TestDeduplicatedObjectsRecordedAsPending520=== RUN TestGCSweepSkipsPendingObjects521=== PAUSE TestGCSweepSkipsPendingObjects522=== RUN TestTombstonedObjectOfferedWithoutWaiting523=== PAUSE TestTombstonedObjectOfferedWithoutWaiting524=== RUN TestGCSweepDeliversEachKeyOnce525=== PAUSE TestGCSweepDeliversEachKeyOnce526=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection527=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection528=== RUN TestForceGCDuringPushOffersSweptObject529=== PAUSE TestForceGCDuringPushOffersSweptObject530=== RUN TestFailedS3DeleteKeepsTombstone531=== PAUSE TestFailedS3DeleteKeepsTombstone532=== RUN TestSweepSkipsRowsLockedByPush533=== PAUSE TestSweepSkipsRowsLockedByPush534=== RUN TestRegisterCompletedObjectNeedsPendingRow535=== PAUSE TestRegisterCompletedObjectNeedsPendingRow536=== RUN TestGetExistingObjectsLocksRows537=== PAUSE TestGetExistingObjectsLocksRows538=== RUN TestSweepRechecksPendingAfterLocking539=== PAUSE TestSweepRechecksPendingAfterLocking540=== RUN TestPushWaitsForSweepHoldingRow541=== PAUSE TestPushWaitsForSweepHoldingRow542=== RUN TestCommitRacingPendingCleanupKeepsObjects543=== PAUSE TestCommitRacingPendingCleanupKeepsObjects544=== RUN TestGCEndsOnShutdown545=== PAUSE TestGCEndsOnShutdown546=== RUN TestGCTaskStore_StartNew547=== PAUSE TestGCTaskStore_StartNew548=== RUN TestGCTaskStore_DeduplicateSameParams549=== PAUSE TestGCTaskStore_DeduplicateSameParams550=== RUN TestGCTaskStore_ConflictDifferentParams551=== PAUSE TestGCTaskStore_ConflictDifferentParams552=== RUN TestGCTaskStore_GetEmpty553=== PAUSE TestGCTaskStore_GetEmpty554=== RUN TestGCTaskStore_GetReturnsLatest555=== PAUSE TestGCTaskStore_GetReturnsLatest556=== RUN TestGCTaskStore_CompletedAllowsNewTask557=== PAUSE TestGCTaskStore_CompletedAllowsNewTask558=== RUN TestGCTaskStore_PhaseUpdates559=== PAUSE TestGCTaskStore_PhaseUpdates560=== RUN TestGCTaskStore_Fail561=== PAUSE TestGCTaskStore_Fail562=== RUN TestGracefulShutdownDrainsInflight563=== PAUSE TestGracefulShutdownDrainsInflight564=== RUN TestService_healthCheckHandler565=== PAUSE TestService_healthCheckHandler566=== RUN TestService_readinessHandler567=== PAUSE TestService_readinessHandler568=== RUN TestGenerateLandingPage569=== PAUSE TestGenerateLandingPage570=== RUN TestCacheConfigHandlerMaxNarSize571=== PAUSE TestCacheConfigHandlerMaxNarSize572=== RUN TestCreatePendingClosureRejectsOversizedNAR573=== PAUSE TestCreatePendingClosureRejectsOversizedNAR574=== RUN TestNARDeduplicationMetadataUploadBug575=== PAUSE TestNARDeduplicationMetadataUploadBug576=== RUN TestMetricsInventory577=== PAUSE TestMetricsInventory578=== RUN TestService_NativeMTLS579=== PAUSE TestService_NativeMTLS580=== RUN TestServerTLSConfig581=== PAUSE TestServerTLSConfig582=== RUN TestMultipartCleanup583=== PAUSE TestMultipartCleanup584=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded585=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded586=== RUN TestPendingCleanupUsesOneCutoff587=== PAUSE TestPendingCleanupUsesOneCutoff588=== RUN TestObjectStatsTrigger589=== PAUSE TestObjectStatsTrigger590=== RUN TestOrphanedObjectsGC591=== PAUSE TestOrphanedObjectsGC592=== RUN TestOrphanedObjectsGCStressTest593=== PAUSE TestOrphanedObjectsGCStressTest594=== RUN TestCreatePin_ReservedPins595=== PAUSE TestCreatePin_ReservedPins596=== RUN TestPresentReportsOnlyClosureRoots597=== PAUSE TestPresentReportsOnlyClosureRoots598=== RUN TestPresentNotReportedWhileGCDeletesClosure599=== PAUSE TestPresentNotReportedWhileGCDeletesClosure600=== RUN TestParseSingleRange601=== PAUSE TestParseSingleRange602=== RUN TestProxyHeadersOnlyTrustedOnSocket603=== PAUSE TestProxyHeadersOnlyTrustedOnSocket604=== RUN TestIsValidCachePath605=== PAUSE TestIsValidCachePath606=== RUN TestReadProxyNarinfo607=== PAUSE TestReadProxyNarinfo608=== RUN TestReadProxyNarinfoAlreadyDecompressed609=== PAUSE TestReadProxyNarinfoAlreadyDecompressed610=== RUN TestReadProxyNarStreaming611=== PAUSE TestReadProxyNarStreaming612=== RUN TestReadProxy404613=== PAUSE TestReadProxy404614=== RUN TestReadProxyInvalidPath615=== PAUSE TestReadProxyInvalidPath616=== RUN TestReadProxyHead617=== PAUSE TestReadProxyHead618=== RUN TestReadProxyConditionalGet619=== PAUSE TestReadProxyConditionalGet620=== RUN TestReadProxyRootRedirectsToIndexHTML621=== PAUSE TestReadProxyRootRedirectsToIndexHTML622=== RUN TestReadProxyDisabled623=== PAUSE TestReadProxyDisabled624=== RUN TestReadRedirectNar625=== PAUSE TestReadRedirectNar626=== RUN TestReadRedirectKeepsNarinfoProxied627=== PAUSE TestReadRedirectKeepsNarinfoProxied628=== RUN TestReadProxyRangeRequest629=== PAUSE TestReadProxyRangeRequest630=== RUN TestReadRedirectUsesPublicS3URL631=== PAUSE TestReadRedirectUsesPublicS3URL632=== RUN TestPush_OverlappingRootsStoreOneRowPerKey633=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey634=== RUN TestPush_CompleteCommitsEveryRoot635=== PAUSE TestPush_CompleteCommitsEveryRoot636=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit637=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit638=== RUN TestPush_RejectsBadRequests639=== PAUSE TestPush_RejectsBadRequests640=== RUN TestPush_SignsNarinfosOfItsPendingObjects641=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects642=== RUN TestRedundantMultipartUpload643=== PAUSE TestRedundantMultipartUpload644=== RUN TestCompleteMultipartUpload_ErrorButObjectExists645=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists646=== RUN TestCompletedNarNotReofferedAcrossClosures647=== PAUSE TestCompletedNarNotReofferedAcrossClosures648=== RUN TestPresignedUploadRegisteredBeforeCommit649=== PAUSE TestPresignedUploadRegisteredBeforeCommit650=== RUN TestService_Rustfstest651=== PAUSE TestService_Rustfstest652=== RUN TestParseSize653=== PAUSE TestParseSize654=== RUN TestSkippedUploadsHandler655=== PAUSE TestSkippedUploadsHandler656=== RUN TestSystemdListenerNotActivated657--- PASS: TestSystemdListenerNotActivated (0.00s)658=== RUN TestWatchdogBeatsWhenHealthy659--- PASS: TestWatchdogBeatsWhenHealthy (0.04s)660=== RUN TestWatchdogSkipsWhenUnhealthy6612026/10/01 10:03:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 10:03:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 10:03:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/01 10:03:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/01 10:03:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/01 10:03:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/01 10:03:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/01 10:03:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/01 10:03:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/01 10:03:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"671--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)672=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle673=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle674=== RUN TestProxyWriteTimeout675=== PAUSE TestProxyWriteTimeout676=== RUN TestIsValidUploadKey677=== PAUSE TestIsValidUploadKey678=== RUN TestUploadHandlersRejectInvalidKeys679=== PAUSE TestUploadHandlersRejectInvalidKeys680=== RUN TestUploadHandlersRejectOversizedBody681=== PAUSE TestUploadHandlersRejectOversizedBody682=== RUN TestService_cleanupPendingClosuresHandler683=== PAUSE TestService_cleanupPendingClosuresHandler684=== RUN TestService_createPendingClosureHandler685=== PAUSE TestService_createPendingClosureHandler686=== RUN TestService_verifyS3Integrity687=== PAUSE TestService_verifyS3Integrity688=== RUN TestCompleteMultipartUnregistered689=== PAUSE TestCompleteMultipartUnregistered690=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT691=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT692=== CONT TestService_AuthMiddleware693=== CONT TestCreatePendingClosureRejectsOversizedNAR694=== CONT TestGCSweepSkipsPendingObjects695=== CONT TestClientWithDependencies696=== CONT TestCacheConfigHandlerMaxNarSize6972026/10/01 10:03:56 INFO Received uploads request method=POST path=/api/pending_closures698=== CONT TestCacheConfigHandler699=== CONT TestReadRedirectNar700=== RUN TestCacheConfigHandler/full_config,_no_issuer701--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)702--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)703=== CONT TestGenerateLandingPage704=== PAUSE TestCacheConfigHandler/full_config,_no_issuer705=== RUN TestCacheConfigHandler/no_cache_url_configured706=== PAUSE TestCacheConfigHandler/no_cache_url_configured707=== RUN TestCacheConfigHandler/no_signing_keys708=== PAUSE TestCacheConfigHandler/no_signing_keys709=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator710=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator711=== CONT TestGracefulShutdownDrainsInflight712=== CONT TestService_readinessHandler713=== CONT TestReadProxyDisabled714=== CONT TestService_healthCheckHandler715=== CONT TestReadProxyRootRedirectsToIndexHTML7162026/10/01 10:03:56 INFO Starting HTTP server address=127.0.0.1:579957172026/10/01 10:03:56 INFO Shutdown signal received, draining in-flight requests timeout=10s718--- PASS: TestGenerateLandingPage (0.00s)719=== CONT TestReadProxyConditionalGet720--- PASS: TestGracefulShutdownDrainsInflight (0.08s)721=== CONT TestGCTaskStore_Fail722--- PASS: TestGCTaskStore_Fail (0.00s)723=== CONT TestReadProxyHead7242026-10-01 10:03:59.134 UTC [7633] ERROR: relation "goose_db_version" does not exist at character 367252026-10-01 10:03:59.134 UTC [7633] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026-10-01 10:03:59.203 UTC [7638] ERROR: relation "goose_db_version" does not exist at character 367272026-10-01 10:03:59.203 UTC [7638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7282026-10-01 10:03:59.212 UTC [7635] ERROR: relation "goose_db_version" does not exist at character 367292026-10-01 10:03:59.212 UTC [7635] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7302026-10-01 10:03:59.214 UTC [7634] ERROR: relation "goose_db_version" does not exist at character 367312026-10-01 10:03:59.214 UTC [7634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7322026-10-01 10:03:59.223 UTC [7642] ERROR: relation "goose_db_version" does not exist at character 367332026-10-01 10:03:59.223 UTC [7642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7342026-10-01 10:03:59.225 UTC [7641] ERROR: relation "goose_db_version" does not exist at character 367352026-10-01 10:03:59.225 UTC [7641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7362026-10-01 10:03:59.243 UTC [7640] ERROR: relation "goose_db_version" does not exist at character 367372026-10-01 10:03:59.243 UTC [7640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7382026-10-01 10:03:59.247 UTC [7637] ERROR: relation "goose_db_version" does not exist at character 367392026-10-01 10:03:59.247 UTC [7637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7402026-10-01 10:03:59.261 UTC [7639] ERROR: relation "goose_db_version" does not exist at character 367412026-10-01 10:03:59.261 UTC [7639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7422026-10-01 10:03:59.261 UTC [7636] ERROR: relation "goose_db_version" does not exist at character 367432026-10-01 10:03:59.261 UTC [7636] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7442026/10/01 10:03:59 OK 20241026095416_initial_model.sql (161.15ms)7452026/10/01 10:03:59 OK 20251210153512_drop_unused_gin_index.sql (11.17ms)7462026/10/01 10:03:59 OK 20241026095416_initial_model.sql (109.57ms)7472026/10/01 10:03:59 OK 20251218171726_add_pins.sql (9.72ms)7482026/10/01 10:03:59 OK 20241026095416_initial_model.sql (96.61ms)7492026/10/01 10:03:59 OK 20241026095416_initial_model.sql (69.3ms)7502026/10/01 10:03:59 OK 20241026095416_initial_model.sql (82.4ms)7512026/10/01 10:03:59 OK 20251210153512_drop_unused_gin_index.sql (12.41ms)7522026/10/01 10:03:59 OK 20251210153512_drop_unused_gin_index.sql (12.06ms)7532026/10/01 10:03:59 OK 20251210153512_drop_unused_gin_index.sql (12.42ms)7542026/10/01 10:03:59 OK 20251210153512_drop_unused_gin_index.sql (15.14ms)7552026/10/01 10:03:59 OK 20241026095416_initial_model.sql (107.55ms)7562026/10/01 10:03:59 OK 20241026095416_initial_model.sql (96.64ms)7572026/10/01 10:03:59 OK 20251218171726_add_pins.sql (13.32ms)7582026/10/01 10:03:59 OK 20260628120000_add_object_size_and_stats.sql (39.31ms)7592026/10/01 10:03:59 OK 20251210153512_drop_unused_gin_index.sql (13.43ms)7602026/10/01 10:03:59 OK 20241026095416_initial_model.sql (121.42ms)7612026/10/01 10:03:59 OK 20241026095416_initial_model.sql (121.48ms)7622026/10/01 10:03:59 OK 20251218171726_add_pins.sql (27.05ms)7632026/10/01 10:03:59 OK 20251218171726_add_pins.sql (27.06ms)7642026/10/01 10:03:59 OK 20251218171726_add_pins.sql (37.75ms)7652026/10/01 10:03:59 OK 20251210153512_drop_unused_gin_index.sql (31.32ms)7662026/10/01 10:03:59 OK 20251210153512_drop_unused_gin_index.sql (26.55ms)7672026/10/01 10:03:59 OK 20251210153512_drop_unused_gin_index.sql (26.64ms)7682026/10/01 10:03:59 OK 20260628120000_add_object_size_and_stats.sql (42.88ms)7692026/10/01 10:03:59 OK 20260628120000_add_object_size_and_stats.sql (29.28ms)7702026/10/01 10:03:59 OK 20241026095416_initial_model.sql (139.93ms)7712026/10/01 10:03:59 OK 20251218171726_add_pins.sql (29.73ms)7722026/10/01 10:03:59 OK 20260628120000_add_object_size_and_stats.sql (21.4ms)7732026/10/01 10:03:59 OK 20260628120000_add_object_size_and_stats.sql (32.17ms)7742026/10/01 10:03:59 OK 20251210153512_drop_unused_gin_index.sql (10.22ms)7752026/10/01 10:03:59 OK 20251218171726_add_pins.sql (30.72ms)7762026/10/01 10:03:59 OK 20251218171726_add_pins.sql (41.92ms)7772026/10/01 10:03:59 OK 20260905000000_add_claims.sql (39.92ms)7782026/10/01 10:03:59 OK 20260628120000_add_object_size_and_stats.sql (39.82ms)7792026/10/01 10:03:59 OK 20251218171726_add_pins.sql (42.11ms)7802026/10/01 10:03:59 OK 20251218171726_add_pins.sql (29.6ms)7812026/10/01 10:03:59 OK 20260628120000_add_object_size_and_stats.sql (32.15ms)7822026/10/01 10:03:59 OK 20260905000000_add_claims.sql (80.73ms)7832026/10/01 10:03:59 OK 20260628120000_add_object_size_and_stats.sql (28.98ms)7842026/10/01 10:03:59 OK 20260905000000_add_claims.sql (66.22ms)7852026/10/01 10:03:59 OK 20260920000000_drop_claims.sql (27.06ms)7862026/10/01 10:03:59 OK 20260920000000_drop_claims.sql (39.96ms)7872026/10/01 10:03:59 OK 20260905000000_add_claims.sql (81.2ms)7882026/10/01 10:03:59 OK 20260628120000_add_object_size_and_stats.sql (41.46ms)7892026/10/01 10:03:59 OK 20260905000000_add_claims.sql (79.06ms)7902026/10/01 10:03:59 OK 20260628120000_add_object_size_and_stats.sql (42.08ms)7912026/10/01 10:03:59 OK 20260905000000_add_claims.sql (51.49ms)7922026/10/01 10:03:59 OK 20260923120000_add_pushes.sql (13.98ms)7932026/10/01 10:03:59 goose: successfully migrated database to version: 202609231200007942026/10/01 10:03:59 OK 20260905000000_add_claims.sql (41.25ms)7952026/10/01 10:03:59 OK 20260923120000_add_pushes.sql (12.38ms)7962026/10/01 10:03:59 goose: successfully migrated database to version: 202609231200007972026/10/01 10:03:59 OK 1_commit_pending_closure.sql (3.41ms)7982026/10/01 10:03:59 OK 1_commit_pending_closure.sql (3.3ms)7992026/10/01 10:03:59 OK 2_object_stats_trigger.sql (622.42µs)8002026/10/01 10:03:59 OK 2_object_stats_trigger.sql (615.46µs)8012026/10/01 10:03:59 OK 3_commit_push.sql (428.63µs)8022026/10/01 10:03:59 goose: up to current file version: 38032026/10/01 10:03:59 OK 3_commit_push.sql (439.96µs)8042026/10/01 10:03:59 goose: up to current file version: 38052026/10/01 10:03:59 OK 20260920000000_drop_claims.sql (50.43ms)8062026/10/01 10:03:59 OK 20260920000000_drop_claims.sql (64.8ms)8072026/10/01 10:03:59 OK 20260923120000_add_pushes.sql (29.72ms)8082026/10/01 10:03:59 goose: successfully migrated database to version: 202609231200008092026/10/01 10:03:59 OK 1_commit_pending_closure.sql (3.2ms)8102026/10/01 10:03:59 OK 2_object_stats_trigger.sql (716.83µs)8112026/10/01 10:03:59 OK 3_commit_push.sql (570.88µs)8122026/10/01 10:03:59 goose: up to current file version: 38132026/10/01 10:03:59 OK 20260920000000_drop_claims.sql (72.6ms)8142026/10/01 10:03:59 OK 20260920000000_drop_claims.sql (82.17ms)8152026/10/01 10:03:59 OK 20260920000000_drop_claims.sql (71.86ms)8162026/10/01 10:03:59 OK 20260905000000_add_claims.sql (95.61ms)8172026/10/01 10:03:59 OK 20260923120000_add_pushes.sql (29.87ms)8182026/10/01 10:03:59 goose: successfully migrated database to version: 202609231200008192026/10/01 10:03:59 OK 1_commit_pending_closure.sql (3.62ms)8202026/10/01 10:03:59 OK 2_object_stats_trigger.sql (705.54µs)8212026/10/01 10:03:59 OK 3_commit_push.sql (447µs)8222026/10/01 10:03:59 goose: up to current file version: 38232026/10/01 10:03:59 OK 20260923120000_add_pushes.sql (28.19ms)8242026/10/01 10:03:59 goose: successfully migrated database to version: 202609231200008252026/10/01 10:03:59 OK 1_commit_pending_closure.sql (2.64ms)8262026/10/01 10:03:59 OK 2_object_stats_trigger.sql (599.13µs)8272026/10/01 10:03:59 OK 3_commit_push.sql (474.38µs)8282026/10/01 10:03:59 goose: up to current file version: 38292026/10/01 10:03:59 OK 20260923120000_add_pushes.sql (34.97ms)8302026/10/01 10:03:59 goose: successfully migrated database to version: 202609231200008312026/10/01 10:03:59 OK 20260923120000_add_pushes.sql (35.09ms)8322026/10/01 10:03:59 goose: successfully migrated database to version: 202609231200008332026/10/01 10:03:59 OK 1_commit_pending_closure.sql (2.18ms)8342026/10/01 10:03:59 OK 1_commit_pending_closure.sql (2.22ms)8352026/10/01 10:03:59 OK 2_object_stats_trigger.sql (535.75µs)8362026/10/01 10:03:59 OK 2_object_stats_trigger.sql (543.29µs)8372026/10/01 10:03:59 OK 3_commit_push.sql (343.63µs)8382026/10/01 10:03:59 goose: up to current file version: 38392026/10/01 10:03:59 OK 3_commit_push.sql (368.58µs)8402026/10/01 10:03:59 goose: up to current file version: 38412026/10/01 10:03:59 OK 20260905000000_add_claims.sql (123.61ms)8422026/10/01 10:03:59 OK 20260905000000_add_claims.sql (140.62ms)8432026/10/01 10:03:59 OK 20260920000000_drop_claims.sql (94.07ms)8442026/10/01 10:03:59 OK 20260923120000_add_pushes.sql (22.18ms)8452026/10/01 10:03:59 goose: successfully migrated database to version: 202609231200008462026/10/01 10:03:59 OK 1_commit_pending_closure.sql (2.68ms)8472026/10/01 10:03:59 OK 2_object_stats_trigger.sql (533.25µs)8482026/10/01 10:03:59 OK 3_commit_push.sql (329.71µs)8492026/10/01 10:03:59 goose: up to current file version: 38502026/10/01 10:03:59 OK 20260920000000_drop_claims.sql (82ms)8512026/10/01 10:03:59 OK 20260920000000_drop_claims.sql (89.25ms)8522026/10/01 10:03:59 OK 20260923120000_add_pushes.sql (24.76ms)8532026/10/01 10:03:59 goose: successfully migrated database to version: 202609231200008542026/10/01 10:03:59 OK 1_commit_pending_closure.sql (3.1ms)8552026/10/01 10:03:59 OK 2_object_stats_trigger.sql (561.67µs)8562026/10/01 10:03:59 OK 3_commit_push.sql (359.33µs)8572026/10/01 10:03:59 goose: up to current file version: 38582026/10/01 10:03:59 OK 20260923120000_add_pushes.sql (36.78ms)8592026/10/01 10:03:59 goose: successfully migrated database to version: 202609231200008602026/10/01 10:03:59 OK 1_commit_pending_closure.sql (3.12ms)8612026/10/01 10:03:59 OK 2_object_stats_trigger.sql (721.04µs)8622026/10/01 10:03:59 OK 3_commit_push.sql (522.21µs)8632026/10/01 10:03:59 goose: up to current file version: 3864--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.68s)865=== CONT TestGCTaskStore_PhaseUpdates866--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)867=== CONT TestReadProxyInvalidPath868--- PASS: TestReadRedirectNar (4.09s)869=== CONT TestGCTaskStore_CompletedAllowsNewTask870--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)871=== CONT TestReadProxy4048722026/10/01 10:04:01 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"873--- PASS: TestService_AuthMiddleware (4.94s)874=== CONT TestGCTaskStore_GetReturnsLatest875--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)876=== CONT TestReadProxyNarStreaming877=== NAME TestClientWithDependencies878 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-7135-908923472/TestClientWithDependencies437338419/001/store/a0lf0pmybkbpz2vb5m9ms942jp8i3i3g-test-script879 client_integration_test.go:615: Found 1 dependencies (including self)880--- PASS: TestService_healthCheckHandler (5.39s)881=== CONT TestGCTaskStore_GetEmpty882--- PASS: TestGCTaskStore_GetEmpty (0.00s)883=== CONT TestReadProxyNarinfoAlreadyDecompressed8842026/10/01 10:04:01 INFO Received push request method=POST path=/api/pushes8852026/10/01 10:04:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8862026/10/01 10:04:01 INFO Uploading a0lf0pmybkbpz2vb5m9ms942jp8i3i3g-test-script (136B)8872026/10/01 10:04:01 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"8882026/10/01 10:04:01 WARN Failed to register uploaded object key=a0lf0pmybkbpz2vb5m9ms942jp8i3i3g.ls error="server returned 404: 404 page not found\n"8892026/10/01 10:04:01 WARN Failed to register uploaded object key=log/63s5rbhlfd2xmi64cl78kcbadsqq047w-test-script.drv error="server returned 404: 404 page not found\n"8902026/10/01 10:04:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8912026/10/01 10:04:01 INFO Signed narinfos id=1 count=18922026/10/01 10:04:01 INFO Uploading 1 narinfos8932026/10/01 10:04:01 INFO Received complete push request method=POST path=/api/pushes/1/complete8942026/10/01 10:04:01 WARN Failed to register uploaded object key=a0lf0pmybkbpz2vb5m9ms942jp8i3i3g.narinfo error="server returned 404: 404 page not found\n"8952026/10/01 10:04:02 INFO Upload complete. (289ms)896=== NAME TestClientWithDependencies897 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-7135-908923472/TestClientWithDependencies437338419/001/store) requires matching store prefix898--- PASS: TestReadProxyConditionalGet (5.87s)899=== CONT TestGCTaskStore_ConflictDifferentParams900--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)901=== CONT TestReadProxyNarinfo902--- PASS: TestClientWithDependencies (5.94s)903=== CONT TestGCTaskStore_DeduplicateSameParams904--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)905=== CONT TestIsValidCachePath906=== RUN TestIsValidCachePath/narinfo907=== PAUSE TestIsValidCachePath/narinfo908=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars909=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars910=== RUN TestIsValidCachePath/nar_zst911=== PAUSE TestIsValidCachePath/nar_zst912=== RUN TestIsValidCachePath/nar_xz913=== PAUSE TestIsValidCachePath/nar_xz914=== RUN TestIsValidCachePath/nar_bz2915=== PAUSE TestIsValidCachePath/nar_bz2916=== RUN TestIsValidCachePath/nar_uncompressed917=== PAUSE TestIsValidCachePath/nar_uncompressed918=== RUN TestIsValidCachePath/ls919=== PAUSE TestIsValidCachePath/ls920=== RUN TestIsValidCachePath/log921=== PAUSE TestIsValidCachePath/log922=== RUN TestIsValidCachePath/realisation923=== PAUSE TestIsValidCachePath/realisation924=== RUN TestIsValidCachePath/nix-cache-info925=== PAUSE TestIsValidCachePath/nix-cache-info926=== RUN TestIsValidCachePath/index.html927=== PAUSE TestIsValidCachePath/index.html928=== RUN TestIsValidCachePath/traversal_parent929=== PAUSE TestIsValidCachePath/traversal_parent930=== RUN TestIsValidCachePath/traversal_in_middle931=== PAUSE TestIsValidCachePath/traversal_in_middle932=== RUN TestIsValidCachePath/invalid_char_e933=== PAUSE TestIsValidCachePath/invalid_char_e934=== RUN TestIsValidCachePath/invalid_char_u935=== PAUSE TestIsValidCachePath/invalid_char_u936=== RUN TestIsValidCachePath/random_path937=== PAUSE TestIsValidCachePath/random_path938=== RUN TestIsValidCachePath/empty939=== PAUSE TestIsValidCachePath/empty940=== RUN TestIsValidCachePath/leading_slash941=== PAUSE TestIsValidCachePath/leading_slash942=== RUN TestIsValidCachePath/wrong_extension943=== PAUSE TestIsValidCachePath/wrong_extension944=== RUN TestIsValidCachePath/short_hash945=== PAUSE TestIsValidCachePath/short_hash946=== CONT TestGCTaskStore_StartNew947--- PASS: TestGCTaskStore_StartNew (0.00s)948=== CONT TestGCEndsOnShutdown9492026/10/01 10:04:02 WARN readiness check failed error="closed pool"950--- PASS: TestService_readinessHandler (6.23s)951=== CONT TestProxyHeadersOnlyTrustedOnSocket952--- PASS: TestReadProxyHead (6.66s)953=== CONT TestCommitRacingPendingCleanupKeepsObjects954--- PASS: TestReadProxyDisabled (7.11s)955=== CONT TestParseSingleRange956=== RUN TestParseSingleRange/none957=== PAUSE TestParseSingleRange/none958=== RUN TestParseSingleRange/unknown_unit959=== PAUSE TestParseSingleRange/unknown_unit960=== RUN TestParseSingleRange/multi-range_ignored961=== PAUSE TestParseSingleRange/multi-range_ignored962=== RUN TestParseSingleRange/malformed_no_dash963=== PAUSE TestParseSingleRange/malformed_no_dash964=== RUN TestParseSingleRange/malformed_both_empty965=== PAUSE TestParseSingleRange/malformed_both_empty966=== RUN TestParseSingleRange/malformed_end_before_start967=== PAUSE TestParseSingleRange/malformed_end_before_start968=== RUN TestParseSingleRange/closed969=== PAUSE TestParseSingleRange/closed970=== RUN TestParseSingleRange/open-ended971=== PAUSE TestParseSingleRange/open-ended972=== RUN TestParseSingleRange/end_clamped_to_size973=== PAUSE TestParseSingleRange/end_clamped_to_size974=== RUN TestParseSingleRange/suffix975=== PAUSE TestParseSingleRange/suffix976=== RUN TestParseSingleRange/suffix_exceeds_size977=== PAUSE TestParseSingleRange/suffix_exceeds_size978=== RUN TestParseSingleRange/single_byte979=== PAUSE TestParseSingleRange/single_byte980=== RUN TestParseSingleRange/start_past_EOF981=== PAUSE TestParseSingleRange/start_past_EOF982=== RUN TestParseSingleRange/start_far_past_EOF983=== PAUSE TestParseSingleRange/start_far_past_EOF984=== CONT TestPresentNotReportedWhileGCDeletesClosure9852026-10-01 10:04:03.818 UTC [7747] ERROR: relation "goose_db_version" does not exist at character 369862026-10-01 10:04:03.818 UTC [7747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9872026/10/01 10:04:03 INFO Received uploads request method=POST path=/api/pending_closures9882026/10/01 10:04:03 INFO Aborted multipart uploads count=0 kept=09892026/10/01 10:04:03 WARN Force mode enabled - objects will be deleted immediately without grace period9902026/10/01 10:04:03 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=09912026/10/01 10:04:04 INFO Vacuumed table table=pending_closures9922026/10/01 10:04:04 INFO Vacuumed table table=pending_objects9932026/10/01 10:04:04 INFO Vacuumed table table=multipart_uploads9942026/10/01 10:04:04 INFO Vacuumed table table=closures9952026/10/01 10:04:04 INFO Vacuumed table table=objects996--- PASS: TestGCSweepSkipsPendingObjects (7.81s)997=== CONT TestPushWaitsForSweepHoldingRow9982026-10-01 10:04:04.220 UTC [7764] ERROR: relation "goose_db_version" does not exist at character 369992026-10-01 10:04:04.220 UTC [7764] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10002026/10/01 10:04:04 OK 20241026095416_initial_model.sql (287.16ms)10012026/10/01 10:04:04 OK 20251210153512_drop_unused_gin_index.sql (13.23ms)10022026/10/01 10:04:04 OK 20251218171726_add_pins.sql (17.43ms)10032026/10/01 10:04:04 OK 20260628120000_add_object_size_and_stats.sql (39.46ms)10042026/10/01 10:04:04 OK 20260905000000_add_claims.sql (80.9ms)10052026/10/01 10:04:04 OK 20260920000000_drop_claims.sql (62.02ms)10062026/10/01 10:04:04 OK 20260923120000_add_pushes.sql (19.5ms)10072026/10/01 10:04:04 goose: successfully migrated database to version: 2026092312000010082026/10/01 10:04:04 OK 1_commit_pending_closure.sql (1.85ms)10092026/10/01 10:04:04 OK 2_object_stats_trigger.sql (306.83µs)10102026/10/01 10:04:04 OK 3_commit_push.sql (234µs)10112026/10/01 10:04:04 goose: up to current file version: 310122026-10-01 10:04:04.528 UTC [7774] ERROR: relation "goose_db_version" does not exist at character 3610132026-10-01 10:04:04.528 UTC [7774] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10142026/10/01 10:04:04 OK 20241026095416_initial_model.sql (249.58ms)10152026/10/01 10:04:04 OK 20251210153512_drop_unused_gin_index.sql (24.02ms)10162026/10/01 10:04:04 OK 20251218171726_add_pins.sql (29.94ms)10172026/10/01 10:04:04 OK 20260628120000_add_object_size_and_stats.sql (56.37ms)10182026/10/01 10:04:04 OK 20260905000000_add_claims.sql (142.48ms)10192026/10/01 10:04:04 OK 20260920000000_drop_claims.sql (87.3ms)1020--- PASS: TestReadProxyInvalidPath (4.89s)1021=== CONT TestPresentReportsOnlyClosureRoots10222026/10/01 10:04:04 OK 20260923120000_add_pushes.sql (27.68ms)10232026/10/01 10:04:04 goose: successfully migrated database to version: 2026092312000010242026/10/01 10:04:04 OK 1_commit_pending_closure.sql (3.92ms)10252026/10/01 10:04:04 OK 2_object_stats_trigger.sql (364.04µs)10262026/10/01 10:04:04 OK 3_commit_push.sql (242.71µs)10272026/10/01 10:04:04 goose: up to current file version: 310282026/10/01 10:04:04 OK 20241026095416_initial_model.sql (289.95ms)10292026/10/01 10:04:04 OK 20251210153512_drop_unused_gin_index.sql (10.51ms)10302026/10/01 10:04:04 OK 20251218171726_add_pins.sql (52.98ms)10312026/10/01 10:04:05 OK 20260628120000_add_object_size_and_stats.sql (56.65ms)10322026/10/01 10:04:05 OK 20260905000000_add_claims.sql (117.65ms)10332026/10/01 10:04:05 OK 20260920000000_drop_claims.sql (104.28ms)10342026/10/01 10:04:05 OK 20260923120000_add_pushes.sql (53.47ms)10352026/10/01 10:04:05 goose: successfully migrated database to version: 2026092312000010362026/10/01 10:04:05 OK 1_commit_pending_closure.sql (5.4ms)10372026/10/01 10:04:05 OK 2_object_stats_trigger.sql (2.99ms)10382026/10/01 10:04:05 OK 3_commit_push.sql (1.06ms)10392026/10/01 10:04:05 goose: up to current file version: 31040--- PASS: TestReadProxy404 (5.24s)1041=== CONT TestSweepRechecksPendingAfterLocking10422026-10-01 10:04:05.682 UTC [7783] ERROR: relation "goose_db_version" does not exist at character 3610432026-10-01 10:04:05.682 UTC [7783] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1044--- PASS: TestReadProxyNarStreaming (4.81s)1045=== CONT TestGetExistingObjectsLocksRows10462026/10/01 10:04:06 OK 20241026095416_initial_model.sql (524.99ms)10472026/10/01 10:04:06 OK 20251210153512_drop_unused_gin_index.sql (29.2ms)10482026/10/01 10:04:06 OK 20251218171726_add_pins.sql (60.83ms)10492026/10/01 10:04:06 OK 20260628120000_add_object_size_and_stats.sql (61.79ms)10502026/10/01 10:04:06 OK 20260905000000_add_claims.sql (152.68ms)10512026/10/01 10:04:06 OK 20260920000000_drop_claims.sql (78.36ms)10522026/10/01 10:04:06 OK 20260923120000_add_pushes.sql (20.38ms)10532026/10/01 10:04:06 goose: successfully migrated database to version: 2026092312000010542026/10/01 10:04:06 OK 1_commit_pending_closure.sql (2.13ms)10552026/10/01 10:04:06 OK 2_object_stats_trigger.sql (457.58µs)10562026/10/01 10:04:06 OK 3_commit_push.sql (395.58µs)10572026/10/01 10:04:06 goose: up to current file version: 310582026-10-01 10:04:06.747 UTC [7791] ERROR: relation "goose_db_version" does not exist at character 3610592026-10-01 10:04:06.747 UTC [7791] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10602026-10-01 10:04:06.764 UTC [7792] ERROR: relation "goose_db_version" does not exist at character 3610612026-10-01 10:04:06.764 UTC [7792] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10622026-10-01 10:04:06.963 UTC [7798] ERROR: relation "goose_db_version" does not exist at character 3610632026-10-01 10:04:06.963 UTC [7798] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10642026/10/01 10:04:07 OK 20241026095416_initial_model.sql (326.93ms)10652026/10/01 10:04:07 OK 20241026095416_initial_model.sql (320.38ms)10662026/10/01 10:04:07 OK 20251210153512_drop_unused_gin_index.sql (26.49ms)10672026/10/01 10:04:07 OK 20251210153512_drop_unused_gin_index.sql (27.72ms)10682026/10/01 10:04:07 OK 20251218171726_add_pins.sql (85.83ms)1069--- PASS: TestReadProxyNarinfoAlreadyDecompressed (5.61s)1070=== CONT TestRegisterCompletedObjectNeedsPendingRow10712026/10/01 10:04:07 OK 20251218171726_add_pins.sql (96.82ms)10722026/10/01 10:04:07 OK 20260628120000_add_object_size_and_stats.sql (53.46ms)10732026/10/01 10:04:07 OK 20260628120000_add_object_size_and_stats.sql (64.79ms)10742026/10/01 10:04:07 OK 20260905000000_add_claims.sql (143.22ms)10752026/10/01 10:04:07 OK 20260905000000_add_claims.sql (172.6ms)10762026/10/01 10:04:07 OK 20260920000000_drop_claims.sql (56.97ms)10772026/10/01 10:04:07 OK 20241026095416_initial_model.sql (401.68ms)10782026/10/01 10:04:07 OK 20260920000000_drop_claims.sql (69.44ms)10792026/10/01 10:04:07 OK 20260923120000_add_pushes.sql (45.2ms)10802026/10/01 10:04:07 goose: successfully migrated database to version: 2026092312000010812026/10/01 10:04:07 OK 1_commit_pending_closure.sql (3.78ms)10822026/10/01 10:04:07 OK 2_object_stats_trigger.sql (821.63µs)10832026/10/01 10:04:07 OK 3_commit_push.sql (554.79µs)10842026/10/01 10:04:07 goose: up to current file version: 310852026/10/01 10:04:07 OK 20251210153512_drop_unused_gin_index.sql (20.11ms)10862026/10/01 10:04:07 OK 20260923120000_add_pushes.sql (37.27ms)10872026/10/01 10:04:07 goose: successfully migrated database to version: 2026092312000010882026/10/01 10:04:07 OK 1_commit_pending_closure.sql (2.31ms)10892026/10/01 10:04:07 OK 2_object_stats_trigger.sql (561.21µs)10902026/10/01 10:04:07 OK 3_commit_push.sql (389.08µs)10912026/10/01 10:04:07 goose: up to current file version: 310922026/10/01 10:04:07 OK 20251218171726_add_pins.sql (52.94ms)10932026/10/01 10:04:07 OK 20260628120000_add_object_size_and_stats.sql (40.99ms)10942026-10-01 10:04:07.750 UTC [7802] ERROR: relation "goose_db_version" does not exist at character 3610952026-10-01 10:04:07.750 UTC [7802] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10962026/10/01 10:04:07 OK 20260905000000_add_claims.sql (106.87ms)10972026/10/01 10:04:07 OK 20260920000000_drop_claims.sql (57.25ms)10982026/10/01 10:04:07 OK 20260923120000_add_pushes.sql (36.46ms)10992026/10/01 10:04:07 goose: successfully migrated database to version: 2026092312000011002026/10/01 10:04:07 OK 1_commit_pending_closure.sql (2.85ms)11012026/10/01 10:04:07 OK 2_object_stats_trigger.sql (473.83µs)11022026/10/01 10:04:07 OK 3_commit_push.sql (428.21µs)11032026/10/01 10:04:07 goose: up to current file version: 31104--- PASS: TestGCEndsOnShutdown (5.85s)1105=== CONT TestSweepSkipsRowsLockedByPush11062026-10-01 10:04:08.188 UTC [7807] ERROR: relation "goose_db_version" does not exist at character 3611072026-10-01 10:04:08.188 UTC [7807] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11082026/10/01 10:04:08 OK 20241026095416_initial_model.sql (364.48ms)11092026/10/01 10:04:08 OK 20251210153512_drop_unused_gin_index.sql (21.31ms)11102026/10/01 10:04:08 OK 20251218171726_add_pins.sql (93.85ms)11112026/10/01 10:04:08 OK 20260628120000_add_object_size_and_stats.sql (72.61ms)11122026/10/01 10:04:08 OK 20260905000000_add_claims.sql (119.03ms)1113--- PASS: TestReadProxyNarinfo (6.38s)1114=== CONT TestFailedS3DeleteKeepsTombstone11152026/10/01 10:04:08 OK 20260920000000_drop_claims.sql (85.42ms)11162026/10/01 10:04:08 OK 20260923120000_add_pushes.sql (23.35ms)11172026/10/01 10:04:08 goose: successfully migrated database to version: 2026092312000011182026/10/01 10:04:08 OK 1_commit_pending_closure.sql (2.4ms)11192026/10/01 10:04:08 OK 2_object_stats_trigger.sql (413.08µs)11202026/10/01 10:04:08 OK 3_commit_push.sql (361.83µs)11212026/10/01 10:04:08 goose: up to current file version: 311222026/10/01 10:04:08 OK 20241026095416_initial_model.sql (349.2ms)11232026/10/01 10:04:08 OK 20251210153512_drop_unused_gin_index.sql (15.63ms)11242026/10/01 10:04:08 OK 20251218171726_add_pins.sql (36.62ms)11252026-10-01 10:04:08.775 UTC [7816] ERROR: relation "goose_db_version" does not exist at character 3611262026-10-01 10:04:08.775 UTC [7816] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11272026/10/01 10:04:08 OK 20260628120000_add_object_size_and_stats.sql (48.42ms)11282026/10/01 10:04:08 OK 20260905000000_add_claims.sql (68.92ms)11292026/10/01 10:04:08 INFO Starting HTTP server address=/nix/var/nix/builds/nix-7135-908923472/TestProxyHeadersOnlyTrustedOnSocket2212856438/001/proxy.sock11302026/10/01 10:04:08 INFO Starting HTTP server address=127.0.0.1:5820211312026/10/01 10:04:08 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11322026/10/01 10:04:08 INFO Shutdown signal received, draining in-flight requests timeout=10s11332026/10/01 10:04:08 OK 20260920000000_drop_claims.sql (116.16ms)1134=== CONT TestForceGCDuringPushOffersSweptObject1135--- PASS: TestProxyHeadersOnlyTrustedOnSocket (6.46s)1136=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1137=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1138=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1139=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1140=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11412026/10/01 10:04:09 OK 20260923120000_add_pushes.sql (42.81ms)11422026/10/01 10:04:09 goose: successfully migrated database to version: 2026092312000011432026/10/01 10:04:09 OK 1_commit_pending_closure.sql (2.75ms)11442026/10/01 10:04:09 OK 2_object_stats_trigger.sql (639.13µs)11452026/10/01 10:04:09 OK 3_commit_push.sql (584.04µs)11462026/10/01 10:04:09 goose: up to current file version: 311472026/10/01 10:04:09 OK 20241026095416_initial_model.sql (421.54ms)11482026/10/01 10:04:09 OK 20251210153512_drop_unused_gin_index.sql (9.52ms)11492026/10/01 10:04:09 OK 20251218171726_add_pins.sql (52.43ms)11502026/10/01 10:04:09 OK 20260628120000_add_object_size_and_stats.sql (56.71ms)11512026-10-01 10:04:09.489 UTC [7821] ERROR: relation "goose_db_version" does not exist at character 3611522026-10-01 10:04:09.489 UTC [7821] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11532026/10/01 10:04:09 OK 20260905000000_add_claims.sql (133.83ms)11542026/10/01 10:04:09 OK 20260920000000_drop_claims.sql (81.93ms)11552026/10/01 10:04:09 OK 20260923120000_add_pushes.sql (167.18ms)11562026/10/01 10:04:09 goose: successfully migrated database to version: 2026092312000011572026/10/01 10:04:09 OK 1_commit_pending_closure.sql (6.52ms)11582026/10/01 10:04:09 OK 2_object_stats_trigger.sql (1.21ms)11592026/10/01 10:04:09 OK 3_commit_push.sql (854.96µs)11602026/10/01 10:04:09 goose: up to current file version: 311612026/10/01 10:04:09 INFO Aborted multipart uploads count=0 kept=011622026/10/01 10:04:09 WARN Force mode enabled - objects will be deleted immediately without grace period11632026/10/01 10:04:09 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=011642026/10/01 10:04:09 INFO Vacuumed table table=pending_closures11652026/10/01 10:04:09 INFO Vacuumed table table=pending_objects11662026/10/01 10:04:09 INFO Vacuumed table table=multipart_uploads11672026/10/01 10:04:09 INFO Vacuumed table table=closures11682026/10/01 10:04:09 INFO Vacuumed table table=objects1169--- PASS: TestCommitRacingPendingCleanupKeepsObjects (6.92s)1170=== CONT TestGCSweepDeliversEachKeyOnce11712026/10/01 10:04:09 OK 20241026095416_initial_model.sql (367.52ms)11722026/10/01 10:04:09 OK 20251210153512_drop_unused_gin_index.sql (10.89ms)11732026/10/01 10:04:10 OK 20251218171726_add_pins.sql (64.08ms)11742026/10/01 10:04:10 OK 20260628120000_add_object_size_and_stats.sql (105.36ms)11752026/10/01 10:04:10 OK 20260905000000_add_claims.sql (176.63ms)11762026/10/01 10:04:10 OK 20260920000000_drop_claims.sql (110.74ms)11772026/10/01 10:04:10 OK 20260923120000_add_pushes.sql (14.13ms)11782026/10/01 10:04:10 goose: successfully migrated database to version: 2026092312000011792026/10/01 10:04:10 OK 1_commit_pending_closure.sql (1.15ms)11802026/10/01 10:04:10 OK 2_object_stats_trigger.sql (283.63µs)11812026/10/01 10:04:10 OK 3_commit_push.sql (217.63µs)11822026/10/01 10:04:10 goose: up to current file version: 311832026-10-01 10:04:10.568 UTC [7828] ERROR: relation "goose_db_version" does not exist at character 3611842026-10-01 10:04:10.568 UTC [7828] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11852026/10/01 10:04:10 INFO Received uploads request method=POST path=/api/pending_closures1186--- PASS: TestPresentNotReportedWhileGCDeletesClosure (7.22s)1187=== CONT TestTombstonedObjectOfferedWithoutWaiting11882026-10-01 10:04:10.892 UTC [7834] ERROR: relation "goose_db_version" does not exist at character 3611892026-10-01 10:04:10.892 UTC [7834] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11902026/10/01 10:04:11 OK 20241026095416_initial_model.sql (338.84ms)11912026/10/01 10:04:11 OK 20251210153512_drop_unused_gin_index.sql (8.96ms)11922026/10/01 10:04:11 OK 20251218171726_add_pins.sql (46.85ms)1193--- PASS: TestPushWaitsForSweepHoldingRow (6.98s)1194=== CONT TestCreatePin_ReservedPins1195--- PASS: TestPresentReportsOnlyClosureRoots (6.22s)1196=== CONT TestOrphanedObjectsGCStressTest11972026/10/01 10:04:11 OK 20260628120000_add_object_size_and_stats.sql (54.6ms)11982026/10/01 10:04:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58228/oidc11992026/10/01 10:04:11 OK 20260905000000_add_claims.sql (84.92ms)12002026/10/01 10:04:11 OK 20241026095416_initial_model.sql (230.96ms)12012026/10/01 10:04:11 OK 20251210153512_drop_unused_gin_index.sql (9.38ms)12022026/10/01 10:04:11 OK 20260920000000_drop_claims.sql (37.09ms)12032026/10/01 10:04:11 OK 20260923120000_add_pushes.sql (35.93ms)12042026/10/01 10:04:11 goose: successfully migrated database to version: 2026092312000012052026/10/01 10:04:11 OK 1_commit_pending_closure.sql (1.4ms)12062026/10/01 10:04:11 OK 2_object_stats_trigger.sql (213.13µs)12072026/10/01 10:04:11 OK 3_commit_push.sql (173.88µs)12082026/10/01 10:04:11 goose: up to current file version: 312092026/10/01 10:04:11 OK 20251218171726_add_pins.sql (55.12ms)12102026/10/01 10:04:11 OK 20260628120000_add_object_size_and_stats.sql (48ms)12112026/10/01 10:04:11 OK 20260905000000_add_claims.sql (82.65ms)12122026/10/01 10:04:11 OK 20260920000000_drop_claims.sql (78.2ms)12132026/10/01 10:04:11 OK 20260923120000_add_pushes.sql (24.71ms)12142026/10/01 10:04:11 goose: successfully migrated database to version: 2026092312000012152026/10/01 10:04:11 OK 1_commit_pending_closure.sql (961µs)12162026/10/01 10:04:11 OK 2_object_stats_trigger.sql (206.33µs)12172026/10/01 10:04:11 OK 3_commit_push.sql (181.38µs)12182026/10/01 10:04:11 goose: up to current file version: 312192026-10-01 10:04:11.576 UTC [7855] ERROR: relation "goose_db_version" does not exist at character 3612202026-10-01 10:04:11.576 UTC [7855] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12212026/10/01 10:04:11 INFO Aborted multipart uploads count=0 kept=012222026/10/01 10:04:11 WARN Force mode enabled - objects will be deleted immediately without grace period12232026/10/01 10:04:11 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=012242026/10/01 10:04:11 INFO Vacuumed table table=pending_closures12252026/10/01 10:04:11 INFO Vacuumed table table=pending_objects12262026/10/01 10:04:11 INFO Vacuumed table table=multipart_uploads12272026/10/01 10:04:11 INFO Vacuumed table table=closures12282026/10/01 10:04:11 INFO Vacuumed table table=objects1229--- PASS: TestSweepRechecksPendingAfterLocking (6.29s)1230=== CONT TestOrphanedObjectsGC12312026/10/01 10:04:11 OK 20241026095416_initial_model.sql (268.49ms)12322026/10/01 10:04:11 OK 20251210153512_drop_unused_gin_index.sql (24.88ms)1233--- PASS: TestGetExistingObjectsLocksRows (5.92s)1234=== CONT TestObjectStatsTrigger12352026/10/01 10:04:11 OK 20251218171726_add_pins.sql (38.51ms)12362026-10-01 10:04:11.998 UTC [7864] ERROR: relation "goose_db_version" does not exist at character 3612372026-10-01 10:04:11.998 UTC [7864] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12382026/10/01 10:04:12 OK 20260628120000_add_object_size_and_stats.sql (56.83ms)12392026/10/01 10:04:12 OK 20260905000000_add_claims.sql (78.65ms)12402026/10/01 10:04:12 OK 20260920000000_drop_claims.sql (46.87ms)12412026/10/01 10:04:12 OK 20260923120000_add_pushes.sql (17.61ms)12422026/10/01 10:04:12 goose: successfully migrated database to version: 2026092312000012432026/10/01 10:04:12 OK 1_commit_pending_closure.sql (2.07ms)12442026/10/01 10:04:12 OK 2_object_stats_trigger.sql (439.58µs)12452026/10/01 10:04:12 OK 3_commit_push.sql (340.58µs)12462026/10/01 10:04:12 goose: up to current file version: 312472026/10/01 10:04:12 OK 20241026095416_initial_model.sql (279ms)12482026/10/01 10:04:12 OK 20251210153512_drop_unused_gin_index.sql (26.92ms)12492026/10/01 10:04:12 OK 20251218171726_add_pins.sql (26.34ms)12502026/10/01 10:04:12 OK 20260628120000_add_object_size_and_stats.sql (76.63ms)12512026-10-01 10:04:12.484 UTC [7873] ERROR: relation "goose_db_version" does not exist at character 3612522026-10-01 10:04:12.484 UTC [7873] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12532026/10/01 10:04:12 OK 20260905000000_add_claims.sql (105.18ms)1254--- PASS: TestRegisterCompletedObjectNeedsPendingRow (5.38s)1255=== CONT TestPendingCleanupUsesOneCutoff12562026/10/01 10:04:12 OK 20260920000000_drop_claims.sql (108.18ms)12572026/10/01 10:04:12 OK 20260923120000_add_pushes.sql (52.09ms)12582026/10/01 10:04:12 goose: successfully migrated database to version: 2026092312000012592026/10/01 10:04:12 OK 1_commit_pending_closure.sql (3.74ms)12602026/10/01 10:04:12 OK 2_object_stats_trigger.sql (452.38µs)12612026/10/01 10:04:12 OK 3_commit_push.sql (338.92µs)12622026/10/01 10:04:12 goose: up to current file version: 312632026-10-01 10:04:12.763 UTC [7874] ERROR: relation "goose_db_version" does not exist at character 3612642026-10-01 10:04:12.763 UTC [7874] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12652026/10/01 10:04:12 OK 20241026095416_initial_model.sql (380.23ms)12662026/10/01 10:04:12 OK 20251210153512_drop_unused_gin_index.sql (17.79ms)12672026/10/01 10:04:13 OK 20251218171726_add_pins.sql (43.23ms)12682026/10/01 10:04:13 OK 20260628120000_add_object_size_and_stats.sql (86.7ms)12692026/10/01 10:04:13 OK 20241026095416_initial_model.sql (389.95ms)12702026/10/01 10:04:13 OK 20260905000000_add_claims.sql (157.96ms)12712026/10/01 10:04:13 INFO Aborted multipart uploads count=0 kept=012722026/10/01 10:04:13 WARN Force mode enabled - objects will be deleted immediately without grace period12732026/10/01 10:04:13 OK 20251210153512_drop_unused_gin_index.sql (15.54ms)12742026/10/01 10:04:13 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=012752026/10/01 10:04:13 INFO Vacuumed table table=pending_closures12762026/10/01 10:04:13 INFO Vacuumed table table=pending_objects12772026/10/01 10:04:13 INFO Vacuumed table table=multipart_uploads12782026/10/01 10:04:13 INFO Vacuumed table table=closures12792026/10/01 10:04:13 INFO Vacuumed table table=objects12802026/10/01 10:04:13 OK 20260920000000_drop_claims.sql (71.41ms)12812026/10/01 10:04:13 INFO Aborted multipart uploads count=0 kept=012822026/10/01 10:04:13 OK 20251218171726_add_pins.sql (56.24ms)12832026/10/01 10:04:13 WARN Force mode enabled - objects will be deleted immediately without grace period12842026/10/01 10:04:13 OK 20260923120000_add_pushes.sql (20.57ms)12852026/10/01 10:04:13 goose: successfully migrated database to version: 2026092312000012862026/10/01 10:04:13 OK 1_commit_pending_closure.sql (989.58µs)12872026/10/01 10:04:13 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=012882026/10/01 10:04:13 OK 2_object_stats_trigger.sql (245.88µs)12892026/10/01 10:04:13 OK 3_commit_push.sql (166.46µs)12902026/10/01 10:04:13 goose: up to current file version: 312912026/10/01 10:04:13 INFO Vacuumed table table=pending_closures12922026/10/01 10:04:13 INFO Vacuumed table table=pending_objects12932026/10/01 10:04:13 INFO Vacuumed table table=multipart_uploads12942026/10/01 10:04:13 INFO Vacuumed table table=closures12952026/10/01 10:04:13 INFO Vacuumed table table=objects1296--- PASS: TestSweepSkipsRowsLockedByPush (5.28s)1297=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded12982026/10/01 10:04:13 OK 20260628120000_add_object_size_and_stats.sql (42.02ms)12992026-10-01 10:04:13.471 UTC [7885] ERROR: relation "goose_db_version" does not exist at character 3613002026-10-01 10:04:13.471 UTC [7885] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13012026/10/01 10:04:13 OK 20260905000000_add_claims.sql (88.7ms)13022026/10/01 10:04:13 OK 20260920000000_drop_claims.sql (69.13ms)13032026/10/01 10:04:13 OK 20260923120000_add_pushes.sql (11.11ms)13042026/10/01 10:04:13 goose: successfully migrated database to version: 2026092312000013052026/10/01 10:04:13 OK 1_commit_pending_closure.sql (1.68ms)13062026/10/01 10:04:13 OK 2_object_stats_trigger.sql (242.88µs)13072026/10/01 10:04:13 OK 3_commit_push.sql (173.33µs)13082026/10/01 10:04:13 goose: up to current file version: 313092026/10/01 10:04:13 INFO Received uploads request method=POST path=/api/pending_closures13102026/10/01 10:04:13 OK 20241026095416_initial_model.sql (377.89ms)13112026/10/01 10:04:13 OK 20251210153512_drop_unused_gin_index.sql (15.45ms)13122026-10-01 10:04:14.041 UTC [7891] ERROR: relation "goose_db_version" does not exist at character 3613132026-10-01 10:04:14.041 UTC [7891] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13142026/10/01 10:04:14 INFO Aborted multipart uploads count=0 kept=013152026/10/01 10:04:14 OK 20251218171726_add_pins.sql (66.01ms)13162026/10/01 10:04:14 WARN Force mode enabled - objects will be deleted immediately without grace period13172026/10/01 10:04:14 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13182026/10/01 10:04:14 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1319--- PASS: TestFailedS3DeleteKeepsTombstone (5.52s)1320=== CONT TestMultipartCleanup13212026/10/01 10:04:14 OK 20260628120000_add_object_size_and_stats.sql (62.88ms)13222026/10/01 10:04:14 OK 20260905000000_add_claims.sql (103.63ms)13232026/10/01 10:04:14 OK 20260920000000_drop_claims.sql (33.86ms)13242026/10/01 10:04:14 OK 20260923120000_add_pushes.sql (23.8ms)13252026/10/01 10:04:14 goose: successfully migrated database to version: 2026092312000013262026/10/01 10:04:14 OK 1_commit_pending_closure.sql (1.54ms)13272026/10/01 10:04:14 OK 2_object_stats_trigger.sql (312.54µs)13282026/10/01 10:04:14 OK 3_commit_push.sql (242.79µs)13292026/10/01 10:04:14 goose: up to current file version: 313302026/10/01 10:04:14 INFO Received uploads request method=POST path=/api/pending_closures13312026-10-01 10:04:14.360 UTC [7897] ERROR: relation "goose_db_version" does not exist at character 3613322026-10-01 10:04:14.360 UTC [7897] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13332026-10-01 10:04:14.362 UTC [7898] ERROR: relation "goose_db_version" does not exist at character 3613342026-10-01 10:04:14.362 UTC [7898] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13352026/10/01 10:04:14 OK 20241026095416_initial_model.sql (202.44ms)13362026/10/01 10:04:14 OK 20251210153512_drop_unused_gin_index.sql (21.45ms)13372026/10/01 10:04:14 OK 20251218171726_add_pins.sql (24.82ms)13382026/10/01 10:04:14 OK 20260628120000_add_object_size_and_stats.sql (47.73ms)13392026/10/01 10:04:14 OK 20260905000000_add_claims.sql (39.45ms)1340--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (5.54s)1341=== CONT TestServerTLSConfig1342=== RUN TestServerTLSConfig/no_client_CA1343=== PAUSE TestServerTLSConfig/no_client_CA1344=== RUN TestServerTLSConfig/missing_CA_file1345=== PAUSE TestServerTLSConfig/missing_CA_file1346=== RUN TestServerTLSConfig/not_a_PEM_file1347=== PAUSE TestServerTLSConfig/not_a_PEM_file1348=== CONT TestService_Rustfstest13492026/10/01 10:04:14 OK 20260920000000_drop_claims.sql (35.05ms)13502026/10/01 10:04:14 OK 20260923120000_add_pushes.sql (21.68ms)13512026/10/01 10:04:14 goose: successfully migrated database to version: 2026092312000013522026/10/01 10:04:14 OK 1_commit_pending_closure.sql (950.92µs)13532026/10/01 10:04:14 OK 2_object_stats_trigger.sql (230.58µs)13542026/10/01 10:04:14 OK 3_commit_push.sql (204.33µs)13552026/10/01 10:04:14 goose: up to current file version: 313562026/10/01 10:04:14 OK 20241026095416_initial_model.sql (190.77ms)13572026/10/01 10:04:14 OK 20251210153512_drop_unused_gin_index.sql (13.43ms)13582026/10/01 10:04:14 OK 20241026095416_initial_model.sql (190.3ms)13592026/10/01 10:04:14 OK 20251210153512_drop_unused_gin_index.sql (13.75ms)13602026/10/01 10:04:14 OK 20251218171726_add_pins.sql (40.21ms)13612026/10/01 10:04:14 OK 20251218171726_add_pins.sql (33.7ms)13622026/10/01 10:04:14 INFO Aborted multipart uploads count=0 kept=013632026/10/01 10:04:14 WARN Force mode enabled - objects will be deleted immediately without grace period13642026/10/01 10:04:14 OK 20260628120000_add_object_size_and_stats.sql (48.16ms)13652026/10/01 10:04:14 OK 20260628120000_add_object_size_and_stats.sql (70.83ms)13662026/10/01 10:04:14 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=013672026/10/01 10:04:14 INFO Vacuumed table table=pending_closures13682026/10/01 10:04:14 INFO Vacuumed table table=pending_objects13692026/10/01 10:04:14 INFO Vacuumed table table=multipart_uploads13702026/10/01 10:04:14 INFO Vacuumed table table=closures13712026/10/01 10:04:14 OK 20260905000000_add_claims.sql (112.3ms)13722026/10/01 10:04:14 OK 20260905000000_add_claims.sql (96.88ms)13732026/10/01 10:04:14 INFO Vacuumed table table=objects1374--- PASS: TestGCSweepDeliversEachKeyOnce (4.87s)1375=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT13762026/10/01 10:04:14 OK 20260920000000_drop_claims.sql (78.01ms)13772026/10/01 10:04:14 OK 20260920000000_drop_claims.sql (63.79ms)13782026/10/01 10:04:14 OK 20260923120000_add_pushes.sql (5.78ms)13792026/10/01 10:04:14 goose: successfully migrated database to version: 2026092312000013802026/10/01 10:04:14 OK 20260923120000_add_pushes.sql (4.91ms)13812026/10/01 10:04:14 goose: successfully migrated database to version: 2026092312000013822026/10/01 10:04:14 OK 1_commit_pending_closure.sql (970.33µs)13832026/10/01 10:04:14 OK 1_commit_pending_closure.sql (1.06ms)13842026/10/01 10:04:14 OK 2_object_stats_trigger.sql (233.58µs)13852026/10/01 10:04:14 OK 2_object_stats_trigger.sql (217.58µs)13862026/10/01 10:04:14 OK 3_commit_push.sql (190.38µs)13872026/10/01 10:04:14 goose: up to current file version: 313882026/10/01 10:04:14 OK 3_commit_push.sql (199.75µs)13892026/10/01 10:04:14 goose: up to current file version: 313902026/10/01 10:04:15 INFO Received uploads request method=POST path=/api/pending_closures1391--- PASS: TestTombstonedObjectOfferedWithoutWaiting (4.41s)1392=== CONT TestService_NativeMTLS13932026-10-01 10:04:15.217 UTC [7922] ERROR: relation "goose_db_version" does not exist at character 3613942026-10-01 10:04:15.217 UTC [7922] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13952026/10/01 10:04:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13962026/10/01 10:04:15 WARN Refused reserved pin name=worker-x86_64-linux13972026/10/01 10:04:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13982026/10/01 10:04:15 INFO Received create pin request method=POST path=/api/pins/my-app13992026/10/01 10:04:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1400--- PASS: TestCreatePin_ReservedPins (4.17s)1401=== CONT TestCompleteMultipartUnregistered14022026-10-01 10:04:15.350 UTC [7923] ERROR: relation "goose_db_version" does not exist at character 3614032026-10-01 10:04:15.350 UTC [7923] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14042026/10/01 10:04:15 OK 20241026095416_initial_model.sql (263.41ms)14052026/10/01 10:04:15 OK 20251210153512_drop_unused_gin_index.sql (14.51ms)14062026/10/01 10:04:15 OK 20251218171726_add_pins.sql (39.44ms)14072026/10/01 10:04:15 OK 20260628120000_add_object_size_and_stats.sql (61.23ms)14082026/10/01 10:04:15 OK 20241026095416_initial_model.sql (283.8ms)14092026/10/01 10:04:15 OK 20251210153512_drop_unused_gin_index.sql (23.45ms)14102026/10/01 10:04:15 OK 20260905000000_add_claims.sql (103.63ms)14112026/10/01 10:04:15 OK 20251218171726_add_pins.sql (39.48ms)14122026/10/01 10:04:15 OK 20260628120000_add_object_size_and_stats.sql (57.78ms)14132026/10/01 10:04:15 OK 20260920000000_drop_claims.sql (82.81ms)14142026/10/01 10:04:15 OK 20260923120000_add_pushes.sql (27ms)14152026/10/01 10:04:15 goose: successfully migrated database to version: 2026092312000014162026/10/01 10:04:15 OK 1_commit_pending_closure.sql (1.67ms)14172026/10/01 10:04:15 OK 2_object_stats_trigger.sql (376.96µs)14182026/10/01 10:04:15 OK 3_commit_push.sql (312.46µs)14192026/10/01 10:04:15 goose: up to current file version: 314202026/10/01 10:04:15 OK 20260905000000_add_claims.sql (138.83ms)14212026/10/01 10:04:16 OK 20260920000000_drop_claims.sql (121.68ms)14222026/10/01 10:04:16 OK 20260923120000_add_pushes.sql (32.76ms)14232026/10/01 10:04:16 goose: successfully migrated database to version: 2026092312000014242026/10/01 10:04:16 OK 1_commit_pending_closure.sql (7.03ms)14252026/10/01 10:04:16 OK 2_object_stats_trigger.sql (2.06ms)14262026/10/01 10:04:16 OK 3_commit_push.sql (808.75µs)14272026/10/01 10:04:16 goose: up to current file version: 314282026-10-01 10:04:16.462 UTC [7935] ERROR: relation "goose_db_version" does not exist at character 3614292026-10-01 10:04:16.462 UTC [7935] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14302026/10/01 10:04:16 OK 20241026095416_initial_model.sql (358.45ms)1431--- PASS: TestObjectStatsTrigger (4.95s)1432=== CONT TestService_verifyS3Integrity14332026/10/01 10:04:16 OK 20251210153512_drop_unused_gin_index.sql (11.7ms)14342026/10/01 10:04:17 OK 20251218171726_add_pins.sql (69.68ms)14352026/10/01 10:04:17 OK 20260628120000_add_object_size_and_stats.sql (48.79ms)14362026/10/01 10:04:17 OK 20260905000000_add_claims.sql (83.02ms)14372026/10/01 10:04:17 OK 20260920000000_drop_claims.sql (117.11ms)14382026/10/01 10:04:17 OK 20260923120000_add_pushes.sql (18.72ms)14392026/10/01 10:04:17 goose: successfully migrated database to version: 2026092312000014402026/10/01 10:04:17 OK 1_commit_pending_closure.sql (3.37ms)14412026/10/01 10:04:17 OK 2_object_stats_trigger.sql (654.33µs)14422026/10/01 10:04:17 OK 3_commit_push.sql (430.71µs)14432026/10/01 10:04:17 goose: up to current file version: 314442026-10-01 10:04:17.409 UTC [7940] ERROR: relation "goose_db_version" does not exist at character 3614452026-10-01 10:04:17.409 UTC [7940] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1446=== NAME TestOrphanedObjectsGC1447 orphaned_objects_gc_test.go:290: GC Test Summary:1448 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1449 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1450 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1451 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1452 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1453--- PASS: TestOrphanedObjectsGC (5.83s)1454=== CONT TestService_createPendingClosureHandler14552026/10/01 10:04:17 INFO Received uploads request method=POST path=/api/pending_closures14562026/10/01 10:04:17 OK 20241026095416_initial_model.sql (409.27ms)14572026/10/01 10:04:17 INFO Received uploads request method=POST path=/api/pending_closures14582026/10/01 10:04:17 OK 20251210153512_drop_unused_gin_index.sql (10.81ms)14592026-10-01 10:04:17.977 UTC [7943] ERROR: relation "goose_db_version" does not exist at character 3614602026-10-01 10:04:17.977 UTC [7943] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14612026/10/01 10:04:18 OK 20251218171726_add_pins.sql (80.13ms)14622026/10/01 10:04:18 INFO Received cleanup request method=DELETE path=/api/pending_closures14632026/10/01 10:04:18 OK 20260628120000_add_object_size_and_stats.sql (68.47ms)14642026/10/01 10:04:18 OK 20260905000000_add_claims.sql (98.7ms)14652026/10/01 10:04:18 OK 20260920000000_drop_claims.sql (109.86ms)14662026/10/01 10:04:18 OK 20260923120000_add_pushes.sql (22.28ms)14672026/10/01 10:04:18 goose: successfully migrated database to version: 2026092312000014682026/10/01 10:04:18 OK 1_commit_pending_closure.sql (4.72ms)14692026/10/01 10:04:18 OK 2_object_stats_trigger.sql (791.17µs)14702026/10/01 10:04:18 OK 3_commit_push.sql (2ms)14712026/10/01 10:04:18 goose: up to current file version: 314722026/10/01 10:04:18 OK 20241026095416_initial_model.sql (409.06ms)14732026/10/01 10:04:18 OK 20251210153512_drop_unused_gin_index.sql (15.65ms)14742026/10/01 10:04:18 OK 20251218171726_add_pins.sql (64.03ms)14752026-10-01 10:04:18.609 UTC [7946] ERROR: relation "goose_db_version" does not exist at character 3614762026-10-01 10:04:18.609 UTC [7946] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14772026/10/01 10:04:18 OK 20260628120000_add_object_size_and_stats.sql (83.44ms)14782026/10/01 10:04:18 INFO Received uploads request method=POST path=/api/pending_closures14792026/10/01 10:04:18 OK 20260905000000_add_claims.sql (139.01ms)14802026/10/01 10:04:18 OK 20260920000000_drop_claims.sql (88.92ms)14812026/10/01 10:04:18 OK 20260923120000_add_pushes.sql (34.3ms)14822026/10/01 10:04:18 goose: successfully migrated database to version: 202609231200001483--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (5.58s)1484=== CONT TestMetricsInventory14852026/10/01 10:04:18 OK 1_commit_pending_closure.sql (5.72ms)14862026/10/01 10:04:18 OK 2_object_stats_trigger.sql (2.23ms)14872026/10/01 10:04:18 OK 3_commit_push.sql (821.71µs)14882026/10/01 10:04:18 goose: up to current file version: 314892026/10/01 10:04:19 OK 20241026095416_initial_model.sql (394.17ms)14902026/10/01 10:04:19 OK 20251210153512_drop_unused_gin_index.sql (26.81ms)14912026/10/01 10:04:19 OK 20251218171726_add_pins.sql (46.55ms)14922026/10/01 10:04:19 OK 20260628120000_add_object_size_and_stats.sql (92.38ms)14932026-10-01 10:04:19.411 UTC [7950] ERROR: relation "goose_db_version" does not exist at character 3614942026-10-01 10:04:19.411 UTC [7950] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14952026/10/01 10:04:19 OK 20260905000000_add_claims.sql (161.03ms)14962026/10/01 10:04:19 INFO Received uploads request method=POST path=/api/pending_closures14972026/10/01 10:04:19 OK 20260920000000_drop_claims.sql (112.69ms)14982026/10/01 10:04:19 OK 20260923120000_add_pushes.sql (28.46ms)14992026/10/01 10:04:19 goose: successfully migrated database to version: 2026092312000015002026/10/01 10:04:19 OK 1_commit_pending_closure.sql (1.59ms)15012026/10/01 10:04:19 OK 2_object_stats_trigger.sql (402.75µs)15022026/10/01 10:04:19 OK 3_commit_push.sql (292.21µs)15032026/10/01 10:04:19 goose: up to current file version: 315042026/10/01 10:04:19 INFO Received cleanup request method=DELETE path=/api/pending_closures15052026/10/01 10:04:19 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket38/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15062026/10/01 10:04:19 INFO Aborted multipart uploads count=0 kept=115072026/10/01 10:04:19 INFO Received cleanup request method=DELETE path=/api/pending_closures15082026/10/01 10:04:19 INFO Aborted multipart uploads count=1 kept=01509--- PASS: TestMultipartCleanup (5.68s)1510=== CONT TestService_cleanupPendingClosuresHandler15112026-10-01 10:04:19.762 UTC [7954] ERROR: relation "goose_db_version" does not exist at character 3615122026-10-01 10:04:19.762 UTC [7954] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15132026/10/01 10:04:20 OK 20241026095416_initial_model.sql (455.88ms)15142026/10/01 10:04:20 OK 20251210153512_drop_unused_gin_index.sql (27.46ms)15152026/10/01 10:04:20 OK 20251218171726_add_pins.sql (48.07ms)15162026/10/01 10:04:20 OK 20260628120000_add_object_size_and_stats.sql (82.76ms)1517--- PASS: TestService_Rustfstest (5.63s)1518=== CONT TestUploadHandlersRejectOversizedBody15192026-10-01 10:04:20.196 UTC [7959] ERROR: relation "goose_db_version" does not exist at character 3615202026-10-01 10:04:20.196 UTC [7959] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1521=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1522=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1523=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1524=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1525=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1526=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1527=== CONT TestNARDeduplicationMetadataUploadBug15282026/10/01 10:04:20 OK 20260905000000_add_claims.sql (137.33ms)15292026/10/01 10:04:20 OK 20241026095416_initial_model.sql (374.29ms)15302026/10/01 10:04:20 OK 20251210153512_drop_unused_gin_index.sql (17.25ms)15312026/10/01 10:04:20 OK 20251218171726_add_pins.sql (50.22ms)15322026/10/01 10:04:20 OK 20260920000000_drop_claims.sql (73.48ms)15332026/10/01 10:04:20 OK 20260923120000_add_pushes.sql (41.66ms)15342026/10/01 10:04:20 goose: successfully migrated database to version: 2026092312000015352026/10/01 10:04:20 OK 20260628120000_add_object_size_and_stats.sql (52.54ms)15362026/10/01 10:04:20 OK 1_commit_pending_closure.sql (5.41ms)15372026/10/01 10:04:20 OK 2_object_stats_trigger.sql (936.92µs)15382026/10/01 10:04:20 OK 3_commit_push.sql (844.88µs)15392026/10/01 10:04:20 goose: up to current file version: 315402026/10/01 10:04:20 OK 20260905000000_add_claims.sql (120.69ms)15412026/10/01 10:04:20 OK 20241026095416_initial_model.sql (318.24ms)15422026/10/01 10:04:20 OK 20251210153512_drop_unused_gin_index.sql (18.69ms)15432026/10/01 10:04:20 OK 20260920000000_drop_claims.sql (117.38ms)15442026/10/01 10:04:20 OK 20251218171726_add_pins.sql (74.73ms)15452026/10/01 10:04:20 OK 20260923120000_add_pushes.sql (59.78ms)15462026/10/01 10:04:20 goose: successfully migrated database to version: 2026092312000015472026/10/01 10:04:20 OK 1_commit_pending_closure.sql (4.65ms)15482026/10/01 10:04:20 OK 2_object_stats_trigger.sql (940.38µs)15492026/10/01 10:04:20 OK 3_commit_push.sql (652.96µs)15502026/10/01 10:04:20 goose: up to current file version: 315512026/10/01 10:04:20 OK 20260628120000_add_object_size_and_stats.sql (68.78ms)15522026/10/01 10:04:20 OK 20260905000000_add_claims.sql (136.43ms)15532026/10/01 10:04:20 INFO Received uploads request method=POST path=/api/pending_closures15542026/10/01 10:04:21 OK 20260920000000_drop_claims.sql (81.7ms)15552026/10/01 10:04:21 OK 20260923120000_add_pushes.sql (35.5ms)15562026/10/01 10:04:21 goose: successfully migrated database to version: 2026092312000015572026/10/01 10:04:21 OK 1_commit_pending_closure.sql (1.16ms)15582026/10/01 10:04:21 OK 2_object_stats_trigger.sql (283.08µs)15592026/10/01 10:04:21 OK 3_commit_push.sql (233.13µs)15602026/10/01 10:04:21 goose: up to current file version: 31561--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (6.27s)1562=== CONT TestUploadHandlersRejectInvalidKeys1563=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1564=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1565=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1566=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1567=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1568=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1569=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1570=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1571=== CONT TestIsValidUploadKey1572=== RUN TestIsValidUploadKey/narinfo1573=== PAUSE TestIsValidUploadKey/narinfo1574=== RUN TestIsValidUploadKey/nar_zst1575=== PAUSE TestIsValidUploadKey/nar_zst1576=== RUN TestIsValidUploadKey/nar_xz1577=== PAUSE TestIsValidUploadKey/nar_xz1578=== RUN TestIsValidUploadKey/nar_plain1579=== PAUSE TestIsValidUploadKey/nar_plain1580=== RUN TestIsValidUploadKey/listing1581=== PAUSE TestIsValidUploadKey/listing1582=== RUN TestIsValidUploadKey/build_log1583=== PAUSE TestIsValidUploadKey/build_log1584=== RUN TestIsValidUploadKey/build_log_home-manager_file1585=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1586=== RUN TestIsValidUploadKey/build_log_plus_in_name1587=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1588=== RUN TestIsValidUploadKey/build_log_question_mark1589=== PAUSE TestIsValidUploadKey/build_log_question_mark1590=== RUN TestIsValidUploadKey/build_log_equals1591=== PAUSE TestIsValidUploadKey/build_log_equals1592=== RUN TestIsValidUploadKey/realisation1593=== PAUSE TestIsValidUploadKey/realisation1594=== RUN TestIsValidUploadKey/realisation_plus_in_output1595=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1596=== RUN TestIsValidUploadKey/nix-cache-info1597=== PAUSE TestIsValidUploadKey/nix-cache-info1598=== RUN TestIsValidUploadKey/index.html1599=== PAUSE TestIsValidUploadKey/index.html1600=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1601=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1602=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1603=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1604=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1605=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1606=== RUN TestIsValidUploadKey/traversal1607=== PAUSE TestIsValidUploadKey/traversal1608=== RUN TestIsValidUploadKey/traversal_nar1609=== PAUSE TestIsValidUploadKey/traversal_nar1610=== RUN TestIsValidUploadKey/absolute1611=== PAUSE TestIsValidUploadKey/absolute1612=== RUN TestIsValidUploadKey/empty_key1613=== PAUSE TestIsValidUploadKey/empty_key1614=== RUN TestIsValidUploadKey/unknown_type1615=== PAUSE TestIsValidUploadKey/unknown_type1616=== CONT TestProxyWriteTimeout1617=== RUN TestProxyWriteTimeout/narinfo1618=== PAUSE TestProxyWriteTimeout/narinfo1619=== RUN TestProxyWriteTimeout/1_GiB_nar1620=== PAUSE TestProxyWriteTimeout/1_GiB_nar1621=== RUN TestProxyWriteTimeout/10_GiB_nar1622=== PAUSE TestProxyWriteTimeout/10_GiB_nar1623=== RUN TestProxyWriteTimeout/unknown_size1624=== PAUSE TestProxyWriteTimeout/unknown_size1625=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle16262026/10/01 10:04:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16272026/10/01 10:04:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1628--- PASS: TestService_NativeMTLS (6.39s)1629=== CONT TestLeadElectsOneAndHandsOver16302026-10-01 10:04:21.569 UTC [7966] ERROR: relation "goose_db_version" does not exist at character 3616312026-10-01 10:04:21.569 UTC [7966] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16322026/10/01 10:04:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16332026/10/01 10:04:21 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1634--- PASS: TestCompleteMultipartUnregistered (6.57s)1635=== CONT TestSkippedUploadsHandler16362026/10/01 10:04:21 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001637--- PASS: TestSkippedUploadsHandler (0.00s)1638=== CONT TestDeduplicatedObjectsRecordedAsPending16392026/10/01 10:04:21 OK 20241026095416_initial_model.sql (315.5ms)16402026/10/01 10:04:21 OK 20251210153512_drop_unused_gin_index.sql (15.38ms)16412026-10-01 10:04:22.012 UTC [7977] ERROR: relation "goose_db_version" does not exist at character 3616422026-10-01 10:04:22.012 UTC [7977] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16432026/10/01 10:04:22 OK 20251218171726_add_pins.sql (44.19ms)16442026/10/01 10:04:22 OK 20260628120000_add_object_size_and_stats.sql (47.9ms)16452026/10/01 10:04:22 OK 20260905000000_add_claims.sql (88.53ms)16462026/10/01 10:04:22 OK 20260920000000_drop_claims.sql (55ms)16472026/10/01 10:04:22 OK 20260923120000_add_pushes.sql (27.52ms)16482026/10/01 10:04:22 goose: successfully migrated database to version: 2026092312000016492026/10/01 10:04:22 OK 1_commit_pending_closure.sql (3.22ms)16502026/10/01 10:04:22 OK 2_object_stats_trigger.sql (704.67µs)16512026/10/01 10:04:22 OK 3_commit_push.sql (1.29ms)16522026/10/01 10:04:22 goose: up to current file version: 316532026/10/01 10:04:22 OK 20241026095416_initial_model.sql (275.42ms)16542026/10/01 10:04:22 OK 20251210153512_drop_unused_gin_index.sql (15.71ms)16552026/10/01 10:04:22 OK 20251218171726_add_pins.sql (139.94ms)16562026/10/01 10:04:22 OK 20260628120000_add_object_size_and_stats.sql (61.96ms)16572026/10/01 10:04:22 OK 20260905000000_add_claims.sql (94.92ms)16582026/10/01 10:04:22 INFO Received uploads request method=POST path=/api/pending_closures16592026/10/01 10:04:22 OK 20260920000000_drop_claims.sql (46.5ms)16602026/10/01 10:04:22 OK 20260923120000_add_pushes.sql (29.6ms)16612026/10/01 10:04:22 goose: successfully migrated database to version: 2026092312000016622026/10/01 10:04:22 OK 1_commit_pending_closure.sql (5.68ms)16632026/10/01 10:04:22 OK 2_object_stats_trigger.sql (1.62ms)16642026/10/01 10:04:22 OK 3_commit_push.sql (757.33µs)16652026/10/01 10:04:22 goose: up to current file version: 316662026/10/01 10:04:23 INFO Received uploads request method=POST path=/api/pending_closures16672026/10/01 10:04:23 INFO Received uploads request method=POST path=/api/pending_closures16682026/10/01 10:04:23 INFO Received uploads request method=POST path=/api/pending_closures16692026-10-01 10:04:23.713 UTC [7978] ERROR: relation "goose_db_version" does not exist at character 3616702026-10-01 10:04:23.713 UTC [7978] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16712026/10/01 10:04:24 INFO Aborted multipart uploads count=1 kept=016722026/10/01 10:04:24 INFO Received cleanup request method=DELETE path=/api/pending_closures16732026/10/01 10:04:24 OK 20241026095416_initial_model.sql (321.78ms)16742026/10/01 10:04:24 INFO Aborted multipart uploads count=1 kept=01675--- PASS: TestPendingCleanupUsesOneCutoff (11.44s)1676=== CONT TestParseSize1677--- PASS: TestParseSize (0.00s)1678=== CONT TestPushDedupSurvivesConcurrentGC16792026/10/01 10:04:24 OK 20251210153512_drop_unused_gin_index.sql (30.31ms)16802026/10/01 10:04:24 OK 20251218171726_add_pins.sql (51.87ms)16812026/10/01 10:04:24 OK 20260628120000_add_object_size_and_stats.sql (37.97ms)16822026/10/01 10:04:24 OK 20260905000000_add_claims.sql (100.05ms)16832026-10-01 10:04:24.340 UTC [7981] ERROR: relation "goose_db_version" does not exist at character 3616842026-10-01 10:04:24.340 UTC [7981] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16852026/10/01 10:04:24 OK 20260920000000_drop_claims.sql (60.98ms)16862026/10/01 10:04:24 OK 20260923120000_add_pushes.sql (42.8ms)16872026/10/01 10:04:24 goose: successfully migrated database to version: 2026092312000016882026/10/01 10:04:24 OK 1_commit_pending_closure.sql (2.99ms)16892026/10/01 10:04:24 OK 2_object_stats_trigger.sql (576.13µs)16902026/10/01 10:04:24 OK 3_commit_push.sql (390.29µs)16912026/10/01 10:04:24 goose: up to current file version: 316922026-10-01 10:04:24.587 UTC [7982] ERROR: relation "goose_db_version" does not exist at character 3616932026-10-01 10:04:24.587 UTC [7982] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16942026/10/01 10:04:24 OK 20241026095416_initial_model.sql (392.38ms)16952026/10/01 10:04:24 OK 20251210153512_drop_unused_gin_index.sql (5.03ms)16962026/10/01 10:04:24 OK 20251218171726_add_pins.sql (49.36ms)16972026/10/01 10:04:24 OK 20260628120000_add_object_size_and_stats.sql (47.16ms)16982026/10/01 10:04:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16992026/10/01 10:04:25 OK 20241026095416_initial_model.sql (332.87ms)17002026/10/01 10:04:25 OK 20251210153512_drop_unused_gin_index.sql (48.13ms)17012026/10/01 10:04:25 OK 20260905000000_add_claims.sql (129.8ms)1702--- PASS: TestMetricsInventory (6.10s)1703=== CONT TestClientFallsBackToClosures17042026/10/01 10:04:25 OK 20251218171726_add_pins.sql (25.75ms)17052026/10/01 10:04:25 OK 20260920000000_drop_claims.sql (24.97ms)17062026/10/01 10:04:25 OK 20260923120000_add_pushes.sql (21.15ms)17072026/10/01 10:04:25 goose: successfully migrated database to version: 2026092312000017082026/10/01 10:04:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MDNlY2QwNzEtNjcwYy00OTM5LTllYjgtMzcyZmY4NDFmNTg0LjcwNTA5YjliLTg0NGUtNDg4ZC04OGMzLTJiOTM0YzI2ZTAzMngxNzkwODQ5MDYyNzYzMzE4MDAw parts=1017092026/10/01 10:04:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17102026/10/01 10:04:25 OK 1_commit_pending_closure.sql (2.21ms)17112026/10/01 10:04:25 OK 2_object_stats_trigger.sql (416.92µs)17122026/10/01 10:04:25 OK 3_commit_push.sql (316.5µs)17132026/10/01 10:04:25 goose: up to current file version: 317142026/10/01 10:04:25 OK 20260628120000_add_object_size_and_stats.sql (39.84ms)17152026/10/01 10:04:25 INFO Completed upload id=117162026/10/01 10:04:25 INFO Received uploads request method=POST path=/api/pending_closures17172026/10/01 10:04:25 INFO Received uploads request method=POST path=/api/pending_closures17182026/10/01 10:04:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17192026/10/01 10:04:25 WARN Found objects in DB but missing from S3, will re-upload count=11720--- PASS: TestService_verifyS3Integrity (8.19s)1721=== CONT TestGCMetrics17222026/10/01 10:04:25 OK 20260905000000_add_claims.sql (99.55ms)17232026-10-01 10:04:25.247 UTC [7984] ERROR: relation "goose_db_version" does not exist at character 3617242026-10-01 10:04:25.247 UTC [7984] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17252026/10/01 10:04:25 OK 20260920000000_drop_claims.sql (70.59ms)17262026/10/01 10:04:25 OK 20260923120000_add_pushes.sql (27.62ms)17272026/10/01 10:04:25 goose: successfully migrated database to version: 2026092312000017282026/10/01 10:04:25 OK 1_commit_pending_closure.sql (3.08ms)17292026/10/01 10:04:25 OK 2_object_stats_trigger.sql (637.67µs)17302026/10/01 10:04:25 OK 3_commit_push.sql (430.5µs)17312026/10/01 10:04:25 goose: up to current file version: 317322026/10/01 10:04:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17332026/10/01 10:04:25 INFO Received cleanup request method=DELETE path=/api/pending_closures17342026/10/01 10:04:25 INFO Aborted multipart uploads count=0 kept=017352026/10/01 10:04:25 INFO Received uploads request method=POST path=/api/pending_closures17362026/10/01 10:04:25 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MDNlY2QwNzEtNjcwYy00OTM5LTllYjgtMzcyZmY4NDFmNTg0LjQ0ZDNmYmUzLWY3NzgtNDQ3OS04ODEwLTZmMWVhNWFmZjMxM3gxNzkwODQ5MDYzMzI2NjQ1MDAw parts=1017372026/10/01 10:04:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17382026-10-01 10:04:25.587 UTC [7988] ERROR: relation "goose_db_version" does not exist at character 3617392026-10-01 10:04:25.587 UTC [7988] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17402026/10/01 10:04:25 INFO Completed upload id=117412026/10/01 10:04:25 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017422026/10/01 10:04:25 INFO Received uploads request method=POST path=/api/pending_closures17432026/10/01 10:04:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures17442026/10/01 10:04:25 INFO Aborted multipart uploads count=0 kept=017452026/10/01 10:04:25 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=017462026/10/01 10:04:25 INFO Received cleanup request method=DELETE path=/api/pending_closures17472026/10/01 10:04:25 INFO Vacuumed table table=pending_closures17482026/10/01 10:04:25 INFO Aborted multipart uploads count=1 kept=017492026/10/01 10:04:25 OK 20241026095416_initial_model.sql (337.14ms)17502026/10/01 10:04:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17512026/10/01 10:04:25 INFO Vacuumed table table=pending_objects17522026-10-01 10:04:25.677 UTC [7981] ERROR: Closure does not exist: id=117532026-10-01 10:04:25.677 UTC [7981] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE17542026-10-01 10:04:25.677 UTC [7981] STATEMENT: -- name: CommitPendingClosure :exec1755 SELECT commit_pending_closure($1::bigint)1756 1757--- PASS: TestService_cleanupPendingClosuresHandler (5.92s)1758=== CONT TestResolveDBConnectionString17592026/10/01 10:04:25 OK 20251210153512_drop_unused_gin_index.sql (14.98ms)1760=== RUN TestResolveDBConnectionString/flag_wins1761=== PAUSE TestResolveDBConnectionString/flag_wins1762=== RUN TestResolveDBConnectionString/file_when_flag_empty1763=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1764=== RUN TestResolveDBConnectionString/missing_file_is_an_error1765=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1766=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1767=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1768=== RUN TestResolveDBConnectionString/nothing_configured1769=== PAUSE TestResolveDBConnectionString/nothing_configured1770=== CONT TestGCBugBareHashReferences17712026/10/01 10:04:25 INFO Vacuumed table table=multipart_uploads17722026/10/01 10:04:25 OK 20251218171726_add_pins.sql (60.04ms)17732026/10/01 10:04:25 INFO Vacuumed table table=closures17742026/10/01 10:04:25 INFO Vacuumed table table=objects17752026/10/01 10:04:25 OK 20260628120000_add_object_size_and_stats.sql (103.55ms)17762026/10/01 10:04:25 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001777--- PASS: TestService_createPendingClosureHandler (8.10s)1778=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock17792026/10/01 10:04:25 OK 20241026095416_initial_model.sql (224.94ms)1780=== NAME TestOrphanedObjectsGCStressTest1781 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains17822026/10/01 10:04:25 OK 20251210153512_drop_unused_gin_index.sql (15.83ms)17832026/10/01 10:04:25 OK 20260905000000_add_claims.sql (92.47ms)17842026-10-01 10:04:25.948 UTC [7992] ERROR: relation "goose_db_version" does not exist at character 3617852026-10-01 10:04:25.948 UTC [7992] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17862026/10/01 10:04:25 OK 20251218171726_add_pins.sql (31.31ms)17872026/10/01 10:04:25 OK 20260920000000_drop_claims.sql (22.19ms)17882026/10/01 10:04:25 OK 20260923120000_add_pushes.sql (3.93ms)17892026/10/01 10:04:25 goose: successfully migrated database to version: 2026092312000017902026/10/01 10:04:25 OK 20260628120000_add_object_size_and_stats.sql (17.96ms)1791 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17922026/10/01 10:04:25 OK 1_commit_pending_closure.sql (2.64ms)17932026/10/01 10:04:25 OK 2_object_stats_trigger.sql (762.67µs)17942026/10/01 10:04:25 OK 3_commit_push.sql (448.71µs)17952026/10/01 10:04:25 goose: up to current file version: 317962026/10/01 10:04:26 OK 20260905000000_add_claims.sql (39.93ms)17972026/10/01 10:04:26 OK 20260920000000_drop_claims.sql (14.18ms)17982026/10/01 10:04:26 OK 20260923120000_add_pushes.sql (7.53ms)17992026/10/01 10:04:26 goose: successfully migrated database to version: 2026092312000018002026/10/01 10:04:26 OK 1_commit_pending_closure.sql (963.08µs)18012026/10/01 10:04:26 OK 2_object_stats_trigger.sql (281µs)18022026/10/01 10:04:26 OK 3_commit_push.sql (211.13µs)18032026/10/01 10:04:26 goose: up to current file version: 318042026/10/01 10:04:26 OK 20241026095416_initial_model.sql (99.89ms)18052026/10/01 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (11.31ms)18062026/10/01 10:04:26 OK 20251218171726_add_pins.sql (16.89ms)18072026/10/01 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (25.41ms)18082026/10/01 10:04:26 INFO Received uploads request method=POST path=/api/pending_closures1809=== NAME TestNARDeduplicationMetadataUploadBug1810 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-7135-908923472/TestNARDeduplicationMetadataUploadBug389991220/001/store/anvb8bqjl0cmmhv7w3fcdyvsmzma28v0-file1.txt18112026/10/01 10:04:26 OK 20260905000000_add_claims.sql (67.93ms)18122026/10/01 10:04:26 OK 20260920000000_drop_claims.sql (52.11ms)18132026/10/01 10:04:26 INFO Received push request method=POST path=/api/pushes18142026/10/01 10:04:26 OK 20260923120000_add_pushes.sql (14.89ms)18152026/10/01 10:04:26 goose: successfully migrated database to version: 2026092312000018162026/10/01 10:04:26 OK 1_commit_pending_closure.sql (2.83ms)18172026/10/01 10:04:26 OK 2_object_stats_trigger.sql (341.13µs)18182026/10/01 10:04:26 OK 3_commit_push.sql (210.25µs)18192026/10/01 10:04:26 goose: up to current file version: 318202026/10/01 10:04:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18212026/10/01 10:04:26 INFO Uploading anvb8bqjl0cmmhv7w3fcdyvsmzma28v0-file1.txt (160B)18222026/10/01 10:04:26 WARN Failed to register uploaded object key=anvb8bqjl0cmmhv7w3fcdyvsmzma28v0.ls error="server returned 404: 404 page not found\n"18232026/10/01 10:04:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18242026/10/01 10:04:26 INFO Signed narinfos id=1 count=118252026/10/01 10:04:26 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18262026/10/01 10:04:26 INFO Uploading 1 narinfos18272026/10/01 10:04:26 INFO Received complete push request method=POST path=/api/pushes/1/complete18282026/10/01 10:04:26 WARN Failed to register uploaded object key=anvb8bqjl0cmmhv7w3fcdyvsmzma28v0.narinfo error="server returned 404: 404 page not found\n"18292026/10/01 10:04:26 INFO Upload complete. (157ms)1830 metadata_upload_test.go:54: Retrieved narinfo from S3:1831 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestNARDeduplicationMetadataUploadBug389991220/001/store/anvb8bqjl0cmmhv7w3fcdyvsmzma28v0-file1.txt1832 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1833 Compression: zstd1834 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1835 NarSize: 1601836 References: 1837 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1838 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1839 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1840 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18412026/10/01 10:04:26 INFO lead: acquired remote=192.0.2.1:12341842 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-7135-908923472/TestNARDeduplicationMetadataUploadBug389991220/001/store/2mv49kfmw131hdpfk53mj43i8cfjpn04-file2.txt18432026/10/01 10:04:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18442026/10/01 10:04:26 INFO Received push request method=POST path=/api/pushes18452026/10/01 10:04:26 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18462026/10/01 10:04:26 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18472026/10/01 10:04:26 INFO Signed narinfos id=2 count=118482026/10/01 10:04:26 WARN Failed to register uploaded object key=2mv49kfmw131hdpfk53mj43i8cfjpn04.ls error="server returned 404: 404 page not found\n"18492026/10/01 10:04:26 INFO Uploading 1 narinfos18502026/10/01 10:04:26 INFO lead: released remote=192.0.2.1:123418512026/10/01 10:04:26 INFO Received complete push request method=POST path=/api/pushes/2/complete18522026/10/01 10:04:26 WARN Failed to register uploaded object key=2mv49kfmw131hdpfk53mj43i8cfjpn04.narinfo error="server returned 404: 404 page not found\n"18532026/10/01 10:04:26 INFO Upload complete. (122ms)1854 metadata_upload_test.go:76: Retrieved narinfo from S3:1855 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestNARDeduplicationMetadataUploadBug389991220/001/store/2mv49kfmw131hdpfk53mj43i8cfjpn04-file2.txt1856 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1857 Compression: zstd1858 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1859 NarSize: 1601860 References: 1861 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1862 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1863 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1864 {"version":1,"root":{"type":"regular","size":44}}18652026/10/01 10:04:26 INFO lead: acquired remote=192.0.2.1:123418662026/10/01 10:04:26 INFO lead: released remote=192.0.2.1:12341867--- PASS: TestLeadElectsOneAndHandsOver (5.27s)1868=== CONT TestLeadEndsOnShutdown1869--- PASS: TestNARDeduplicationMetadataUploadBug (6.56s)1870=== CONT TestPinProtectsFromGC18712026/10/01 10:04:26 INFO Received uploads request method=POST path=/api/pending_closures1872--- PASS: TestDeduplicatedObjectsRecordedAsPending (5.05s)1873=== CONT TestClientPushesUseOnePush18742026-10-01 10:04:27.081 UTC [8015] ERROR: relation "goose_db_version" does not exist at character 3618752026-10-01 10:04:27.081 UTC [8015] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18762026/10/01 10:04:27 OK 20241026095416_initial_model.sql (251.38ms)18772026/10/01 10:04:27 OK 20251210153512_drop_unused_gin_index.sql (24.75ms)18782026/10/01 10:04:27 OK 20251218171726_add_pins.sql (21.17ms)18792026/10/01 10:04:27 OK 20260628120000_add_object_size_and_stats.sql (63.71ms)18802026/10/01 10:04:27 OK 20260905000000_add_claims.sql (71.52ms)18812026/10/01 10:04:27 OK 20260920000000_drop_claims.sql (18.44ms)18822026/10/01 10:04:27 OK 20260923120000_add_pushes.sql (5.69ms)18832026/10/01 10:04:27 goose: successfully migrated database to version: 2026092312000018842026/10/01 10:04:27 OK 1_commit_pending_closure.sql (4.08ms)18852026/10/01 10:04:27 OK 2_object_stats_trigger.sql (703.58µs)18862026/10/01 10:04:27 OK 3_commit_push.sql (502.25µs)18872026/10/01 10:04:27 goose: up to current file version: 318882026-10-01 10:04:27.976 UTC [8017] ERROR: relation "goose_db_version" does not exist at character 3618892026-10-01 10:04:27.976 UTC [8017] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18902026-10-01 10:04:27.985 UTC [8016] ERROR: relation "goose_db_version" does not exist at character 3618912026-10-01 10:04:27.985 UTC [8016] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18922026/10/01 10:04:28 INFO Received uploads request method=POST path=/api/pending_closures18932026/10/01 10:04:28 OK 20241026095416_initial_model.sql (323.1ms)18942026/10/01 10:04:28 INFO Aborted multipart uploads count=0 kept=018952026/10/01 10:04:28 OK 20251210153512_drop_unused_gin_index.sql (11.66ms)18962026/10/01 10:04:28 OK 20241026095416_initial_model.sql (340.59ms)18972026/10/01 10:04:28 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=018982026/10/01 10:04:28 OK 20251210153512_drop_unused_gin_index.sql (15.09ms)18992026/10/01 10:04:28 OK 20251218171726_add_pins.sql (38.31ms)19002026/10/01 10:04:28 INFO Vacuumed table table=pending_closures19012026/10/01 10:04:28 OK 20251218171726_add_pins.sql (59.71ms)19022026/10/01 10:04:28 INFO Vacuumed table table=pending_objects19032026/10/01 10:04:28 INFO Vacuumed table table=multipart_uploads19042026/10/01 10:04:28 OK 20260628120000_add_object_size_and_stats.sql (68ms)19052026/10/01 10:04:28 INFO Vacuumed table table=closures19062026/10/01 10:04:28 OK 20260628120000_add_object_size_and_stats.sql (36.86ms)19072026/10/01 10:04:28 INFO Vacuumed table table=objects19082026/10/01 10:04:28 INFO Aborted multipart uploads count=0 kept=019092026/10/01 10:04:28 WARN Force mode enabled - objects will be deleted immediately without grace period19102026/10/01 10:04:28 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=019112026/10/01 10:04:28 OK 20260905000000_add_claims.sql (56.81ms)19122026/10/01 10:04:28 INFO Vacuumed table table=pending_closures19132026/10/01 10:04:28 INFO Vacuumed table table=pending_objects19142026/10/01 10:04:28 OK 20260905000000_add_claims.sql (45.82ms)19152026/10/01 10:04:28 INFO Vacuumed table table=multipart_uploads19162026/10/01 10:04:28 OK 20260920000000_drop_claims.sql (9.49ms)19172026/10/01 10:04:28 OK 20260920000000_drop_claims.sql (4.26ms)19182026/10/01 10:04:28 OK 20260923120000_add_pushes.sql (2.63ms)19192026/10/01 10:04:28 goose: successfully migrated database to version: 2026092312000019202026/10/01 10:04:28 INFO Vacuumed table table=closures19212026/10/01 10:04:28 INFO Vacuumed table table=objects19222026/10/01 10:04:28 OK 20260923120000_add_pushes.sql (4.56ms)19232026/10/01 10:04:28 goose: successfully migrated database to version: 2026092312000019242026/10/01 10:04:28 OK 1_commit_pending_closure.sql (5.69ms)1925--- PASS: TestPushDedupSurvivesConcurrentGC (4.49s)1926=== CONT TestClientSharedPathCommittedMidPush19272026/10/01 10:04:28 OK 2_object_stats_trigger.sql (3.92ms)19282026/10/01 10:04:28 OK 1_commit_pending_closure.sql (6.41ms)19292026/10/01 10:04:28 OK 2_object_stats_trigger.sql (2.46ms)19302026/10/01 10:04:28 OK 3_commit_push.sql (3.92ms)19312026/10/01 10:04:28 goose: up to current file version: 319322026-10-01 10:04:28.616 UTC [8019] ERROR: relation "goose_db_version" does not exist at character 3619332026-10-01 10:04:28.616 UTC [8019] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19342026/10/01 10:04:28 OK 3_commit_push.sql (2ms)19352026/10/01 10:04:28 goose: up to current file version: 319362026-10-01 10:04:28.618 UTC [8020] ERROR: relation "goose_db_version" does not exist at character 3619372026-10-01 10:04:28.618 UTC [8020] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19382026/10/01 10:04:28 OK 20241026095416_initial_model.sql (180.16ms)19392026/10/01 10:04:28 OK 20251210153512_drop_unused_gin_index.sql (22.86ms)19402026/10/01 10:04:28 OK 20241026095416_initial_model.sql (205.47ms)19412026/10/01 10:04:28 OK 20251210153512_drop_unused_gin_index.sql (10.71ms)19422026/10/01 10:04:28 OK 20251218171726_add_pins.sql (37.41ms)19432026/10/01 10:04:28 OK 20251218171726_add_pins.sql (35.65ms)19442026/10/01 10:04:28 OK 20260628120000_add_object_size_and_stats.sql (51.81ms)19452026/10/01 10:04:28 OK 20260628120000_add_object_size_and_stats.sql (45.79ms)19462026/10/01 10:04:29 OK 20260905000000_add_claims.sql (167.94ms)19472026/10/01 10:04:29 OK 20260905000000_add_claims.sql (172.31ms)19482026/10/01 10:04:29 OK 20260920000000_drop_claims.sql (51.47ms)19492026/10/01 10:04:29 OK 20260920000000_drop_claims.sql (60.51ms)19502026/10/01 10:04:29 OK 20260923120000_add_pushes.sql (16.56ms)19512026/10/01 10:04:29 goose: successfully migrated database to version: 2026092312000019522026/10/01 10:04:29 OK 1_commit_pending_closure.sql (2.12ms)19532026/10/01 10:04:29 OK 2_object_stats_trigger.sql (527.13µs)19542026/10/01 10:04:29 OK 3_commit_push.sql (445.46µs)19552026/10/01 10:04:29 goose: up to current file version: 319562026/10/01 10:04:29 OK 20260923120000_add_pushes.sql (21.04ms)19572026/10/01 10:04:29 goose: successfully migrated database to version: 2026092312000019582026/10/01 10:04:29 OK 1_commit_pending_closure.sql (2.41ms)19592026/10/01 10:04:29 OK 2_object_stats_trigger.sql (467.75µs)19602026/10/01 10:04:29 OK 3_commit_push.sql (409.08µs)19612026/10/01 10:04:29 goose: up to current file version: 319622026/10/01 10:04:29 INFO Aborted multipart uploads count=0 kept=019632026/10/01 10:04:29 WARN Force mode enabled - objects will be deleted immediately without grace period19642026/10/01 10:04:29 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=019652026/10/01 10:04:29 INFO Vacuumed table table=pending_closures19662026/10/01 10:04:29 INFO Vacuumed table table=pending_objects19672026/10/01 10:04:29 INFO Vacuumed table table=multipart_uploads19682026/10/01 10:04:29 INFO Vacuumed table table=closures19692026/10/01 10:04:29 INFO Vacuumed table table=objects1970--- PASS: TestGCMetrics (4.17s)1971=== CONT TestPush_RejectsBadRequests19722026-10-01 10:04:29.379 UTC [8029] ERROR: relation "goose_db_version" does not exist at character 3619732026-10-01 10:04:29.379 UTC [8029] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19742026-10-01 10:04:29.401 UTC [8031] ERROR: relation "goose_db_version" does not exist at character 3619752026-10-01 10:04:29.401 UTC [8031] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19762026-10-01 10:04:29.433 UTC [8033] ERROR: relation "goose_db_version" does not exist at character 3619772026-10-01 10:04:29.433 UTC [8033] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19782026/10/01 10:04:29 OK 20241026095416_initial_model.sql (99.25ms)19792026/10/01 10:04:29 OK 20251210153512_drop_unused_gin_index.sql (7.63ms)19802026/10/01 10:04:29 OK 20251218171726_add_pins.sql (37.34ms)19812026/10/01 10:04:29 OK 20241026095416_initial_model.sql (146.72ms)19822026/10/01 10:04:29 OK 20260628120000_add_object_size_and_stats.sql (34.02ms)19832026/10/01 10:04:29 OK 20241026095416_initial_model.sql (105.67ms)19842026/10/01 10:04:29 OK 20251210153512_drop_unused_gin_index.sql (3.1ms)19852026/10/01 10:04:29 INFO Received uploads request method=POST path=/api/pending_closures19862026/10/01 10:04:29 OK 20251210153512_drop_unused_gin_index.sql (7.22ms)19872026/10/01 10:04:29 OK 20251218171726_add_pins.sql (7.19ms)19882026/10/01 10:04:29 INFO Received uploads request method=POST path=/api/pending_closures19892026/10/01 10:04:29 OK 20251218171726_add_pins.sql (16.22ms)19902026/10/01 10:04:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19912026/10/01 10:04:29 INFO Uploading 54p3yqxarv8w7xzh21pqzgf2yfp2kxdh-b (248B)19922026/10/01 10:04:29 INFO Uploading 03hn5x8q49kgnq1fv1hsw8h7760r2qw1-shared-dep (136B)19932026/10/01 10:04:29 OK 20260905000000_add_claims.sql (32.62ms)19942026/10/01 10:04:29 WARN Failed to register uploaded object key=54p3yqxarv8w7xzh21pqzgf2yfp2kxdh.ls error="server returned 404: 404 page not found\n"19952026/10/01 10:04:29 WARN Failed to register uploaded object key=657zmgsk3wf9d4q3xjp1d0241xginsfs.ls error="server returned 404: 404 page not found\n"19962026/10/01 10:04:29 OK 20260628120000_add_object_size_and_stats.sql (33.61ms)19972026/10/01 10:04:29 WARN Failed to register uploaded object key=03hn5x8q49kgnq1fv1hsw8h7760r2qw1.ls error="server returned 404: 404 page not found\n"19982026/10/01 10:04:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19992026/10/01 10:04:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20002026/10/01 10:04:29 WARN Failed to register uploaded object key=nar/0whfsza17l2rrbicv6jp80dksc0pd1wls2wfzxcd0kpcvggzj6fy.nar.zst error="server returned 404: 404 page not found\n"20012026/10/01 10:04:29 INFO Signed narinfos id=2 count=220022026/10/01 10:04:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20032026/10/01 10:04:29 INFO Signed narinfos id=1 count=220042026/10/01 10:04:29 INFO Uploading 4 narinfos20052026/10/01 10:04:29 OK 20260920000000_drop_claims.sql (29.03ms)20062026/10/01 10:04:29 OK 20260628120000_add_object_size_and_stats.sql (41.79ms)20072026/10/01 10:04:29 OK 20260923120000_add_pushes.sql (14ms)20082026/10/01 10:04:29 goose: successfully migrated database to version: 2026092312000020092026/10/01 10:04:29 OK 1_commit_pending_closure.sql (1.36ms)20102026/10/01 10:04:29 WARN Failed to register uploaded object key=657zmgsk3wf9d4q3xjp1d0241xginsfs.narinfo error="server returned 404: 404 page not found\n"20112026/10/01 10:04:29 WARN Failed to register uploaded object key=54p3yqxarv8w7xzh21pqzgf2yfp2kxdh.narinfo error="server returned 404: 404 page not found\n"20122026/10/01 10:04:29 OK 2_object_stats_trigger.sql (447.88µs)20132026/10/01 10:04:29 WARN Failed to register uploaded object key=03hn5x8q49kgnq1fv1hsw8h7760r2qw1.narinfo error="server returned 404: 404 page not found\n"20142026/10/01 10:04:29 OK 3_commit_push.sql (187.96µs)20152026/10/01 10:04:29 goose: up to current file version: 32016=== NAME TestOrphanedObjectsGCStressTest2017 orphaned_objects_gc_test.go:509: Stress test completed successfully:2018 orphaned_objects_gc_test.go:510: - Active objects preserved: 202019 orphaned_objects_gc_test.go:511: - Objects deleted: 2102020 orphaned_objects_gc_test.go:512: - Total GC'd: 2102021--- PASS: TestOrphanedObjectsGCStressTest (18.57s)2022=== CONT TestPresignedUploadRegisteredBeforeCommit20232026/10/01 10:04:29 OK 20260905000000_add_claims.sql (72.6ms)20242026/10/01 10:04:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20252026/10/01 10:04:29 WARN Failed to register uploaded object key=03hn5x8q49kgnq1fv1hsw8h7760r2qw1.narinfo error="server returned 404: 404 page not found\n"20262026/10/01 10:04:29 OK 20260905000000_add_claims.sql (57.16ms)20272026/10/01 10:04:29 INFO Completed upload id=120282026/10/01 10:04:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20292026/10/01 10:04:29 INFO Completed upload id=220302026/10/01 10:04:29 INFO Upload complete. (188ms)2031=== NAME TestClientFallsBackToClosures2032 client_pushes_test.go:112: Retrieved narinfo from S3:2033 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestClientFallsBackToClosures114655406/001/store/03hn5x8q49kgnq1fv1hsw8h7760r2qw1-shared-dep2034 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2035 Compression: zstd2036 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822037 NarSize: 1362038 References: 2039 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2040 client_pushes_test.go:112: Retrieved narinfo from S3:2041 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestClientFallsBackToClosures114655406/001/store/657zmgsk3wf9d4q3xjp1d0241xginsfs-a2042 URL: nar/0whfsza17l2rrbicv6jp80dksc0pd1wls2wfzxcd0kpcvggzj6fy.nar.zst2043 Compression: zstd2044 NarHash: sha256:0whfsza17l2rrbicv6jp80dksc0pd1wls2wfzxcd0kpcvggzj6fy2045 NarSize: 2482046 References: /nix/var/nix/builds/nix-7135-908923472/TestClientFallsBackToClosures114655406/001/store/03hn5x8q49kgnq1fv1hsw8h7760r2qw1-shared-dep2047 CA: text:sha256:0w9isxjd37jnqcayhh2hsq80l7xmbhb009krd3ijfqvak23l2b1z2048 client_pushes_test.go:112: Retrieved narinfo from S3:2049 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestClientFallsBackToClosures114655406/001/store/54p3yqxarv8w7xzh21pqzgf2yfp2kxdh-b2050 URL: nar/0whfsza17l2rrbicv6jp80dksc0pd1wls2wfzxcd0kpcvggzj6fy.nar.zst2051 Compression: zstd2052 NarHash: sha256:0whfsza17l2rrbicv6jp80dksc0pd1wls2wfzxcd0kpcvggzj6fy2053 NarSize: 2482054 References: /nix/var/nix/builds/nix-7135-908923472/TestClientFallsBackToClosures114655406/001/store/03hn5x8q49kgnq1fv1hsw8h7760r2qw1-shared-dep2055 CA: text:sha256:0w9isxjd37jnqcayhh2hsq80l7xmbhb009krd3ijfqvak23l2b1z20562026/10/01 10:04:29 OK 20260920000000_drop_claims.sql (30.14ms)20572026/10/01 10:04:29 OK 20260920000000_drop_claims.sql (21.26ms)20582026/10/01 10:04:29 OK 20260923120000_add_pushes.sql (7.23ms)20592026/10/01 10:04:29 goose: successfully migrated database to version: 2026092312000020602026/10/01 10:04:29 OK 1_commit_pending_closure.sql (962.96µs)20612026/10/01 10:04:29 OK 2_object_stats_trigger.sql (220.08µs)20622026/10/01 10:04:29 OK 3_commit_push.sql (192.04µs)20632026/10/01 10:04:29 goose: up to current file version: 320642026/10/01 10:04:29 OK 20260923120000_add_pushes.sql (14.17ms)20652026/10/01 10:04:29 goose: successfully migrated database to version: 2026092312000020662026/10/01 10:04:29 OK 1_commit_pending_closure.sql (855.04µs)20672026/10/01 10:04:29 OK 2_object_stats_trigger.sql (220.5µs)20682026/10/01 10:04:29 OK 3_commit_push.sql (169.71µs)20692026/10/01 10:04:29 goose: up to current file version: 32070--- PASS: TestGCBugBareHashReferences (4.05s)2071=== CONT TestCompletedNarNotReofferedAcrossClosures2072--- PASS: TestClientFallsBackToClosures (4.71s)2073=== CONT TestCompleteMultipartUpload_ErrorButObjectExists20742026/10/01 10:04:29 INFO lead: acquired remote=192.0.2.1:123420752026/10/01 10:04:29 INFO lead: released remote=192.0.2.1:12342076--- PASS: TestLeadEndsOnShutdown (3.30s)2077=== CONT TestRedundantMultipartUpload20782026-10-01 10:04:30.156 UTC [8047] ERROR: relation "goose_db_version" does not exist at character 3620792026-10-01 10:04:30.156 UTC [8047] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20802026/10/01 10:04:30 OK 20241026095416_initial_model.sql (105.58ms)20812026/10/01 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)20822026/10/01 10:04:30 OK 20251218171726_add_pins.sql (17.43ms)20832026/10/01 10:04:30 OK 20260628120000_add_object_size_and_stats.sql (36.26ms)20842026/10/01 10:04:30 OK 20260905000000_add_claims.sql (22.3ms)20852026/10/01 10:04:30 OK 20260920000000_drop_claims.sql (20.05ms)20862026/10/01 10:04:30 OK 20260923120000_add_pushes.sql (3.79ms)20872026/10/01 10:04:30 goose: successfully migrated database to version: 2026092312000020882026/10/01 10:04:30 OK 1_commit_pending_closure.sql (942.42µs)20892026/10/01 10:04:30 OK 2_object_stats_trigger.sql (232.58µs)20902026/10/01 10:04:30 OK 3_commit_push.sql (188.83µs)20912026/10/01 10:04:30 goose: up to current file version: 320922026/10/01 10:04:30 WARN Rate limiter enabled after throttle name=s3-test rate=520932026/10/01 10:04:30 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2094=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2095 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102096 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002097--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (9.39s)2098=== CONT TestPush_SignsNarinfosOfItsPendingObjects20992026-10-01 10:04:30.558 UTC [8061] ERROR: relation "goose_db_version" does not exist at character 3621002026-10-01 10:04:30.558 UTC [8061] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21012026/10/01 10:04:30 INFO Received push request method=POST path=/api/pushes2102=== NAME TestPinProtectsFromGC2103 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-7135-908923472/TestPinProtectsFromGC1914087459/001/store/ds9nbdp1dafklxqwim65582zqmdn4bip-pinned-file.txt2104 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-7135-908923472/TestPinProtectsFromGC1914087459/001/store/j6xikhdfk33brny6dzbmj334q5jazllh-unpinned-file.txt21052026/10/01 10:04:30 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21062026/10/01 10:04:30 INFO Uploading 0admxk9yxlav0q55vnc4s7ra10dgkgv7-shared-dep (136B)21072026/10/01 10:04:30 INFO Uploading crlam1mi3k7ih4f7x5842i9g5khzf2xq-a (248B)21082026/10/01 10:04:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21092026/10/01 10:04:30 WARN Failed to register uploaded object key=0admxk9yxlav0q55vnc4s7ra10dgkgv7.ls error="server returned 404: 404 page not found\n"21102026/10/01 10:04:30 WARN Failed to register uploaded object key=nar/10k50hwjl9nppzqjmhyfgbq49bm9f156vr5bdsd5c476ca99202n.nar.zst error="server returned 404: 404 page not found\n"21112026/10/01 10:04:30 WARN Failed to register uploaded object key=axk06ymh5v9w45l0c3vwa154h74b2rks.ls error="server returned 404: 404 page not found\n"21122026/10/01 10:04:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21132026/10/01 10:04:30 WARN Failed to register uploaded object key=crlam1mi3k7ih4f7x5842i9g5khzf2xq.ls error="server returned 404: 404 page not found\n"21142026/10/01 10:04:30 INFO Signed narinfos id=1 count=321152026/10/01 10:04:30 INFO Uploading 3 narinfos21162026/10/01 10:04:30 WARN Failed to register uploaded object key=crlam1mi3k7ih4f7x5842i9g5khzf2xq.narinfo error="server returned 404: 404 page not found\n"21172026/10/01 10:04:30 WARN Failed to register uploaded object key=axk06ymh5v9w45l0c3vwa154h74b2rks.narinfo error="server returned 404: 404 page not found\n"21182026/10/01 10:04:30 INFO Received complete push request method=POST path=/api/pushes/1/complete21192026/10/01 10:04:30 WARN Failed to register uploaded object key=0admxk9yxlav0q55vnc4s7ra10dgkgv7.narinfo error="server returned 404: 404 page not found\n"21202026/10/01 10:04:30 OK 20241026095416_initial_model.sql (85.01ms)21212026/10/01 10:04:30 INFO Upload complete. (93ms)2122=== NAME TestClientPushesUseOnePush2123 client_pushes_test.go:97: Retrieved narinfo from S3:2124 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestClientPushesUseOnePush2604118117/001/store/0admxk9yxlav0q55vnc4s7ra10dgkgv7-shared-dep2125 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2126 Compression: zstd2127 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822128 NarSize: 1362129 References: 2130 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2131 client_pushes_test.go:97: Retrieved narinfo from S3:2132 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestClientPushesUseOnePush2604118117/001/store/crlam1mi3k7ih4f7x5842i9g5khzf2xq-a2133 URL: nar/10k50hwjl9nppzqjmhyfgbq49bm9f156vr5bdsd5c476ca99202n.nar.zst2134 Compression: zstd2135 NarHash: sha256:10k50hwjl9nppzqjmhyfgbq49bm9f156vr5bdsd5c476ca99202n2136 NarSize: 2482137 References: /nix/var/nix/builds/nix-7135-908923472/TestClientPushesUseOnePush2604118117/001/store/0admxk9yxlav0q55vnc4s7ra10dgkgv7-shared-dep2138 CA: text:sha256:0lgdpv78g46m45nhqks5vbxggnp24mymni1c5wnhs8djr7x9nd1i2139 client_pushes_test.go:97: Retrieved narinfo from S3:2140 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestClientPushesUseOnePush2604118117/001/store/axk06ymh5v9w45l0c3vwa154h74b2rks-b2141 URL: nar/10k50hwjl9nppzqjmhyfgbq49bm9f156vr5bdsd5c476ca99202n.nar.zst2142 Compression: zstd2143 NarHash: sha256:10k50hwjl9nppzqjmhyfgbq49bm9f156vr5bdsd5c476ca99202n2144 NarSize: 2482145 References: /nix/var/nix/builds/nix-7135-908923472/TestClientPushesUseOnePush2604118117/001/store/0admxk9yxlav0q55vnc4s7ra10dgkgv7-shared-dep2146 CA: text:sha256:0lgdpv78g46m45nhqks5vbxggnp24mymni1c5wnhs8djr7x9nd1i21472026/10/01 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (6.72ms)21482026/10/01 10:04:30 OK 20251218171726_add_pins.sql (3.13ms)2149--- PASS: TestClientPushesUseOnePush (3.80s)2150=== CONT TestService_ReadScope_PublicByDefault21512026/10/01 10:04:30 OK 20260628120000_add_object_size_and_stats.sql (41.95ms)2152--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (4.87s)2153=== CONT TestService_RequireScope_OIDC21542026/10/01 10:04:30 INFO Received push request method=POST path=/api/pushes21552026/10/01 10:04:30 OK 20260905000000_add_claims.sql (12.35ms)21562026/10/01 10:04:30 OK 20260920000000_drop_claims.sql (6.11ms)21572026/10/01 10:04:30 OK 20260923120000_add_pushes.sql (12.51ms)21582026/10/01 10:04:30 goose: successfully migrated database to version: 2026092312000021592026/10/01 10:04:30 OK 1_commit_pending_closure.sql (2.65ms)21602026/10/01 10:04:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21612026/10/01 10:04:30 INFO Uploading ds9nbdp1dafklxqwim65582zqmdn4bip-pinned-file.txt (128B)21622026/10/01 10:04:30 OK 2_object_stats_trigger.sql (1.28ms)21632026/10/01 10:04:30 OK 3_commit_push.sql (777.29µs)21642026/10/01 10:04:30 goose: up to current file version: 321652026-10-01 10:04:30.757 UTC [8076] ERROR: relation "goose_db_version" does not exist at character 3621662026-10-01 10:04:30.757 UTC [8076] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21672026/10/01 10:04:30 WARN Failed to register uploaded object key=ds9nbdp1dafklxqwim65582zqmdn4bip.ls error="server returned 404: 404 page not found\n"21682026/10/01 10:04:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21692026/10/01 10:04:30 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"21702026/10/01 10:04:30 INFO Signed narinfos id=1 count=121712026/10/01 10:04:30 INFO Uploading 1 narinfos21722026/10/01 10:04:30 INFO Received complete push request method=POST path=/api/pushes/1/complete21732026/10/01 10:04:30 WARN Failed to register uploaded object key=ds9nbdp1dafklxqwim65582zqmdn4bip.narinfo error="server returned 404: 404 page not found\n"21742026-10-01 10:04:30.822 UTC [8078] ERROR: relation "goose_db_version" does not exist at character 3621752026-10-01 10:04:30.822 UTC [8078] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21762026/10/01 10:04:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58485/oidc21772026/10/01 10:04:30 INFO Upload complete. (175ms)21782026-10-01 10:04:30.897 UTC [8083] ERROR: relation "goose_db_version" does not exist at character 3621792026-10-01 10:04:30.897 UTC [8083] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21802026/10/01 10:04:30 OK 20241026095416_initial_model.sql (65.77ms)21812026/10/01 10:04:30 INFO Received push request method=POST path=/api/pushes21822026/10/01 10:04:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21832026/10/01 10:04:30 INFO Uploading j6xikhdfk33brny6dzbmj334q5jazllh-unpinned-file.txt (128B)21842026/10/01 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (9.36ms)21852026/10/01 10:04:30 WARN Failed to register uploaded object key=j6xikhdfk33brny6dzbmj334q5jazllh.ls error="server returned 404: 404 page not found\n"21862026/10/01 10:04:30 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21872026/10/01 10:04:30 INFO Signed narinfos id=2 count=121882026/10/01 10:04:30 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"21892026/10/01 10:04:30 INFO Uploading 1 narinfos21902026/10/01 10:04:30 INFO Received push request method=POST path=/api/pushes21912026/10/01 10:04:30 OK 20251218171726_add_pins.sql (10.4ms)21922026/10/01 10:04:30 OK 20241026095416_initial_model.sql (74.05ms)21932026/10/01 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (13.45ms)21942026/10/01 10:04:30 INFO Received complete push request method=POST path=/api/pushes/2/complete21952026/10/01 10:04:30 WARN Failed to register uploaded object key=j6xikhdfk33brny6dzbmj334q5jazllh.narinfo error="server returned 404: 404 page not found\n"21962026/10/01 10:04:30 INFO Upload complete. (83ms)21972026/10/01 10:04:30 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)21982026/10/01 10:04:30 INFO Uploading vp0bvlbr1n5a7gf0lgdykpy8nzn4mx3a-top (256B)21992026/10/01 10:04:30 INFO Uploading 6s8r2wnh7nb49bd2vc93d9d16cxh2sm7-shared-dep (136B)22002026/10/01 10:04:30 WARN Failed to register uploaded object key=vp0bvlbr1n5a7gf0lgdykpy8nzn4mx3a.ls error="server returned 404: 404 page not found\n"22012026/10/01 10:04:30 OK 20260628120000_add_object_size_and_stats.sql (40.09ms)22022026/10/01 10:04:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22032026/10/01 10:04:30 OK 20251218171726_add_pins.sql (26.91ms)22042026/10/01 10:04:30 WARN Failed to register uploaded object key=nar/16wzn67089jja816ps9q4vxml64n3ksg1ssasfnlja7d55xdylc5.nar.zst error="server returned 404: 404 page not found\n"22052026/10/01 10:04:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22062026/10/01 10:04:30 WARN Failed to register uploaded object key=6s8r2wnh7nb49bd2vc93d9d16cxh2sm7.ls error="server returned 404: 404 page not found\n"22072026/10/01 10:04:30 INFO Signed narinfos id=1 count=222082026/10/01 10:04:30 INFO Uploading 2 narinfos22092026/10/01 10:04:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures22102026/10/01 10:04:31 INFO Received complete push request method=POST path=/api/pushes/1/complete22112026/10/01 10:04:31 INFO Garbage collection started22122026/10/01 10:04:31 WARN Failed to register uploaded object key=6s8r2wnh7nb49bd2vc93d9d16cxh2sm7.narinfo error="server returned 404: 404 page not found\n"22132026/10/01 10:04:31 WARN Failed to register uploaded object key=vp0bvlbr1n5a7gf0lgdykpy8nzn4mx3a.narinfo error="server returned 404: 404 page not found\n"22142026/10/01 10:04:31 OK 20260628120000_add_object_size_and_stats.sql (33.96ms)22152026/10/01 10:04:31 INFO Aborted multipart uploads count=0 kept=022162026/10/01 10:04:31 INFO Upload complete. (124ms)2217=== NAME TestClientSharedPathCommittedMidPush2218 client_integration_test.go:680: Retrieved narinfo from S3:2219 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestClientSharedPathCommittedMidPush758377537/001/store/6s8r2wnh7nb49bd2vc93d9d16cxh2sm7-shared-dep2220 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2221 Compression: zstd2222 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822223 NarSize: 1362224 References: 2225 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n22262026/10/01 10:04:31 WARN Force mode enabled - objects will be deleted immediately without grace period2227 client_integration_test.go:680: Retrieved narinfo from S3:2228 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestClientSharedPathCommittedMidPush758377537/001/store/vp0bvlbr1n5a7gf0lgdykpy8nzn4mx3a-top2229 URL: nar/16wzn67089jja816ps9q4vxml64n3ksg1ssasfnlja7d55xdylc5.nar.zst2230 Compression: zstd2231 NarHash: sha256:16wzn67089jja816ps9q4vxml64n3ksg1ssasfnlja7d55xdylc52232 NarSize: 2562233 References: /nix/var/nix/builds/nix-7135-908923472/TestClientSharedPathCommittedMidPush758377537/001/store/6s8r2wnh7nb49bd2vc93d9d16cxh2sm7-shared-dep2234 CA: text:sha256:1l3pkbihmxpfcb1iari14g8c1cpqg1as6432pra2qcbsc76x095x22352026/10/01 10:04:31 OK 20260905000000_add_claims.sql (54.11ms)2236=== RUN TestPush_RejectsBadRequests/no_roots2237=== PAUSE TestPush_RejectsBadRequests/no_roots2238=== RUN TestPush_RejectsBadRequests/no_objects2239=== PAUSE TestPush_RejectsBadRequests/no_objects2240=== RUN TestPush_RejectsBadRequests/bad_root2241=== PAUSE TestPush_RejectsBadRequests/bad_root2242=== RUN TestPush_RejectsBadRequests/root_not_in_objects2243=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2244=== CONT TestPush_OverlappingRootsStoreOneRowPerKey22452026/10/01 10:04:31 OK 20260920000000_drop_claims.sql (16ms)22462026/10/01 10:04:31 OK 20260905000000_add_claims.sql (36.48ms)2247--- PASS: TestClientSharedPathCommittedMidPush (2.44s)2248=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit22492026/10/01 10:04:31 OK 20260923120000_add_pushes.sql (8.37ms)22502026/10/01 10:04:31 goose: successfully migrated database to version: 2026092312000022512026/10/01 10:04:31 OK 1_commit_pending_closure.sql (1.57ms)22522026/10/01 10:04:31 OK 2_object_stats_trigger.sql (248.08µs)22532026/10/01 10:04:31 OK 3_commit_push.sql (239.54µs)22542026/10/01 10:04:31 goose: up to current file version: 322552026/10/01 10:04:31 OK 20241026095416_initial_model.sql (126.97ms)22562026/10/01 10:04:31 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=022572026/10/01 10:04:31 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)22582026/10/01 10:04:31 OK 20260920000000_drop_claims.sql (22.48ms)22592026/10/01 10:04:31 OK 20260923120000_add_pushes.sql (20.63ms)22602026/10/01 10:04:31 goose: successfully migrated database to version: 2026092312000022612026/10/01 10:04:31 OK 1_commit_pending_closure.sql (833µs)22622026/10/01 10:04:31 OK 2_object_stats_trigger.sql (217.96µs)22632026/10/01 10:04:31 OK 3_commit_push.sql (178.42µs)22642026/10/01 10:04:31 goose: up to current file version: 322652026/10/01 10:04:31 INFO Vacuumed table table=pending_closures22662026/10/01 10:04:31 OK 20251218171726_add_pins.sql (42.09ms)22672026/10/01 10:04:31 INFO Vacuumed table table=pending_objects22682026/10/01 10:04:31 INFO Vacuumed table table=multipart_uploads22692026/10/01 10:04:31 OK 20260628120000_add_object_size_and_stats.sql (40.1ms)22702026/10/01 10:04:31 INFO Vacuumed table table=closures22712026/10/01 10:04:31 INFO Vacuumed table table=objects22722026/10/01 10:04:31 OK 20260905000000_add_claims.sql (31.32ms)22732026/10/01 10:04:31 OK 20260920000000_drop_claims.sql (16.43ms)22742026/10/01 10:04:31 OK 20260923120000_add_pushes.sql (10.73ms)22752026/10/01 10:04:31 goose: successfully migrated database to version: 2026092312000022762026/10/01 10:04:31 OK 1_commit_pending_closure.sql (1.64ms)22772026/10/01 10:04:31 OK 2_object_stats_trigger.sql (254.33µs)22782026/10/01 10:04:31 OK 3_commit_push.sql (210.21µs)22792026/10/01 10:04:31 goose: up to current file version: 322802026/10/01 10:04:31 INFO Received uploads request method=POST path=/api/pending_closures22812026-10-01 10:04:31.329 UTC [8099] ERROR: relation "goose_db_version" does not exist at character 3622822026-10-01 10:04:31.329 UTC [8099] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22832026/10/01 10:04:31 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst22842026/10/01 10:04:31 INFO Received uploads request method=POST path=/api/pending_closures2285--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.68s)2286=== CONT TestPush_CompleteCommitsEveryRoot22872026/10/01 10:04:31 OK 20241026095416_initial_model.sql (87.79ms)22882026/10/01 10:04:31 OK 20251210153512_drop_unused_gin_index.sql (8.77ms)22892026/10/01 10:04:31 INFO Received uploads request method=POST path=/api/pending_closures22902026/10/01 10:04:31 OK 20251218171726_add_pins.sql (24.92ms)22912026/10/01 10:04:31 OK 20260628120000_add_object_size_and_stats.sql (58.92ms)22922026/10/01 10:04:31 OK 20260905000000_add_claims.sql (64.16ms)22932026/10/01 10:04:31 OK 20260920000000_drop_claims.sql (10.99ms)22942026/10/01 10:04:31 OK 20260923120000_add_pushes.sql (17.68ms)22952026/10/01 10:04:31 goose: successfully migrated database to version: 2026092312000022962026/10/01 10:04:31 OK 1_commit_pending_closure.sql (2.44ms)22972026/10/01 10:04:31 OK 2_object_stats_trigger.sql (456µs)22982026/10/01 10:04:31 OK 3_commit_push.sql (336.33µs)22992026/10/01 10:04:31 goose: up to current file version: 323002026/10/01 10:04:31 INFO Received uploads request method=POST path=/api/pending_closures23012026-10-01 10:04:31.896 UTC [8102] ERROR: relation "goose_db_version" does not exist at character 3623022026-10-01 10:04:31.896 UTC [8102] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23032026/10/01 10:04:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23042026/10/01 10:04:32 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDNlY2QwNzEtNjcwYy00OTM5LTllYjgtMzcyZmY4NDFmNTg0LjNmNmVlNjU1LThiMjktNDdlNy04NzBlLWEyMjFkZTc4ZmU1NXgxNzkwODQ5MDcxODQ4NjI4MDAw23052026/10/01 10:04:32 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDNlY2QwNzEtNjcwYy00OTM5LTllYjgtMzcyZmY4NDFmNTg0LjNmNmVlNjU1LThiMjktNDdlNy04NzBlLWEyMjFkZTc4ZmU1NXgxNzkwODQ5MDcxODQ4NjI4MDAw parts=12306--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.42s)2307=== CONT TestReadProxyRangeRequest23082026/10/01 10:04:32 INFO Received uploads request method=POST path=/api/pending_closures23092026/10/01 10:04:32 OK 20241026095416_initial_model.sql (270.68ms)23102026/10/01 10:04:32 OK 20251210153512_drop_unused_gin_index.sql (22.86ms)23112026/10/01 10:04:32 INFO Received uploads request method=POST path=/api/pending_closures23122026/10/01 10:04:32 OK 20251218171726_add_pins.sql (39.89ms)23132026/10/01 10:04:32 OK 20260628120000_add_object_size_and_stats.sql (25.53ms)23142026/10/01 10:04:32 OK 20260905000000_add_claims.sql (9.31ms)23152026/10/01 10:04:32 OK 20260920000000_drop_claims.sql (6.48ms)23162026/10/01 10:04:32 OK 20260923120000_add_pushes.sql (14.62ms)23172026/10/01 10:04:32 goose: successfully migrated database to version: 2026092312000023182026/10/01 10:04:32 OK 1_commit_pending_closure.sql (1.76ms)23192026/10/01 10:04:32 OK 2_object_stats_trigger.sql (388.83µs)23202026/10/01 10:04:32 OK 3_commit_push.sql (270.42µs)23212026/10/01 10:04:32 goose: up to current file version: 323222026-10-01 10:04:32.490 UTC [8105] ERROR: relation "goose_db_version" does not exist at character 3623232026-10-01 10:04:32.490 UTC [8105] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23242026-10-01 10:04:32.600 UTC [8106] ERROR: relation "goose_db_version" does not exist at character 3623252026-10-01 10:04:32.600 UTC [8106] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23262026/10/01 10:04:32 INFO Received push request method=POST path=/api/pushes23272026/10/01 10:04:32 OK 20241026095416_initial_model.sql (232.42ms)23282026/10/01 10:04:32 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)23292026/10/01 10:04:32 OK 20251218171726_add_pins.sql (26.58ms)23302026/10/01 10:04:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23312026/10/01 10:04:32 INFO Signed narinfos id=1 count=12332--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.33s)2333=== CONT TestService_AuthMiddleware_OIDC23342026/10/01 10:04:32 OK 20241026095416_initial_model.sql (161.38ms)23352026/10/01 10:04:32 OK 20251210153512_drop_unused_gin_index.sql (18.76ms)23362026/10/01 10:04:32 OK 20260628120000_add_object_size_and_stats.sql (32.42ms)23372026/10/01 10:04:32 OK 20251218171726_add_pins.sql (29.4ms)23382026/10/01 10:04:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58521/oidc23392026/10/01 10:04:32 OK 20260905000000_add_claims.sql (45.35ms)23402026/10/01 10:04:32 OK 20260628120000_add_object_size_and_stats.sql (26.43ms)23412026/10/01 10:04:32 OK 20260920000000_drop_claims.sql (16.62ms)23422026/10/01 10:04:32 OK 20260923120000_add_pushes.sql (1.36ms)23432026/10/01 10:04:32 goose: successfully migrated database to version: 2026092312000023442026/10/01 10:04:32 OK 1_commit_pending_closure.sql (1.16ms)23452026/10/01 10:04:32 OK 2_object_stats_trigger.sql (261.58µs)23462026/10/01 10:04:32 OK 3_commit_push.sql (219.92µs)23472026/10/01 10:04:32 goose: up to current file version: 323482026/10/01 10:04:32 OK 20260905000000_add_claims.sql (11.03ms)23492026/10/01 10:04:32 OK 20260920000000_drop_claims.sql (1.56ms)23502026/10/01 10:04:32 OK 20260923120000_add_pushes.sql (1.79ms)23512026/10/01 10:04:32 goose: successfully migrated database to version: 2026092312000023522026/10/01 10:04:32 OK 1_commit_pending_closure.sql (1.1ms)23532026/10/01 10:04:32 OK 2_object_stats_trigger.sql (237.54µs)23542026/10/01 10:04:32 OK 3_commit_push.sql (184.75µs)23552026/10/01 10:04:32 goose: up to current file version: 323562026-10-01 10:04:32.926 UTC [8110] ERROR: relation "goose_db_version" does not exist at character 3623572026-10-01 10:04:32.926 UTC [8110] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23582026-10-01 10:04:32.926 UTC [8109] ERROR: relation "goose_db_version" does not exist at character 3623592026-10-01 10:04:32.926 UTC [8109] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23602026/10/01 10:04:33 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023612026/10/01 10:04:33 INFO Received create pin request method=POST path=/api/pins/myapp23622026/10/01 10:04:33 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-7135-908923472/TestPinProtectsFromGC1914087459/001/store/ds9nbdp1dafklxqwim65582zqmdn4bip-pinned-file.txt narinfo_key=ds9nbdp1dafklxqwim65582zqmdn4bip.narinfo23632026/10/01 10:04:33 INFO Starting cleanup of old closures method=DELETE path=/api/closures23642026/10/01 10:04:33 INFO Garbage collection started23652026/10/01 10:04:33 INFO Aborted multipart uploads count=0 kept=023662026/10/01 10:04:33 WARN Force mode enabled - objects will be deleted immediately without grace period23672026/10/01 10:04:33 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 10:04:33 INFO Vacuumed table table=pending_closures23692026/10/01 10:04:33 INFO Vacuumed table table=pending_objects23702026/10/01 10:04:33 INFO Vacuumed table table=multipart_uploads23712026/10/01 10:04:33 INFO Vacuumed table table=closures23722026/10/01 10:04:33 INFO Vacuumed table table=objects23732026/10/01 10:04:33 OK 20241026095416_initial_model.sql (253.02ms)23742026/10/01 10:04:33 OK 20241026095416_initial_model.sql (253.44ms)23752026/10/01 10:04:33 OK 20251210153512_drop_unused_gin_index.sql (9.33ms)2376--- PASS: TestService_ReadScope_PublicByDefault (2.57s)2377=== CONT TestReadRedirectUsesPublicS3URL23782026/10/01 10:04:33 OK 20251210153512_drop_unused_gin_index.sql (22.86ms)23792026/10/01 10:04:33 OK 20251218171726_add_pins.sql (63.9ms)23802026/10/01 10:04:33 OK 20251218171726_add_pins.sql (49.96ms)23812026/10/01 10:04:33 OK 20260628120000_add_object_size_and_stats.sql (60.09ms)23822026/10/01 10:04:33 OK 20260628120000_add_object_size_and_stats.sql (60.25ms)23832026/10/01 10:04:33 OK 20260905000000_add_claims.sql (38.45ms)23842026/10/01 10:04:33 OK 20260905000000_add_claims.sql (38.48ms)23852026/10/01 10:04:33 OK 20260920000000_drop_claims.sql (62.78ms)23862026/10/01 10:04:33 OK 20260920000000_drop_claims.sql (70ms)23872026/10/01 10:04:33 OK 20260923120000_add_pushes.sql (25.18ms)23882026/10/01 10:04:33 goose: successfully migrated database to version: 2026092312000023892026/10/01 10:04:33 OK 1_commit_pending_closure.sql (2.87ms)23902026/10/01 10:04:33 OK 2_object_stats_trigger.sql (619.38µs)23912026/10/01 10:04:33 OK 3_commit_push.sql (392.54µs)23922026/10/01 10:04:33 goose: up to current file version: 323932026/10/01 10:04:33 OK 20260923120000_add_pushes.sql (27.56ms)23942026/10/01 10:04:33 goose: successfully migrated database to version: 2026092312000023952026/10/01 10:04:33 OK 1_commit_pending_closure.sql (3.58ms)23962026/10/01 10:04:33 OK 2_object_stats_trigger.sql (848.04µs)23972026/10/01 10:04:33 OK 3_commit_push.sql (559.17µs)23982026/10/01 10:04:33 goose: up to current file version: 323992026-10-01 10:04:33.530 UTC [8113] ERROR: relation "goose_db_version" does not exist at character 3624002026-10-01 10:04:33.530 UTC [8113] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24012026/10/01 10:04:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24022026/10/01 10:04:33 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MDNlY2QwNzEtNjcwYy00OTM5LTllYjgtMzcyZmY4NDFmNTg0LjE5ZDQ2NjU3LTc1ZWUtNDZjMS04ODVmLWFlNTMyYTc1YjA1NXgxNzkwODQ5MDcxNTcyODk3MDAw parts=1224032026/10/01 10:04:33 INFO Received uploads request method=POST path=/api/pending_closures2404--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.86s)2405=== CONT TestClientErrorHandling2406=== RUN TestClientErrorHandling/InvalidStorePath2407=== PAUSE TestClientErrorHandling/InvalidStorePath2408=== RUN TestClientErrorHandling/InvalidAuthToken2409=== PAUSE TestClientErrorHandling/InvalidAuthToken2410=== RUN TestClientErrorHandling/ServerNotAvailable2411=== PAUSE TestClientErrorHandling/ServerNotAvailable2412=== CONT TestClientMultipleUploads2413=== RUN TestService_RequireScope_OIDC/builder_may_write2414=== PAUSE TestService_RequireScope_OIDC/builder_may_write2415=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2416=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2417=== RUN TestService_RequireScope_OIDC/ops_may_admin2418=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2419=== RUN TestService_RequireScope_OIDC/ops_may_not_write2420=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2421=== RUN TestService_RequireScope_OIDC/reader_may_not_write2422=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2423=== RUN TestService_RequireScope_OIDC/static_token_may_admin2424=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2425=== RUN TestService_RequireScope_OIDC/static_token_may_write2426=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2427=== RUN TestService_RequireScope_OIDC/reader_may_read2428=== PAUSE TestService_RequireScope_OIDC/reader_may_read2429=== RUN TestService_RequireScope_OIDC/writer_implies_read2430=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2431=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2432=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2433=== CONT TestService_AuthMiddleware_MTLSBoundSubjects24342026/10/01 10:04:33 OK 20241026095416_initial_model.sql (209.24ms)24352026/10/01 10:04:33 OK 20251210153512_drop_unused_gin_index.sql (3.92ms)24362026/10/01 10:04:33 OK 20251218171726_add_pins.sql (22.13ms)24372026/10/01 10:04:33 OK 20260628120000_add_object_size_and_stats.sql (45.04ms)24382026/10/01 10:04:33 INFO Received push request method=POST path=/api/pushes24392026/10/01 10:04:33 OK 20260905000000_add_claims.sql (68.08ms)24402026/10/01 10:04:33 OK 20260920000000_drop_claims.sql (44.99ms)24412026/10/01 10:04:34 OK 20260923120000_add_pushes.sql (40.54ms)24422026/10/01 10:04:34 goose: successfully migrated database to version: 2026092312000024432026/10/01 10:04:34 OK 1_commit_pending_closure.sql (6.15ms)24442026/10/01 10:04:34 OK 2_object_stats_trigger.sql (1ms)24452026/10/01 10:04:34 OK 3_commit_push.sql (481.67µs)24462026/10/01 10:04:34 goose: up to current file version: 324472026/10/01 10:04:34 INFO Received complete push request method=POST path=/api/pushes/1/complete24482026/10/01 10:04:34 INFO Received push request method=POST path=/api/pushes24492026/10/01 10:04:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24502026/10/01 10:04:34 INFO Aborted multipart uploads count=0 kept=024512026/10/01 10:04:34 WARN Force mode enabled - objects will be deleted immediately without grace period24522026/10/01 10:04:34 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=024532026/10/01 10:04:34 INFO Vacuumed table table=pending_closures24542026/10/01 10:04:34 INFO Vacuumed table table=pending_objects24552026/10/01 10:04:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MDNlY2QwNzEtNjcwYy00OTM5LTllYjgtMzcyZmY4NDFmNTg0LjgxMzQxNjU1LTdiYjUtNDk0ZC1hMWNiLTY0ZDg5OTc5NDVjYngxNzkwODQ5MDcyMjMzMzQ0MDAw parts=1224562026/10/01 10:04:34 INFO Received uploads request method=POST path=/api/pending_closures24572026/10/01 10:04:34 INFO Vacuumed table table=multipart_uploads24582026/10/01 10:04:34 INFO Received uploads request method=POST path=/api/pending_closures24592026/10/01 10:04:34 INFO Vacuumed table table=closures24602026/10/01 10:04:34 INFO Received push request method=POST path=/api/pushes24612026/10/01 10:04:34 INFO Vacuumed table table=objects24622026/10/01 10:04:34 INFO Received complete push request method=POST path=/api/pushes/2/complete2463--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.32s)2464=== CONT TestClientIntegration2465--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.41s)2466=== CONT TestService_ReadAuthMiddleware24672026-10-01 10:04:34.500 UTC [8123] ERROR: relation "goose_db_version" does not exist at character 3624682026-10-01 10:04:34.500 UTC [8123] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24692026/10/01 10:04:34 INFO Received push request method=POST path=/api/pushes24702026/10/01 10:04:34 INFO Received complete push request method=POST path=/api/pushes/1/complete24712026/10/01 10:04:34 OK 20241026095416_initial_model.sql (199.11ms)24722026/10/01 10:04:34 OK 20251210153512_drop_unused_gin_index.sql (14.58ms)2473--- PASS: TestPush_CompleteCommitsEveryRoot (3.44s)2474=== CONT TestReadRedirectKeepsNarinfoProxied24752026/10/01 10:04:34 OK 20251218171726_add_pins.sql (20.79ms)24762026/10/01 10:04:34 OK 20260628120000_add_object_size_and_stats.sql (14.02ms)24772026/10/01 10:04:34 OK 20260905000000_add_claims.sql (2.2ms)24782026/10/01 10:04:34 OK 20260920000000_drop_claims.sql (1.34ms)24792026/10/01 10:04:34 OK 20260923120000_add_pushes.sql (1.23ms)24802026/10/01 10:04:34 goose: successfully migrated database to version: 2026092312000024812026/10/01 10:04:34 OK 1_commit_pending_closure.sql (1.39ms)24822026/10/01 10:04:34 OK 2_object_stats_trigger.sql (316.88µs)24832026/10/01 10:04:34 OK 3_commit_push.sql (247.96µs)24842026/10/01 10:04:34 goose: up to current file version: 324852026-10-01 10:04:34.815 UTC [8130] ERROR: relation "goose_db_version" does not exist at character 3624862026-10-01 10:04:34.815 UTC [8130] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24872026/10/01 10:04:35 OK 20241026095416_initial_model.sql (150.52ms)24882026/10/01 10:04:35 OK 20251210153512_drop_unused_gin_index.sql (8.51ms)2489=== NAME TestPinProtectsFromGC2490 client_integration_test.go:840: Pin successfully protected closure from garbage collection24912026/10/01 10:04:35 OK 20251218171726_add_pins.sql (35.22ms)24922026/10/01 10:04:35 OK 20260628120000_add_object_size_and_stats.sql (21.98ms)2493--- PASS: TestPinProtectsFromGC (8.32s)2494=== CONT TestService_AuthMiddleware_MTLSProxyHeader2495--- PASS: TestReadProxyRangeRequest (2.96s)2496=== CONT TestCacheStatsHandler24972026/10/01 10:04:35 OK 20260905000000_add_claims.sql (69.79ms)24982026/10/01 10:04:35 OK 20260920000000_drop_claims.sql (25.7ms)24992026/10/01 10:04:35 OK 20260923120000_add_pushes.sql (25.44ms)25002026/10/01 10:04:35 goose: successfully migrated database to version: 2026092312000025012026/10/01 10:04:35 OK 1_commit_pending_closure.sql (2.18ms)25022026/10/01 10:04:35 OK 2_object_stats_trigger.sql (918.33µs)25032026/10/01 10:04:35 OK 3_commit_push.sql (308.17µs)25042026/10/01 10:04:35 goose: up to current file version: 325052026-10-01 10:04:35.335 UTC [8135] ERROR: relation "goose_db_version" does not exist at character 3625062026-10-01 10:04:35.335 UTC [8135] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2507=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2508=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2509=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2510=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2511=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2512=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2513=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2514=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2515=== CONT TestClientCADerivations25162026/10/01 10:04:35 OK 20241026095416_initial_model.sql (213.67ms)25172026/10/01 10:04:35 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)25182026-10-01 10:04:35.622 UTC [8138] ERROR: relation "goose_db_version" does not exist at character 3625192026-10-01 10:04:35.622 UTC [8138] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25202026/10/01 10:04:35 OK 20251218171726_add_pins.sql (2.51ms)25212026-10-01 10:04:35.623 UTC [8139] ERROR: relation "goose_db_version" does not exist at character 3625222026-10-01 10:04:35.623 UTC [8139] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25232026/10/01 10:04:35 OK 20260628120000_add_object_size_and_stats.sql (2.39ms)25242026/10/01 10:04:35 OK 20260905000000_add_claims.sql (12.67ms)25252026/10/01 10:04:35 OK 20260920000000_drop_claims.sql (26.91ms)25262026/10/01 10:04:35 OK 20260923120000_add_pushes.sql (10.99ms)25272026/10/01 10:04:35 goose: successfully migrated database to version: 2026092312000025282026/10/01 10:04:35 OK 1_commit_pending_closure.sql (2.56ms)25292026/10/01 10:04:35 OK 2_object_stats_trigger.sql (399.46µs)25302026/10/01 10:04:35 OK 3_commit_push.sql (352.04µs)25312026/10/01 10:04:35 goose: up to current file version: 325322026/10/01 10:04:35 OK 20241026095416_initial_model.sql (137.95ms)25332026/10/01 10:04:35 OK 20241026095416_initial_model.sql (126.77ms)25342026/10/01 10:04:35 OK 20251210153512_drop_unused_gin_index.sql (9.78ms)25352026/10/01 10:04:35 OK 20251210153512_drop_unused_gin_index.sql (15.86ms)25362026/10/01 10:04:35 OK 20251218171726_add_pins.sql (20.32ms)25372026/10/01 10:04:35 OK 20251218171726_add_pins.sql (29.71ms)25382026/10/01 10:04:35 OK 20260628120000_add_object_size_and_stats.sql (23.5ms)25392026/10/01 10:04:35 OK 20260628120000_add_object_size_and_stats.sql (21.26ms)25402026/10/01 10:04:35 OK 20260905000000_add_claims.sql (74.32ms)25412026/10/01 10:04:35 OK 20260905000000_add_claims.sql (74.42ms)25422026/10/01 10:04:35 OK 20260920000000_drop_claims.sql (32.16ms)25432026/10/01 10:04:35 OK 20260920000000_drop_claims.sql (33.35ms)25442026/10/01 10:04:35 OK 20260923120000_add_pushes.sql (26.35ms)25452026/10/01 10:04:35 goose: successfully migrated database to version: 2026092312000025462026/10/01 10:04:35 OK 1_commit_pending_closure.sql (3.89ms)25472026/10/01 10:04:35 OK 2_object_stats_trigger.sql (804.96µs)25482026/10/01 10:04:35 OK 3_commit_push.sql (530.21µs)25492026/10/01 10:04:35 goose: up to current file version: 325502026/10/01 10:04:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25512026/10/01 10:04:35 OK 20260923120000_add_pushes.sql (36.64ms)25522026/10/01 10:04:35 goose: successfully migrated database to version: 2026092312000025532026/10/01 10:04:35 OK 1_commit_pending_closure.sql (3.6ms)25542026/10/01 10:04:36 OK 2_object_stats_trigger.sql (685µs)25552026/10/01 10:04:36 OK 3_commit_push.sql (422.75µs)25562026/10/01 10:04:36 goose: up to current file version: 32557--- PASS: TestReadRedirectUsesPublicS3URL (2.76s)2558=== CONT TestCacheConfigHandler/full_config,_no_issuer2559=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2560=== CONT TestCacheConfigHandler/no_signing_keys2561=== CONT TestCacheConfigHandler/no_cache_url_configured2562--- PASS: TestCacheConfigHandler (0.00s)2563 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2564 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2565 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2566 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2567=== CONT TestIsValidCachePath/narinfo2568=== CONT TestIsValidCachePath/index.html2569=== CONT TestIsValidCachePath/short_hash2570=== CONT TestIsValidCachePath/wrong_extension2571=== CONT TestIsValidCachePath/leading_slash2572=== CONT TestIsValidCachePath/empty2573=== CONT TestIsValidCachePath/random_path2574=== CONT TestIsValidCachePath/invalid_char_u2575=== CONT TestIsValidCachePath/invalid_char_e2576=== CONT TestIsValidCachePath/traversal_in_middle2577=== CONT TestIsValidCachePath/traversal_parent2578=== CONT TestIsValidCachePath/nar_uncompressed2579=== CONT TestIsValidCachePath/nix-cache-info2580=== CONT TestIsValidCachePath/realisation2581=== CONT TestIsValidCachePath/log2582=== CONT TestIsValidCachePath/ls2583=== CONT TestIsValidCachePath/nar_xz2584=== CONT TestIsValidCachePath/nar_bz22585=== CONT TestIsValidCachePath/nar_zst2586=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2587--- PASS: TestIsValidCachePath (0.00s)2588 --- PASS: TestIsValidCachePath/narinfo (0.00s)2589 --- PASS: TestIsValidCachePath/index.html (0.00s)2590 --- PASS: TestIsValidCachePath/short_hash (0.00s)2591 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2592 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2593 --- PASS: TestIsValidCachePath/empty (0.00s)2594 --- PASS: TestIsValidCachePath/random_path (0.00s)2595 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2596 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2597 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2598 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2599 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2600 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2601 --- PASS: TestIsValidCachePath/realisation (0.00s)2602 --- PASS: TestIsValidCachePath/log (0.00s)2603 --- PASS: TestIsValidCachePath/ls (0.00s)2604 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2605 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2606 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2607 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2608=== CONT TestParseSingleRange/none2609=== CONT TestParseSingleRange/start_far_past_EOF2610=== CONT TestParseSingleRange/start_past_EOF2611=== CONT TestParseSingleRange/single_byte2612=== CONT TestParseSingleRange/suffix_exceeds_size2613=== CONT TestParseSingleRange/suffix2614=== CONT TestParseSingleRange/end_clamped_to_size2615=== CONT TestParseSingleRange/open-ended2616=== CONT TestParseSingleRange/closed2617=== CONT TestParseSingleRange/malformed_end_before_start2618=== CONT TestParseSingleRange/malformed_both_empty2619=== CONT TestParseSingleRange/malformed_no_dash2620=== CONT TestParseSingleRange/multi-range_ignored2621=== CONT TestParseSingleRange/unknown_unit2622--- PASS: TestParseSingleRange (0.00s)2623 --- PASS: TestParseSingleRange/none (0.00s)2624 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2625 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2626 --- PASS: TestParseSingleRange/single_byte (0.00s)2627 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2628 --- PASS: TestParseSingleRange/suffix (0.00s)2629 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2630 --- PASS: TestParseSingleRange/open-ended (0.00s)2631 --- PASS: TestParseSingleRange/closed (0.00s)2632 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2633 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2634 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2635 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2636 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2637=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows26382026/10/01 10:04:36 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MDNlY2QwNzEtNjcwYy00OTM5LTllYjgtMzcyZmY4NDFmNTg0LjI4OGRiMzQ0LTc0ZGUtNGU1ZC05NWRmLTZkNWE1MWEyNmYwNngxNzkwODQ5MDc0MzE3NDE5MDAw error="Get \"http://127.0.0.1:1/bucket64/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"26392026/10/01 10:04:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MDNlY2QwNzEtNjcwYy00OTM5LTllYjgtMzcyZmY4NDFmNTg0LmQ0NmU4NjQwLWU3ODgtNDZkZC1hYTY5LTZiMjE3ODY5MzU5YXgxNzkwODQ5MDc0MjY1MDA5MDAw parts=1226402026/10/01 10:04:36 INFO Received cleanup request method=DELETE path=/api/pending_closures26412026/10/01 10:04:36 INFO Aborted multipart uploads count=1 kept=02642--- PASS: TestRedundantMultipartUpload (6.09s)2643=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check26442026-10-01 10:04:36.222 UTC [8144] ERROR: relation "goose_db_version" does not exist at character 3626452026-10-01 10:04:36.222 UTC [8144] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26462026-10-01 10:04:36.300 UTC [8145] ERROR: relation "goose_db_version" does not exist at character 3626472026-10-01 10:04:36.300 UTC [8145] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26482026/10/01 10:04:36 OK 20241026095416_initial_model.sql (138.28ms)26492026/10/01 10:04:36 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)26502026/10/01 10:04:36 OK 20251218171726_add_pins.sql (9.8ms)26512026/10/01 10:04:36 OK 20260628120000_add_object_size_and_stats.sql (35.63ms)26522026/10/01 10:04:36 OK 20241026095416_initial_model.sql (122.23ms)26532026/10/01 10:04:36 OK 20251210153512_drop_unused_gin_index.sql (9.01ms)26542026/10/01 10:04:36 OK 20260905000000_add_claims.sql (52.36ms)26552026/10/01 10:04:36 OK 20251218171726_add_pins.sql (25.02ms)26562026/10/01 10:04:36 OK 20260920000000_drop_claims.sql (16.58ms)2657=== NAME TestClientMultipleUploads2658 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-7135-908923472/TestClientMultipleUploads939526180/001/store/1fz7ppcyapjw14ld0vbr05qxx8lfyr2k-test-file-0.txt26592026-10-01 10:04:36.565 UTC [8148] ERROR: relation "goose_db_version" does not exist at character 3626602026-10-01 10:04:36.565 UTC [8148] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26612026/10/01 10:04:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"26622026/10/01 10:04:36 WARN mTLS auth: bound subjects configured but subject DN unavailable26632026/10/01 10:04:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2664--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.92s)2665=== CONT TestServerTLSConfig/no_client_CA2666=== CONT TestServerTLSConfig/not_a_PEM_file26672026/10/01 10:04:36 OK 20260923120000_add_pushes.sql (47.06ms)26682026/10/01 10:04:36 goose: successfully migrated database to version: 2026092312000026692026/10/01 10:04:36 OK 20260628120000_add_object_size_and_stats.sql (54.72ms)2670=== CONT TestServerTLSConfig/missing_CA_file2671--- PASS: TestServerTLSConfig (0.00s)2672 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2673 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)2674 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2675=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart26762026/10/01 10:04:36 INFO Received complete multipart upload request method=POST path=/26772026/10/01 10:04:36 OK 1_commit_pending_closure.sql (1.5ms)26782026/10/01 10:04:36 OK 2_object_stats_trigger.sql (281.58µs)26792026/10/01 10:04:36 OK 3_commit_push.sql (201.42µs)26802026/10/01 10:04:36 goose: up to current file version: 32681=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure26822026/10/01 10:04:36 INFO Received uploads request method=POST path=/26832026/10/01 10:04:36 OK 20260905000000_add_claims.sql (49.96ms)2684=== NAME TestClientMultipleUploads2685 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-7135-908923472/TestClientMultipleUploads939526180/001/store/rq76nw6c849i037kg9dixrrhyxp3yyb6-test-file-1.txt26862026/10/01 10:04:36 OK 20260920000000_drop_claims.sql (4.07ms)26872026/10/01 10:04:36 OK 20260923120000_add_pushes.sql (9.76ms)26882026/10/01 10:04:36 goose: successfully migrated database to version: 2026092312000026892026/10/01 10:04:36 OK 1_commit_pending_closure.sql (905.71µs)26902026/10/01 10:04:36 OK 2_object_stats_trigger.sql (218.54µs)26912026/10/01 10:04:36 OK 3_commit_push.sql (159.21µs)26922026/10/01 10:04:36 goose: up to current file version: 326932026/10/01 10:04:36 OK 20241026095416_initial_model.sql (56.42ms)26942026/10/01 10:04:36 OK 20251210153512_drop_unused_gin_index.sql (3.58ms)2695 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-7135-908923472/TestClientMultipleUploads939526180/001/store/zpr1mfsqvj8ldqzn64cmpy56jkj82hkr-test-file-2.txt26962026/10/01 10:04:36 OK 20251218171726_add_pins.sql (10.22ms)26972026/10/01 10:04:36 OK 20260628120000_add_object_size_and_stats.sql (13.2ms)26982026/10/01 10:04:36 OK 20260905000000_add_claims.sql (20.31ms)26992026-10-01 10:04:36.724 UTC [8155] ERROR: relation "goose_db_version" does not exist at character 3627002026-10-01 10:04:36.724 UTC [8155] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27012026/10/01 10:04:36 OK 20260920000000_drop_claims.sql (16.24ms)27022026-10-01 10:04:36.753 UTC [8157] ERROR: relation "goose_db_version" does not exist at character 3627032026-10-01 10:04:36.753 UTC [8157] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27042026/10/01 10:04:36 OK 20260923120000_add_pushes.sql (14.33ms)27052026/10/01 10:04:36 goose: successfully migrated database to version: 2026092312000027062026/10/01 10:04:36 OK 1_commit_pending_closure.sql (1.17ms)27072026/10/01 10:04:36 OK 2_object_stats_trigger.sql (212.5µs)27082026/10/01 10:04:36 OK 3_commit_push.sql (344.08µs)27092026/10/01 10:04:36 goose: up to current file version: 327102026/10/01 10:04:36 INFO Received push request method=POST path=/api/pushes27112026/10/01 10:04:36 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)27122026/10/01 10:04:36 INFO Uploading zpr1mfsqvj8ldqzn64cmpy56jkj82hkr-test-file-2.txt (160B)27132026/10/01 10:04:36 INFO Uploading 1fz7ppcyapjw14ld0vbr05qxx8lfyr2k-test-file-0.txt (160B)27142026/10/01 10:04:36 INFO Uploading rq76nw6c849i037kg9dixrrhyxp3yyb6-test-file-1.txt (160B)27152026/10/01 10:04:36 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"27162026/10/01 10:04:36 WARN Failed to register uploaded object key=1fz7ppcyapjw14ld0vbr05qxx8lfyr2k.ls error="server returned 404: 404 page not found\n"27172026/10/01 10:04:36 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"27182026/10/01 10:04:36 WARN Failed to register uploaded object key=zpr1mfsqvj8ldqzn64cmpy56jkj82hkr.ls error="server returned 404: 404 page not found\n"27192026/10/01 10:04:36 WARN Failed to register uploaded object key=rq76nw6c849i037kg9dixrrhyxp3yyb6.ls error="server returned 404: 404 page not found\n"27202026/10/01 10:04:36 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"27212026/10/01 10:04:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27222026/10/01 10:04:36 INFO Signed narinfos id=1 count=327232026/10/01 10:04:36 INFO Uploading 3 narinfos27242026/10/01 10:04:36 WARN Failed to register uploaded object key=rq76nw6c849i037kg9dixrrhyxp3yyb6.narinfo error="server returned 404: 404 page not found\n"27252026/10/01 10:04:36 WARN Failed to register uploaded object key=zpr1mfsqvj8ldqzn64cmpy56jkj82hkr.narinfo error="server returned 404: 404 page not found\n"27262026/10/01 10:04:36 INFO Received complete push request method=POST path=/api/pushes/1/complete27272026/10/01 10:04:36 WARN Failed to register uploaded object key=1fz7ppcyapjw14ld0vbr05qxx8lfyr2k.narinfo error="server returned 404: 404 page not found\n"27282026/10/01 10:04:36 OK 20241026095416_initial_model.sql (75.42ms)27292026/10/01 10:04:36 INFO Upload complete. (119ms)2730 client_integration_test.go:369: Uploaded 3 paths in 157.429292ms27312026/10/01 10:04:36 OK 20251210153512_drop_unused_gin_index.sql (16.58ms)27322026/10/01 10:04:36 OK 20251218171726_add_pins.sql (29.72ms)27332026/10/01 10:04:36 OK 20241026095416_initial_model.sql (98.25ms)27342026/10/01 10:04:36 OK 20251210153512_drop_unused_gin_index.sql (7.52ms)2735=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts27362026/10/01 10:04:36 INFO Received request for more parts method=POST path=/2737--- PASS: TestClientMultipleUploads (3.28s)2738=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info27392026/10/01 10:04:36 INFO Received uploads request method=POST path=/2740=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key27412026/10/01 10:04:36 INFO Received complete multipart upload request method=POST path=/2742=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key27432026/10/01 10:04:36 INFO Received request for more parts method=POST path=/2744=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal27452026/10/01 10:04:36 INFO Received uploads request method=POST path=/2746--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2747 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2748 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2749 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2750 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2751=== CONT TestIsValidUploadKey/narinfo2752=== CONT TestIsValidUploadKey/realisation_plus_in_output2753=== CONT TestIsValidUploadKey/unknown_type2754=== CONT TestIsValidUploadKey/empty_key2755=== CONT TestIsValidUploadKey/absolute2756=== CONT TestIsValidUploadKey/traversal_nar2757=== CONT TestIsValidUploadKey/traversal2758=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2759=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2760=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2761=== CONT TestIsValidUploadKey/index.html2762=== CONT TestIsValidUploadKey/nix-cache-info2763=== CONT TestIsValidUploadKey/build_log_home-manager_file2764=== CONT TestIsValidUploadKey/realisation2765=== CONT TestIsValidUploadKey/build_log_equals2766=== CONT TestIsValidUploadKey/build_log_question_mark2767=== CONT TestIsValidUploadKey/build_log_plus_in_name2768=== CONT TestIsValidUploadKey/nar_plain2769=== CONT TestIsValidUploadKey/build_log2770=== CONT TestIsValidUploadKey/listing2771=== CONT TestIsValidUploadKey/nar_xz2772=== CONT TestIsValidUploadKey/nar_zst2773--- PASS: TestIsValidUploadKey (0.00s)2774 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2775 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2776 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2777 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2778 --- PASS: TestIsValidUploadKey/absolute (0.00s)2779 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2780 --- PASS: TestIsValidUploadKey/traversal (0.00s)2781 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2782 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2783 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2784 --- PASS: TestIsValidUploadKey/index.html (0.00s)2785 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2786 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2787 --- PASS: TestIsValidUploadKey/realisation (0.00s)2788 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2789 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2790 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2791 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2792 --- PASS: TestIsValidUploadKey/build_log (0.00s)2793 --- PASS: TestIsValidUploadKey/listing (0.00s)2794 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2795 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2796=== CONT TestProxyWriteTimeout/narinfo2797=== CONT TestProxyWriteTimeout/10_GiB_nar2798=== CONT TestProxyWriteTimeout/unknown_size2799=== CONT TestProxyWriteTimeout/1_GiB_nar2800--- PASS: TestProxyWriteTimeout (0.00s)2801 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2802 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2803 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2804 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2805=== CONT TestResolveDBConnectionString/flag_wins2806=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2807=== CONT TestResolveDBConnectionString/nothing_configured2808=== CONT TestResolveDBConnectionString/missing_file_is_an_error2809=== CONT TestResolveDBConnectionString/file_when_flag_empty2810=== CONT TestPush_RejectsBadRequests/no_roots28112026/10/01 10:04:36 INFO Received push request method=POST path=/api/pushes2812=== CONT TestPush_RejectsBadRequests/bad_root28132026/10/01 10:04:36 INFO Received push request method=POST path=/api/pushes2814=== CONT TestPush_RejectsBadRequests/root_not_in_objects28152026/10/01 10:04:36 INFO Received push request method=POST path=/api/pushes2816=== CONT TestPush_RejectsBadRequests/no_objects28172026/10/01 10:04:36 INFO Received push request method=POST path=/api/pushes2818=== CONT TestClientErrorHandling/InvalidStorePath2819--- PASS: TestPush_RejectsBadRequests (1.74s)2820 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2821 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2822 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2823 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2824--- PASS: TestResolveDBConnectionString (0.03s)2825 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2826 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2827 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2828 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2829 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)28302026/10/01 10:04:36 OK 20260628120000_add_object_size_and_stats.sql (27.76ms)28312026/10/01 10:04:36 OK 20251218171726_add_pins.sql (20ms)2832--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)2833 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2834 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)2835 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2836=== CONT TestClientErrorHandling/ServerNotAvailable28372026/10/01 10:04:36 OK 20260628120000_add_object_size_and_stats.sql (28.99ms)2838=== NAME TestClientIntegration2839 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-7135-908923472/TestClientIntegration820606618/002/store/i293cf69a3shivm77lp2i2qjas4v5653-test-file.txt28402026/10/01 10:04:36 OK 20260905000000_add_claims.sql (39.97ms)28412026-10-01 10:04:36.955 UTC [8164] ERROR: relation "goose_db_version" does not exist at character 3628422026-10-01 10:04:36.955 UTC [8164] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28432026/10/01 10:04:36 OK 20260920000000_drop_claims.sql (11.94ms)28442026/10/01 10:04:36 OK 20260905000000_add_claims.sql (22.85ms)28452026/10/01 10:04:36 OK 20260920000000_drop_claims.sql (16.53ms)28462026/10/01 10:04:36 OK 20260923120000_add_pushes.sql (16.98ms)28472026/10/01 10:04:36 goose: successfully migrated database to version: 2026092312000028482026/10/01 10:04:36 OK 1_commit_pending_closure.sql (908µs)28492026/10/01 10:04:36 OK 2_object_stats_trigger.sql (226.04µs)28502026/10/01 10:04:36 OK 3_commit_push.sql (193.33µs)28512026/10/01 10:04:36 goose: up to current file version: 328522026/10/01 10:04:36 OK 20260923120000_add_pushes.sql (14.11ms)28532026/10/01 10:04:36 goose: successfully migrated database to version: 2026092312000028542026/10/01 10:04:36 OK 1_commit_pending_closure.sql (1.15ms)28552026/10/01 10:04:36 OK 2_object_stats_trigger.sql (218.38µs)28562026/10/01 10:04:36 OK 3_commit_push.sql (176.04µs)28572026/10/01 10:04:36 goose: up to current file version: 328582026/10/01 10:04:37 INFO Received push request method=POST path=/api/pushes2859--- PASS: TestService_ReadAuthMiddleware (2.60s)2860=== CONT TestClientErrorHandling/InvalidAuthToken28612026/10/01 10:04:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)28622026/10/01 10:04:37 INFO Uploading i293cf69a3shivm77lp2i2qjas4v5653-test-file.txt (152B)28632026/10/01 10:04:37 WARN Failed to register uploaded object key=i293cf69a3shivm77lp2i2qjas4v5653.ls error="server returned 404: 404 page not found\n"28642026/10/01 10:04:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28652026/10/01 10:04:37 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"28662026/10/01 10:04:37 INFO Signed narinfos id=1 count=128672026/10/01 10:04:37 INFO Uploading 1 narinfos28682026/10/01 10:04:37 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/present28692026/10/01 10:04:37 INFO Received complete push request method=POST path=/api/pushes/1/complete28702026/10/01 10:04:37 WARN Failed to register uploaded object key=i293cf69a3shivm77lp2i2qjas4v5653.narinfo error="server returned 404: 404 page not found\n"28712026/10/01 10:04:37 INFO Upload complete. (132ms)28722026/10/01 10:04:37 OK 20241026095416_initial_model.sql (139.07ms)28732026/10/01 10:04:37 OK 20251210153512_drop_unused_gin_index.sql (7.71ms)28742026/10/01 10:04:37 INFO All 1 paths already cached2875=== NAME TestClientIntegration2876 client_integration_test.go:312: Retrieved narinfo from S3:2877 StorePath: /nix/var/nix/builds/nix-7135-908923472/TestClientIntegration820606618/002/store/i293cf69a3shivm77lp2i2qjas4v5653-test-file.txt2878 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2879 Compression: zstd2880 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12881 NarSize: 1522882 References: 2883 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12884 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2885 client_integration_test.go:313: Decompressed .ls content (64 bytes):2886 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2887 client_integration_test.go:316: Testing garbage collection...28882026/10/01 10:04:37 OK 20251218171726_add_pins.sql (18.38ms)28892026/10/01 10:04:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures28902026/10/01 10:04:37 INFO Garbage collection started28912026/10/01 10:04:37 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.473172ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28922026/10/01 10:04:37 INFO Aborted multipart uploads count=0 kept=028932026/10/01 10:04:37 WARN Force mode enabled - objects will be deleted immediately without grace period28942026/10/01 10:04:37 OK 20260628120000_add_object_size_and_stats.sql (26.36ms)28952026/10/01 10:04:37 OK 20260905000000_add_claims.sql (27.63ms)28962026/10/01 10:04:37 OK 20260920000000_drop_claims.sql (9.86ms)28972026/10/01 10:04:37 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=028982026/10/01 10:04:37 OK 20260923120000_add_pushes.sql (16.99ms)28992026/10/01 10:04:37 goose: successfully migrated database to version: 2026092312000029002026/10/01 10:04:37 OK 1_commit_pending_closure.sql (1ms)29012026/10/01 10:04:37 OK 2_object_stats_trigger.sql (210.54µs)29022026/10/01 10:04:37 OK 3_commit_push.sql (162.08µs)29032026/10/01 10:04:37 goose: up to current file version: 329042026/10/01 10:04:37 INFO Vacuumed table table=pending_closures29052026/10/01 10:04:37 INFO Vacuumed table table=pending_objects29062026/10/01 10:04:37 INFO Vacuumed table table=multipart_uploads29072026/10/01 10:04:37 INFO Vacuumed table table=closures2908--- PASS: TestReadRedirectKeepsNarinfoProxied (2.53s)2909=== CONT TestService_RequireScope_OIDC/builder_may_write2910=== CONT TestService_RequireScope_OIDC/static_token_may_admin2911=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2912=== CONT TestService_RequireScope_OIDC/writer_implies_read2913=== CONT TestService_RequireScope_OIDC/reader_may_read2914=== CONT TestService_RequireScope_OIDC/static_token_may_write2915=== CONT TestService_RequireScope_OIDC/ops_may_not_write2916=== CONT TestService_RequireScope_OIDC/reader_may_not_write2917=== CONT TestService_RequireScope_OIDC/ops_may_admin2918=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2919=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2920=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected29212026/10/01 10:04:37 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]2922=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2923=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected29242026/10/01 10:04:37 WARN Authentication failed token_preview=eyJhbGciOi...ZKQexKfHaw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]29252026/10/01 10:04:37 INFO Vacuumed table table=objects2926--- PASS: TestService_AuthMiddleware_OIDC (2.70s)2927 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2928 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2929 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2930 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2931--- PASS: TestService_RequireScope_OIDC (2.93s)2932 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2933 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2934 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2935 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2936 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2937 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2938 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2939 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2940 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2941 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)29422026/10/01 10:04:37 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.699405ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29432026-10-01 10:04:37.401 UTC [8179] ERROR: relation "goose_db_version" does not exist at character 3629442026-10-01 10:04:37.401 UTC [8179] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29452026-10-01 10:04:37.407 UTC [8180] ERROR: relation "goose_db_version" does not exist at character 3629462026-10-01 10:04:37.407 UTC [8180] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29472026/10/01 10:04:37 OK 20241026095416_initial_model.sql (113.36ms)2948--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.44s)29492026/10/01 10:04:37 OK 20251210153512_drop_unused_gin_index.sql (5.88ms)29502026/10/01 10:04:37 OK 20241026095416_initial_model.sql (105.06ms)29512026/10/01 10:04:37 OK 20251210153512_drop_unused_gin_index.sql (10.17ms)29522026/10/01 10:04:37 OK 20251218171726_add_pins.sql (36.26ms)29532026/10/01 10:04:37 OK 20251218171726_add_pins.sql (39.68ms)29542026/10/01 10:04:37 OK 20260628120000_add_object_size_and_stats.sql (31.13ms)29552026/10/01 10:04:37 OK 20260628120000_add_object_size_and_stats.sql (19.78ms)29562026/10/01 10:04:37 OK 20260905000000_add_claims.sql (10.02ms)29572026/10/01 10:04:37 OK 20260905000000_add_claims.sql (25.55ms)29582026/10/01 10:04:37 OK 20260920000000_drop_claims.sql (18.56ms)29592026/10/01 10:04:37 OK 20260923120000_add_pushes.sql (10.93ms)29602026/10/01 10:04:37 goose: successfully migrated database to version: 2026092312000029612026/10/01 10:04:37 OK 1_commit_pending_closure.sql (4.49ms)29622026/10/01 10:04:37 OK 2_object_stats_trigger.sql (930.58µs)29632026/10/01 10:04:37 OK 3_commit_push.sql (689.71µs)29642026/10/01 10:04:37 goose: up to current file version: 329652026/10/01 10:04:37 OK 20260920000000_drop_claims.sql (22.8ms)29662026/10/01 10:04:37 OK 20260923120000_add_pushes.sql (3.2ms)29672026/10/01 10:04:37 goose: successfully migrated database to version: 2026092312000029682026/10/01 10:04:37 OK 1_commit_pending_closure.sql (3.9ms)29692026/10/01 10:04:37 OK 2_object_stats_trigger.sql (694.83µs)29702026/10/01 10:04:37 OK 3_commit_push.sql (436.17µs)29712026/10/01 10:04:37 goose: up to current file version: 329722026/10/01 10:04:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=779.474753ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2973--- PASS: TestCacheStatsHandler (2.74s)29742026-10-01 10:04:38.164 UTC [8183] ERROR: relation "goose_db_version" does not exist at character 3629752026-10-01 10:04:38.164 UTC [8183] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29762026-10-01 10:04:38.207 UTC [8184] ERROR: relation "goose_db_version" does not exist at character 3629772026-10-01 10:04:38.207 UTC [8184] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29782026/10/01 10:04:38 OK 20241026095416_initial_model.sql (49.53ms)29792026/10/01 10:04:38 OK 20251210153512_drop_unused_gin_index.sql (5.35ms)29802026/10/01 10:04:38 OK 20251218171726_add_pins.sql (6.4ms)29812026/10/01 10:04:38 OK 20241026095416_initial_model.sql (39.62ms)29822026/10/01 10:04:38 OK 20251210153512_drop_unused_gin_index.sql (6.93ms)29832026/10/01 10:04:38 OK 20260628120000_add_object_size_and_stats.sql (19.56ms)29842026/10/01 10:04:38 INFO Received uploads request method=POST path=/api/pending_closures29852026/10/01 10:04:38 OK 20251218171726_add_pins.sql (18.78ms)29862026/10/01 10:04:38 INFO Aborted multipart uploads count=0 kept=029872026/10/01 10:04:38 WARN Force mode enabled - objects will be deleted immediately without grace period29882026/10/01 10:04:38 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=029892026/10/01 10:04:38 OK 20260628120000_add_object_size_and_stats.sql (21.39ms)29902026/10/01 10:04:38 INFO Vacuumed table table=pending_closures29912026/10/01 10:04:38 OK 20260905000000_add_claims.sql (29.16ms)29922026/10/01 10:04:38 INFO Vacuumed table table=pending_objects29932026/10/01 10:04:38 INFO Vacuumed table table=multipart_uploads29942026/10/01 10:04:38 INFO Vacuumed table table=closures29952026/10/01 10:04:38 INFO Vacuumed table table=objects29962026/10/01 10:04:38 OK 20260920000000_drop_claims.sql (18.33ms)29972026/10/01 10:04:38 OK 20260905000000_add_claims.sql (19.23ms)29982026/10/01 10:04:38 OK 20260923120000_add_pushes.sql (6.65ms)29992026/10/01 10:04:38 goose: successfully migrated database to version: 2026092312000030002026/10/01 10:04:38 OK 1_commit_pending_closure.sql (1.09ms)30012026/10/01 10:04:38 OK 2_object_stats_trigger.sql (205.79µs)30022026/10/01 10:04:38 OK 3_commit_push.sql (151.88µs)30032026/10/01 10:04:38 goose: up to current file version: 330042026/10/01 10:04:38 OK 20260920000000_drop_claims.sql (21.42ms)30052026/10/01 10:04:38 OK 20260923120000_add_pushes.sql (5.37ms)30062026/10/01 10:04:38 goose: successfully migrated database to version: 2026092312000030072026/10/01 10:04:38 OK 1_commit_pending_closure.sql (849.13µs)30082026/10/01 10:04:38 OK 2_object_stats_trigger.sql (226.96µs)30092026/10/01 10:04:38 OK 3_commit_push.sql (182.04µs)30102026/10/01 10:04:38 goose: up to current file version: 33011=== NAME TestClientCADerivations3012 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-7135-908923472/TestClientCADerivations2877575858/001/store/sxh3s6ib1m50s7x453xb9zfxvk025f9p-ca-test3013 client_ca_test.go:139: Found 1 dependencies (including self)30142026/10/01 10:04:38 INFO Received uploads request method=POST path=/api/pending_closures30152026/10/01 10:04:38 INFO Aborted multipart uploads count=0 kept=030162026/10/01 10:04:38 WARN Force mode enabled - objects will be deleted immediately without grace period30172026/10/01 10:04:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=030182026/10/01 10:04:38 INFO Vacuumed table table=pending_closures30192026/10/01 10:04:38 INFO Vacuumed table table=pending_objects30202026/10/01 10:04:38 INFO Vacuumed table table=multipart_uploads30212026/10/01 10:04:38 INFO Vacuumed table table=closures30222026/10/01 10:04:38 INFO Vacuumed table table=objects30232026/10/01 10:04:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.501629564s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30242026/10/01 10:04:38 INFO Received push request method=POST path=/api/pushes3025--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)3026 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.26s)3027 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.55s)30282026/10/01 10:04:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)30292026/10/01 10:04:38 INFO Uploading sxh3s6ib1m50s7x453xb9zfxvk025f9p-ca-test (144B)30302026/10/01 10:04:38 WARN Failed to register uploaded object key=sxh3s6ib1m50s7x453xb9zfxvk025f9p.ls error="server returned 404: 404 page not found\n"30312026/10/01 10:04:38 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"30322026/10/01 10:04:38 WARN Failed to register uploaded object key=log/9lcr55fsrxp6gqd5dar1vaphg9afvzqj-ca-test.drv error="server returned 404: 404 page not found\n"30332026/10/01 10:04:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign30342026/10/01 10:04:38 INFO Signed narinfos id=1 count=130352026/10/01 10:04:38 INFO Uploading 1 narinfos30362026/10/01 10:04:38 INFO Received complete push request method=POST path=/api/pushes/1/complete30372026/10/01 10:04:38 WARN Failed to register uploaded object key=sxh3s6ib1m50s7x453xb9zfxvk025f9p.narinfo error="server returned 404: 404 page not found\n"30382026/10/01 10:04:38 INFO Upload complete. (168ms)3039=== NAME TestClientCADerivations3040 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-7135-908923472/TestClientCADerivations2877575858/001/store/sxh3s6ib1m50s7x453xb9zfxvk025f9p-ca-test3041 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst3042 Compression: zstd3043 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n3044 NarSize: 1443045 References: 3046 Deriver: /nix/var/nix/builds/nix-7135-908923472/TestClientCADerivations2877575858/001/store/9lcr55fsrxp6gqd5dar1vaphg9afvzqj-ca-test.drv3047 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n3048 client_ca_test.go:185: Checking for realisation files in S3...3049 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations3050 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache3051 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket81?endpoint=http://localhost:57911&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-7135-908923472/TestClientCADerivations2877575858/001/store'3052 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 13053--- PASS: TestClientCADerivations (3.25s)30542026/10/01 10:04:38 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30552026/10/01 10:04:39 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30562026/10/01 10:04:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=03057=== NAME TestClientIntegration3058 client_integration_test.go:323: Objects in database after GC:3059 client_integration_test.go:323: Successfully deleted all objects with GC --force3060--- PASS: TestClientIntegration (4.80s)30612026/10/01 10:04:40 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-config30622026/10/01 10:04:40 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.352045ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30632026/10/01 10:04:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=423.282771ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30642026/10/01 10:04:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=821.570088ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30652026/10/01 10:04:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.488220733s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30662026/10/01 10:04:43 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"30672026/10/01 10:04:43 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-config30682026/10/01 10:04:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.312739ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30692026/10/01 10:04:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.542548ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30702026/10/01 10:04:43 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=777.353833ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30712026/10/01 10:04:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.751425691s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30722026/10/01 10:04:46 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_closures30732026/10/01 10:04:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.86388ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30742026/10/01 10:04:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=414.527145ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30752026/10/01 10:04:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=835.648967ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30762026/10/01 10:04:48 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.610816603s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3077--- PASS: TestClientErrorHandling (0.00s)3078 --- PASS: TestClientErrorHandling/InvalidStorePath (1.84s)3079 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.98s)3080 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.73s)3081PASS3082{"timestamp":"2026-10-01T10:04:49.634224Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58392","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}30832026-10-01 10:04:49.783 UTC [7457] LOG: received smart shutdown request30842026-10-01 10:04:49.784 UTC [7457] LOG: background worker "logical replication launcher" (PID 7468) exited with exit code 130852026-10-01 10:04:49.787 UTC [7463] LOG: shutting down30862026-10-01 10:04:49.787 UTC [7463] LOG: checkpoint starting: shutdown immediate30872026-10-01 10:04:50.959 UTC [7463] LOG: checkpoint complete: wrote 12593 buffers (76.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.634 s, sync=0.492 s, total=1.172 s; sync files=28648, longest=0.001 s, average=0.001 s; distance=403232 kB, estimate=403232 kB; lsn=0/1A1552B8, redo lsn=0/1A1552B830882026-10-01 10:04:50.965 UTC [7457] LOG: database system is shut down3089Running OIDC tests...3090=== RUN TestAudienceForIssuer3091=== PAUSE TestAudienceForIssuer3092=== RUN TestGlobMatch3093=== PAUSE TestGlobMatch3094=== RUN TestValidateToken_ValidToken3095=== PAUSE TestValidateToken_ValidToken3096=== RUN TestValidateToken_WrongAudience3097=== PAUSE TestValidateToken_WrongAudience3098=== RUN TestValidateToken_Expired3099=== PAUSE TestValidateToken_Expired3100=== RUN TestValidateToken_BoundClaimsMismatch3101=== PAUSE TestValidateToken_BoundClaimsMismatch3102=== RUN TestValidateToken_BoundSubjectMismatch3103=== PAUSE TestValidateToken_BoundSubjectMismatch3104=== RUN TestValidateToken_MultipleProviders3105=== PAUSE TestValidateToken_MultipleProviders3106=== RUN TestValidateToken_NoMatchingProvider3107=== PAUSE TestValidateToken_NoMatchingProvider3108=== RUN TestValidateToken_KubernetesServiceAccount3109=== PAUSE TestValidateToken_KubernetesServiceAccount3110=== RUN TestNewValidator_KubernetesRequiresCA3111=== PAUSE TestNewValidator_KubernetesRequiresCA3112=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3113=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3114=== RUN TestPins_ReservedForMatchingRule3115=== PAUSE TestPins_ReservedForMatchingRule3116=== RUN TestPins_TopLevelShorthand3117=== PAUSE TestPins_TopLevelShorthand3118=== RUN TestPins_ConfigValidation3119=== PAUSE TestPins_ConfigValidation3120=== RUN TestScopes_LegacyProviderDefaultsToWrite3121=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3122=== RUN TestScopes_Rules3123=== PAUSE TestScopes_Rules3124=== RUN TestScopes_ConfigValidation3125=== PAUSE TestScopes_ConfigValidation3126=== CONT TestAudienceForIssuer3127--- PASS: TestAudienceForIssuer (0.00s)3128=== CONT TestValidateToken_NoMatchingProvider3129=== CONT TestValidateToken_Expired3130=== CONT TestValidateToken_KubernetesServiceAccount3131=== CONT TestScopes_ConfigValidation3132=== CONT TestScopes_Rules3133=== CONT TestScopes_LegacyProviderDefaultsToWrite3134=== CONT TestPins_ConfigValidation3135=== CONT TestPins_TopLevelShorthand3136=== CONT TestPins_ReservedForMatchingRule3137=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3138--- PASS: TestScopes_ConfigValidation (0.00s)3139=== CONT TestNewValidator_KubernetesRequiresCA3140--- PASS: TestPins_ConfigValidation (0.00s)3141=== CONT TestValidateToken_MultipleProviders31422026/10/01 10:04:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58706/oidc31432026/10/01 10:04:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58708/oidc3144--- PASS: TestPins_ReservedForMatchingRule (0.04s)3145=== CONT TestValidateToken_ValidToken3146--- PASS: TestScopes_Rules (0.05s)3147=== CONT TestValidateToken_WrongAudience31482026/10/01 10:04:52 http: TLS handshake error from 127.0.0.1:58711: read tcp 127.0.0.1:58710->127.0.0.1:58711: use of closed network connection3149--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)3150=== CONT TestValidateToken_BoundClaimsMismatch31512026/10/01 10:04:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58712/oidc3152--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)3153=== CONT TestGlobMatch3154=== RUN TestGlobMatch/foo_foo3155=== PAUSE TestGlobMatch/foo_foo3156=== RUN TestGlobMatch/foo_bar3157=== PAUSE TestGlobMatch/foo_bar3158=== RUN TestGlobMatch/*_3159=== PAUSE TestGlobMatch/*_3160=== RUN TestGlobMatch/*_anything3161=== PAUSE TestGlobMatch/*_anything3162=== RUN TestGlobMatch/foo*_foo3163=== PAUSE TestGlobMatch/foo*_foo3164=== RUN TestGlobMatch/foo*_foobar3165=== PAUSE TestGlobMatch/foo*_foobar3166=== RUN TestGlobMatch/foo*_bar3167=== PAUSE TestGlobMatch/foo*_bar3168=== RUN TestGlobMatch/*bar_bar3169=== PAUSE TestGlobMatch/*bar_bar3170=== RUN TestGlobMatch/*bar_foobar3171=== PAUSE TestGlobMatch/*bar_foobar3172=== RUN TestGlobMatch/*bar_foo3173=== PAUSE TestGlobMatch/*bar_foo3174=== RUN TestGlobMatch/foo*bar_foobar3175=== PAUSE TestGlobMatch/foo*bar_foobar3176=== RUN TestGlobMatch/foo*bar_foo123bar3177=== PAUSE TestGlobMatch/foo*bar_foo123bar3178=== RUN TestGlobMatch/foo*bar_foobarbaz3179=== PAUSE TestGlobMatch/foo*bar_foobarbaz3180=== RUN TestGlobMatch/*/*_foo/bar3181=== PAUSE TestGlobMatch/*/*_foo/bar3182=== RUN TestGlobMatch/*/*_foo3183=== PAUSE TestGlobMatch/*/*_foo3184=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3185=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3186=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03187=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03188=== RUN TestGlobMatch/refs/*/main_refs/heads/main3189=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3190=== RUN TestGlobMatch/fo?_foo3191=== PAUSE TestGlobMatch/fo?_foo3192=== RUN TestGlobMatch/fo?_fo3193=== PAUSE TestGlobMatch/fo?_fo3194=== RUN TestGlobMatch/fo?_fooo3195=== PAUSE TestGlobMatch/fo?_fooo3196=== RUN TestGlobMatch/?oo_foo3197=== PAUSE TestGlobMatch/?oo_foo3198=== RUN TestGlobMatch/?oo_boo3199=== PAUSE TestGlobMatch/?oo_boo3200=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3201=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3202=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3203=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3204=== CONT TestValidateToken_BoundSubjectMismatch32052026/10/01 10:04:52 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233206--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)3207=== CONT TestGlobMatch/foo_foo3208=== CONT TestGlobMatch/*/*_foo/bar3209=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3210=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3211=== CONT TestGlobMatch/?oo_boo3212=== CONT TestGlobMatch/?oo_foo3213=== CONT TestGlobMatch/fo?_fooo3214=== CONT TestGlobMatch/fo?_fo3215=== CONT TestGlobMatch/fo?_foo3216=== CONT TestGlobMatch/refs/*/main_refs/heads/main3217=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03218=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3219=== CONT TestGlobMatch/*/*_foo3220=== CONT TestGlobMatch/foo*bar_foobarbaz3221=== CONT TestGlobMatch/foo*bar_foo123bar3222=== CONT TestGlobMatch/foo*bar_foobar3223=== CONT TestGlobMatch/*bar_foo3224=== CONT TestGlobMatch/*bar_foobar3225=== CONT TestGlobMatch/*bar_bar3226=== CONT TestGlobMatch/foo*_bar3227=== CONT TestGlobMatch/foo*_foobar3228=== CONT TestGlobMatch/foo*_foo3229=== CONT TestGlobMatch/*_anything3230=== CONT TestGlobMatch/*_3231=== CONT TestGlobMatch/foo_bar3232--- PASS: TestGlobMatch (0.00s)3233 --- PASS: TestGlobMatch/foo_foo (0.00s)3234 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3235 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3236 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3237 --- PASS: TestGlobMatch/?oo_boo (0.00s)3238 --- PASS: TestGlobMatch/?oo_foo (0.00s)3239 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3240 --- PASS: TestGlobMatch/fo?_fo (0.00s)3241 --- PASS: TestGlobMatch/fo?_foo (0.00s)3242 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3243 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3244 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3245 --- PASS: TestGlobMatch/*/*_foo (0.00s)3246 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3247 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3248 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3249 --- PASS: TestGlobMatch/*bar_foo (0.00s)3250 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3251 --- PASS: TestGlobMatch/*bar_bar (0.00s)3252 --- PASS: TestGlobMatch/foo*_bar (0.00s)3253 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3254 --- PASS: TestGlobMatch/foo*_foo (0.00s)3255 --- PASS: TestGlobMatch/*_anything (0.00s)3256 --- PASS: TestGlobMatch/*_ (0.00s)3257 --- PASS: TestGlobMatch/foo_bar (0.00s)32582026/10/01 10:04:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58717/oidc32592026/10/01 10:04:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58719/oidc3260--- PASS: TestValidateToken_ValidToken (0.06s)3261--- PASS: TestValidateToken_Expired (0.10s)32622026/10/01 10:04:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58721/oidc3263--- PASS: TestValidateToken_WrongAudience (0.06s)32642026/10/01 10:04:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58723/oidc3265--- PASS: TestPins_TopLevelShorthand (0.11s)32662026/10/01 10:04:52 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:587253267--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)32682026/10/01 10:04:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58727/oidc3269--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)32702026/10/01 10:04:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58730/oidc3271--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)32722026/10/01 10:04:52 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:58716/oidc32732026/10/01 10:04:52 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:58728/oidc32742026/10/01 10:04:52 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:58734/oidc3275--- PASS: TestValidateToken_NoMatchingProvider (0.19s)3276--- PASS: TestValidateToken_MultipleProviders (0.19s)3277PASS3278Running hook tests...3279=== RUN TestSendPathsEmpty3280=== PAUSE TestSendPathsEmpty3281=== RUN TestQueueEnqueueAndFetch3282=== PAUSE TestQueueEnqueueAndFetch3283=== RUN TestQueueDeduplication3284=== PAUSE TestQueueDeduplication3285=== RUN TestQueueRemove3286=== PAUSE TestQueueRemove3287=== RUN TestQueueFetchBatchLimit3288=== PAUSE TestQueueFetchBatchLimit3289=== RUN TestQueueRetryMovesToBack3290=== PAUSE TestQueueRetryMovesToBack3291=== RUN TestQueueFetchRemoveLifecycle3292=== PAUSE TestQueueFetchRemoveLifecycle3293=== RUN TestQueueConcurrentWriters3294=== PAUSE TestQueueConcurrentWriters3295=== RUN TestQueueRemoveLargeClosure3296=== PAUSE TestQueueRemoveLargeClosure3297=== RUN TestServerClientIntegration3298=== PAUSE TestServerClientIntegration3299=== RUN TestServerQueueError3300=== PAUSE TestServerQueueError3301=== RUN TestGetListenerSocketActivation3302 server_test.go:210: === RUN TestGetListenerSocketActivation3303 --- PASS: TestGetListenerSocketActivation (0.00s)3304 PASS3305 3306--- PASS: TestGetListenerSocketActivation (0.01s)3307=== RUN TestDrainIsolatesPoisonPath3308=== PAUSE TestDrainIsolatesPoisonPath3309=== RUN TestRunNotBlockedByPoisonHead3310=== PAUSE TestRunNotBlockedByPoisonHead3311=== RUN TestDrainGivesUpWhenServerDown3312=== PAUSE TestDrainGivesUpWhenServerDown3313=== RUN TestFailedPathPrunedByLaterClosure3314=== PAUSE TestFailedPathPrunedByLaterClosure3315=== RUN TestWorkerUploadsAndRemoves3316=== PAUSE TestWorkerUploadsAndRemoves3317=== RUN TestWorkerSkipsGCdPaths3318=== PAUSE TestWorkerSkipsGCdPaths3319=== RUN TestWorkerPrunesClosureDeps3320=== PAUSE TestWorkerPrunesClosureDeps3321=== RUN TestDrainTimeout3322=== PAUSE TestDrainTimeout3323=== CONT TestSendPathsEmpty3324--- PASS: TestSendPathsEmpty (0.00s)3325=== CONT TestServerClientIntegration3326=== CONT TestServerQueueError3327=== CONT TestQueueRetryMovesToBack3328=== CONT TestDrainGivesUpWhenServerDown3329=== CONT TestRunNotBlockedByPoisonHead3330=== CONT TestDrainIsolatesPoisonPath3331=== CONT TestWorkerUploadsAndRemoves3332=== CONT TestDrainTimeout3333=== CONT TestWorkerPrunesClosureDeps3334=== CONT TestWorkerSkipsGCdPaths33352026/10/01 10:04:52 ERROR Failed to queue paths error="permission denied" count=13336--- PASS: TestServerQueueError (0.00s)3337=== CONT TestFailedPathPrunedByLaterClosure3338--- PASS: TestServerClientIntegration (0.00s)3339=== CONT TestQueueRemove33402026/10/01 10:04:52 INFO Upload queue status pending=233412026/10/01 10:04:52 INFO Uploading batch count=133422026/10/01 10:04:52 INFO Uploading batch count=133432026/10/01 10:04:52 ERROR Upload failed error="upload failed" count=133442026/10/01 10:04:52 INFO Upload queue status pending=233452026/10/01 10:04:52 INFO Uploading batch count=133462026/10/01 10:04:52 INFO Upload queue status pending=233472026/10/01 10:04:52 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-7135-908923472/TestWorkerSkipsGCdPaths3071068653/002/nonexistent33482026/10/01 10:04:52 INFO Uploading batch count=23349--- PASS: TestQueueRetryMovesToBack (0.01s)3350=== CONT TestQueueFetchBatchLimit33512026/10/01 10:04:52 INFO Uploading batch count=133522026/10/01 10:04:52 INFO Uploading batch count=233532026/10/01 10:04:52 INFO Uploading batch count=133542026/10/01 10:04:52 INFO Uploading batch count=433552026/10/01 10:04:52 ERROR Upload failed error="upload failed" count=43356--- PASS: TestQueueRemove (0.01s)3357=== CONT TestQueueConcurrentWriters33582026/10/01 10:04:52 INFO Upload queue status pending=333592026/10/01 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-7135-908923472/TestDrainIsolatesPoisonPath2184073598/002/bbb33602026/10/01 10:04:52 INFO Uploading batch count=133612026/10/01 10:04:52 ERROR Upload failed error="upload failed" count=133622026/10/01 10:04:52 INFO Uploading batch count=233632026/10/01 10:04:52 ERROR Upload failed error="upload failed" count=233642026/10/01 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-7135-908923472/TestDrainGivesUpWhenServerDown103479024/002/a33652026/10/01 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-7135-908923472/TestDrainGivesUpWhenServerDown103479024/002/b33662026/10/01 10:04:52 INFO Uploading batch count=133672026/10/01 10:04:52 ERROR Upload failed error="upload failed" count=133682026/10/01 10:04:52 INFO Uploading batch count=233692026/10/01 10:04:52 ERROR Upload failed error="upload failed" count=233702026/10/01 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-7135-908923472/TestDrainGivesUpWhenServerDown103479024/002/c33712026/10/01 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-7135-908923472/TestDrainGivesUpWhenServerDown103479024/002/d3372--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)3373=== CONT TestQueueRemoveLargeClosure33742026/10/01 10:04:52 INFO Uploading batch count=133752026/10/01 10:04:52 ERROR Upload failed error="upload failed" count=133762026/10/01 10:04:52 INFO Uploading batch count=233772026/10/01 10:04:52 ERROR Upload failed error="upload failed" count=233782026/10/01 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-7135-908923472/TestDrainGivesUpWhenServerDown103479024/002/e33792026/10/01 10:04:52 INFO Uploading batch count=133802026/10/01 10:04:52 ERROR Upload failed error="upload failed" count=133812026/10/01 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-7135-908923472/TestDrainGivesUpWhenServerDown103479024/002/f33822026/10/01 10:04:52 ERROR Drain finished with paths left in queue remaining=133832026/10/01 10:04:52 ERROR Drain finished with paths left in queue remaining=103384--- PASS: TestDrainIsolatesPoisonPath (0.01s)3385=== CONT TestQueueFetchRemoveLifecycle3386--- PASS: TestQueueFetchBatchLimit (0.00s)3387=== CONT TestQueueDeduplication3388--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3389=== CONT TestQueueEnqueueAndFetch3390--- PASS: TestQueueFetchRemoveLifecycle (0.00s)3391--- PASS: TestQueueDeduplication (0.00s)3392--- PASS: TestQueueEnqueueAndFetch (0.00s)3393--- PASS: TestWorkerPrunesClosureDeps (0.03s)3394--- PASS: TestWorkerSkipsGCdPaths (0.03s)3395--- PASS: TestWorkerUploadsAndRemoves (0.03s)3396--- PASS: TestQueueRemoveLargeClosure (0.04s)3397--- PASS: TestQueueConcurrentWriters (0.15s)33982026/10/01 10:04:52 ERROR Upload failed error="context deadline exceeded" count=233992026/10/01 10:04:52 ERROR Drain finished with paths left in queue remaining=43400--- PASS: TestDrainTimeout (0.22s)34012026/10/01 10:04:53 INFO Uploading batch count=134022026/10/01 10:04:53 INFO Uploading batch count=134032026/10/01 10:04:53 INFO Uploading batch count=134042026/10/01 10:04:53 ERROR Upload failed error="upload failed" count=134052026/10/01 10:04:53 INFO Uploading batch count=134062026/10/01 10:04:53 ERROR Upload failed error="upload failed" count=134072026/10/01 10:04:53 INFO Uploading batch count=134082026/10/01 10:04:53 ERROR Upload failed error="upload failed" count=134092026/10/01 10:04:53 INFO Uploading batch count=134102026/10/01 10:04:53 ERROR Upload failed error="upload failed" count=134112026/10/01 10:04:53 ERROR Drain finished with paths left in queue remaining=13412--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3413PASS

succeeded niks3-go-unit-tests checks.aarch64-darwin.go-unit-tests · build #330 · raw

succeeded `niks3-go-unit-tests` `checks.aarch64-darwin.go-unit-tests` · build #330 · raw