niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #337
· 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.03s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)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 TestScriptTokenEmptyCommand96=== CONT TestSetClientTLSErrors97--- PASS: TestScriptTokenEmptyCommand (0.00s)98=== CONT TestShellSplit99=== CONT TestStreamPushBatchesUnderLoad100=== CONT TestStreamPushGivesUpOnDeadServer101=== CONT TestStreamPushIsolatesFailures102=== CONT TestScriptTokenNoExpiryRerunsEveryCall103=== CONT TestScriptTokenScriptFails1042026/10/01 10:22:24 ERROR Upload failed error="connection refused" count=201052026/10/01 10:22:24 ERROR Upload failed error="bad path" count=3106=== CONT TestScriptTokenBadJSON1072026/10/01 10:22:24 ERROR Server seems unavailable, giving up on batch untried=17108=== CONT TestScriptTokenEmptyToken109=== CONT TestEncodeNixBase32WithRealHash110--- PASS: TestShellSplit (0.00s)111=== CONT TestScriptTokenCachesUntilRefresh112--- PASS: TestStreamPushIsolatesFailures (0.00s)113--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)114--- PASS: TestEncodeNixBase32WithRealHash (0.00s)115=== CONT TestDoWithRetry_BodyReplayedViaGetBody116=== RUN TestSetClientTLSErrors/missing_cert_file117=== PAUSE TestSetClientTLSErrors/missing_cert_file118=== RUN TestSetClientTLSErrors/missing_key_file119=== PAUSE TestSetClientTLSErrors/missing_key_file120=== RUN TestSetClientTLSErrors/missing_ca_file121=== PAUSE TestSetClientTLSErrors/missing_ca_file122=== RUN TestSetClientTLSErrors/invalid_ca_file123=== PAUSE TestSetClientTLSErrors/invalid_ca_file124=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1252026/10/01 10:22:24 WARN Rate limiter enabled after throttle name=server-test rate=5126=== CONT TestResolveStorePath1272026/10/01 10:22:24 WARN Rate limiter enabled after throttle name=server-test rate=51282026/10/01 10:22:24 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:60596129--- PASS: TestDoServerRequestAttachesToken (0.00s)130=== CONT TestRateLimiterFeedback131--- PASS: TestResolveStorePath (0.00s)132=== CONT TestPathInfoCACompatibility133=== RUN TestPathInfoCACompatibility/null_ca_field134=== PAUSE TestPathInfoCACompatibility/null_ca_field135=== RUN TestPathInfoCACompatibility/old_string_format_-_text136--- PASS: TestScriptTokenScriptFails (0.00s)137=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text138=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive139=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive140=== RUN TestPathInfoCACompatibility/new_structured_format_-_text141=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text142=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method143=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method144=== CONT TestParsePathInfoJSON145=== RUN TestParsePathInfoJSON/Nix_format1462026/10/01 10:22:24 WARN Rate limiter backed off name=server-test rate=51472026/10/01 10:22:24 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:60596148=== CONT TestParsePathInfoJSONMultiplePaths149=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths150=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths152=== RUN TestRateLimiterFeedback/429_enables_limiter153=== PAUSE TestRateLimiterFeedback/429_enables_limiter154=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths155=== PAUSE TestParsePathInfoJSON/Nix_format156=== CONT TestPathInfoHashCompatibility157=== RUN TestRateLimiterFeedback/503_enables_limiter158=== RUN TestParsePathInfoJSON/Lix_format159=== PAUSE TestRateLimiterFeedback/503_enables_limiter160=== PAUSE TestParsePathInfoJSON/Lix_format161=== RUN TestParsePathInfoJSON/empty_input162=== PAUSE TestParsePathInfoJSON/empty_input163=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)164=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter165=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)166=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon167=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon168=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI169=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI170=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter171=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512172=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512173=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter174=== RUN TestParsePathInfoJSON/whitespace_only175=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter176=== CONT TestGetStorePathHash177=== RUN TestGetStorePathHash/valid_store_path178=== PAUSE TestGetStorePathHash/valid_store_path179=== PAUSE TestParsePathInfoJSON/whitespace_only180=== RUN TestGetStorePathHash/basename_without_hyphen_should_error181=== RUN TestParsePathInfoJSON/invalid_JSON182=== PAUSE TestParsePathInfoJSON/invalid_JSON183=== CONT TestConvertHashToNix32184=== RUN TestConvertHashToNix32/SRI_format_to_Nix32185=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32186=== CONT TestUploadMultipart_SupersededByPeer187=== RUN TestUploadMultipart_SupersededByPeer/exists188=== RUN TestConvertHashToNix32/already_Nix32_format189=== PAUSE TestUploadMultipart_SupersededByPeer/exists190=== PAUSE TestConvertHashToNix32/already_Nix32_format191=== RUN TestConvertHashToNix32/invalid_format192=== RUN TestUploadMultipart_SupersededByPeer/missing193=== PAUSE TestConvertHashToNix32/invalid_format194=== CONT TestDumpPathWriterError195--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)196=== CONT TestEncodeNixBase32197=== RUN TestEncodeNixBase32/test_string_hash198=== PAUSE TestEncodeNixBase32/test_string_hash199=== RUN TestEncodeNixBase32/empty_input200=== PAUSE TestEncodeNixBase32/empty_input201=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error202=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error203=== CONT TestDumpPathSingleFile204=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error205=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error206=== PAUSE TestUploadMultipart_SupersededByPeer/missing207=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error208=== CONT TestDumpPathMatchesNix209=== CONT TestSetClientTLS210=== RUN TestSetClientTLS/rejects_connection_without_client_cert211=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert212=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA213=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA214=== RUN TestSetClientTLS/preserves_debug_logging_transport215=== PAUSE TestSetClientTLS/preserves_debug_logging_transport216=== CONT TestSetClientTLSDoesNotMutateDefaultTransport217--- PASS: TestScriptTokenBadJSON (0.01s)218=== CONT TestStreamPushReportsEveryPath219--- PASS: TestStreamPushReportsEveryPath (0.00s)220=== CONT TestFilterOversizedClosures221=== RUN TestFilterOversizedClosures/no_limit_keeps_everything222=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything223=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped224=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped225=== RUN TestFilterOversizedClosures/all_closures_skipped226=== PAUSE TestFilterOversizedClosures/all_closures_skipped227=== CONT TestPartSizeForNAR228=== RUN TestPartSizeForNAR/zero_stays_at_minimum229=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum230=== RUN TestPartSizeForNAR/small_stays_at_minimum231=== PAUSE TestPartSizeForNAR/small_stays_at_minimum232=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum233=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum234=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts235=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts236=== RUN TestPartSizeForNAR/1_TiB237=== PAUSE TestPartSizeForNAR/1_TiB238=== RUN TestPartSizeForNAR/5_TiB_S3_max_object239=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object240=== RUN TestPartSizeForNAR/capped_at_5_GiB241=== PAUSE TestPartSizeForNAR/capped_at_5_GiB242=== CONT TestUploadMultipart_PartsInParallel243--- PASS: TestScriptTokenEmptyToken (0.01s)244=== CONT TestShellSplitErrors245--- PASS: TestShellSplitErrors (0.00s)246=== CONT TestCaseHackSuffix247--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)248=== CONT TestFileTokenMissing249--- PASS: TestFileTokenMissing (0.00s)250=== CONT TestFileTokenEmpty251--- PASS: TestFileTokenEmpty (0.00s)252=== CONT TestFileTokenReadsAndCaches253--- PASS: TestFileTokenReadsAndCaches (0.00s)254=== CONT TestClientSignaturesByStorePath255--- PASS: TestClientSignaturesByStorePath (0.00s)256=== CONT TestRegisterUploadedObjectReusesConnections257--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)258=== CONT TestStaticToken259--- PASS: TestStaticToken (0.00s)260=== CONT TestStreamPushReportsSignatures2612026/10/01 10:22:24 ERROR Upload failed error=boom count=1262--- PASS: TestStreamPushReportsSignatures (0.00s)263=== CONT TestStreamPushRequestLine2642026/10/01 10:22:24 ERROR Upload failed error=boom count=1265--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)266=== CONT TestSetClientTLSErrors/missing_cert_file267=== CONT TestSetClientTLSErrors/missing_ca_file268=== CONT TestSetClientTLSErrors/invalid_ca_file269=== CONT TestSetClientTLSErrors/missing_key_file270--- PASS: TestSetClientTLSErrors (0.00s)271 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)272 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)273 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)274 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)275=== CONT TestPathInfoCACompatibility/null_ca_field276=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method277=== CONT TestPathInfoCACompatibility/new_structured_format_-_text278=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive279=== CONT TestPathInfoCACompatibility/old_string_format_-_text280--- PASS: TestPathInfoCACompatibility (0.00s)281 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)282 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)283 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)284 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)285 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)286=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths287=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths288--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)289 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)290 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)291=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)292--- PASS: TestStreamPushRequestLine (0.01s)293=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512294=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon295=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI296--- PASS: TestPathInfoHashCompatibility (0.00s)297 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)298 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)299 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)300 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)301=== CONT TestRateLimiterFeedback/429_enables_limiter302=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3032026/10/01 10:22:24 WARN Rate limiter enabled after throttle name=server-test rate=53042026/10/01 10:22:24 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:606713052026/10/01 10:22:24 WARN Rate limiter backed off name=server-test rate=5306=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter307--- PASS: TestDumpPathWriterError (0.04s)308=== CONT TestParsePathInfoJSON/Nix_format309=== CONT TestParsePathInfoJSON/whitespace_only310=== CONT TestParsePathInfoJSON/empty_input311=== CONT TestParsePathInfoJSON/Lix_format312=== CONT TestRateLimiterFeedback/503_enables_limiter313=== CONT TestParsePathInfoJSON/invalid_JSON314--- PASS: TestParsePathInfoJSON (0.00s)315 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)316 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)317 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)318 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)319 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)320=== CONT TestConvertHashToNix32/SRI_format_to_Nix32321=== CONT TestConvertHashToNix32/invalid_format322=== CONT TestConvertHashToNix32/already_Nix32_format323--- PASS: TestConvertHashToNix32 (0.00s)324 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)325 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)326 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)327=== CONT TestEncodeNixBase32/test_string_hash328=== CONT TestEncodeNixBase32/empty_input329--- PASS: TestEncodeNixBase32 (0.00s)330 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)331 --- PASS: TestEncodeNixBase32/empty_input (0.00s)332=== CONT TestGetStorePathHash/valid_store_path333=== CONT TestUploadMultipart_SupersededByPeer/exists3342026/10/01 10:22:24 WARN Rate limiter enabled after throttle name=server-test rate=53352026/10/01 10:22:24 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:60677336=== CONT TestUploadMultipart_SupersededByPeer/missing3372026/10/01 10:22:24 WARN Rate limiter backed off name=server-test rate=5338--- PASS: TestRateLimiterFeedback (0.00s)339 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)340 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)341 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)342 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)343=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error344=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error345=== CONT TestGetStorePathHash/basename_without_hyphen_should_error346--- PASS: TestGetStorePathHash (0.00s)347 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)348 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)349 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)350 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)351=== CONT TestSetClientTLS/rejects_connection_without_client_cert352=== CONT TestSetClientTLS/preserves_debug_logging_transport353--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)354=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA355--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)356 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)357 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)358=== CONT TestFilterOversizedClosures/no_limit_keeps_everything359=== CONT TestFilterOversizedClosures/all_closures_skipped3602026/10/01 10:22:24 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=50361=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3622026/10/01 10:22:24 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=2000363=== CONT TestPartSizeForNAR/zero_stays_at_minimum364=== CONT TestPartSizeForNAR/1_TiB365=== CONT TestPartSizeForNAR/capped_at_5_GiB366=== CONT TestPartSizeForNAR/5_TiB_S3_max_object367=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum368=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts369=== CONT TestPartSizeForNAR/small_stays_at_minimum370--- PASS: TestFilterOversizedClosures (0.00s)371 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)372 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)373 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)374--- PASS: TestPartSizeForNAR (0.00s)375 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)376 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)377 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)378 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)379 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)380 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)381 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)3822026/10/01 10:22:24 http: TLS handshake error from 127.0.0.1:60683: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)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.05s)388--- PASS: TestDumpPathSingleFile (0.05s)389--- PASS: TestDumpPathMatchesNix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)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-32041-4233760698/postgres2290529180/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-32041-4233760698/postgres2290529180/data -l logfile start421422/nix/var/nix/builds/nix-32041-4233760698/postgres2290529180:5432 - no response4232026-10-01 10:22:26.111 UTC [32084] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-10-01 10:22:26.112 UTC [32084] LOG: listening on Unix socket "/nix/var/nix/builds/nix-32041-4233760698/postgres2290529180/.s.PGSQL.5432"4252026-10-01 10:22:26.114 UTC [32091] LOG: database system was shut down at 2026-10-01 10:22:26 UTC4262026-10-01 10:22:26.114 UTC [32084] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-32041-4233760698/postgres2290529180:5432 - accepting connections428{"timestamp":"2026-10-01T10:22:26.329747Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"05665174-e948-4341-826f-75a5e17c2a48","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)"}429{"timestamp":"2026-10-01T10:22:26.433503Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a9854559-3535-4b4b-a732-069f9499b63b","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(3)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestLeadElectsOneAndHandsOver471=== PAUSE TestLeadElectsOneAndHandsOver472=== RUN TestLeadIncumbentWinsAfterRestart4732026-10-01 10:22:26.620 UTC [32121] ERROR: relation "goose_db_version" does not exist at character 364742026-10-01 10:22:26.620 UTC [32121] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4752026/10/01 10:22:26 OK 20241026095416_initial_model.sql (3.34ms)4762026/10/01 10:22:26 OK 20251210153512_drop_unused_gin_index.sql (515.75µs)4772026/10/01 10:22:26 OK 20251218171726_add_pins.sql (846.04µs)4782026/10/01 10:22:26 OK 20260628120000_add_object_size_and_stats.sql (892.67µs)4792026/10/01 10:22:26 OK 20260905000000_add_claims.sql (933.71µs)4802026/10/01 10:22:26 OK 20260920000000_drop_claims.sql (561.83µs)4812026/10/01 10:22:26 OK 20260923120000_add_pushes.sql (377.25µs)4822026/10/01 10:22:26 goose: successfully migrated database to version: 202609231200004832026/10/01 10:22:26 OK 1_commit_pending_closure.sql (835.71µs)4842026/10/01 10:22:26 OK 2_object_stats_trigger.sql (213.25µs)4852026/10/01 10:22:26 OK 3_commit_push.sql (191.83µs)4862026/10/01 10:22:26 goose: up to current file version: 34872026/10/01 10:22:26 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 10:22:27 INFO lead: released remote=192.0.2.1:12344892026/10/01 10:22:27 INFO lead: acquired remote=192.0.2.1:12344902026/10/01 10:22:27 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)492=== RUN TestLeadEndsOnShutdown493=== PAUSE TestLeadEndsOnShutdown494=== RUN TestGCAdvisoryLockBlocksConcurrentRun4952026-10-01 10:22:27.427 UTC [32125] ERROR: relation "goose_db_version" does not exist at character 364962026-10-01 10:22:27.427 UTC [32125] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4972026/10/01 10:22:27 OK 20241026095416_initial_model.sql (3.41ms)4982026/10/01 10:22:27 OK 20251210153512_drop_unused_gin_index.sql (400.08µs)4992026/10/01 10:22:27 OK 20251218171726_add_pins.sql (872.42µs)5002026/10/01 10:22:27 OK 20260628120000_add_object_size_and_stats.sql (871.5µs)5012026/10/01 10:22:27 OK 20260905000000_add_claims.sql (1.01ms)5022026/10/01 10:22:27 OK 20260920000000_drop_claims.sql (605.79µs)5032026/10/01 10:22:27 OK 20260923120000_add_pushes.sql (402.58µs)5042026/10/01 10:22:27 goose: successfully migrated database to version: 202609231200005052026/10/01 10:22:27 OK 1_commit_pending_closure.sql (882.04µs)5062026/10/01 10:22:27 OK 2_object_stats_trigger.sql (223.04µs)5072026/10/01 10:22:27 OK 3_commit_push.sql (190.08µs)5082026/10/01 10:22:27 goose: up to current file version: 3509--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.16s)510=== RUN TestGCBugBareHashReferences511=== PAUSE TestGCBugBareHashReferences512=== RUN TestGCMetrics513=== PAUSE TestGCMetrics514=== RUN TestPushDedupSurvivesConcurrentGC515=== PAUSE TestPushDedupSurvivesConcurrentGC516=== RUN TestDeduplicatedObjectsRecordedAsPending517=== PAUSE TestDeduplicatedObjectsRecordedAsPending518=== RUN TestGCSweepSkipsPendingObjects519=== PAUSE TestGCSweepSkipsPendingObjects520=== RUN TestTombstonedObjectOfferedWithoutWaiting521=== PAUSE TestTombstonedObjectOfferedWithoutWaiting522=== RUN TestGCSweepDeliversEachKeyOnce523=== PAUSE TestGCSweepDeliversEachKeyOnce524=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection526=== RUN TestForceGCDuringPushOffersSweptObject527=== PAUSE TestForceGCDuringPushOffersSweptObject528=== RUN TestFailedS3DeleteKeepsTombstone529=== PAUSE TestFailedS3DeleteKeepsTombstone530=== RUN TestSweepSkipsRowsLockedByPush531=== PAUSE TestSweepSkipsRowsLockedByPush532=== RUN TestRegisterCompletedObjectNeedsPendingRow533=== PAUSE TestRegisterCompletedObjectNeedsPendingRow534=== RUN TestGetExistingObjectsLocksRows535=== PAUSE TestGetExistingObjectsLocksRows536=== RUN TestSweepRechecksPendingAfterLocking537=== PAUSE TestSweepRechecksPendingAfterLocking538=== RUN TestPushWaitsForSweepHoldingRow539=== PAUSE TestPushWaitsForSweepHoldingRow540=== RUN TestCommitRacingPendingCleanupKeepsObjects541=== PAUSE TestCommitRacingPendingCleanupKeepsObjects542=== RUN TestGCEndsOnShutdown543=== PAUSE TestGCEndsOnShutdown544=== RUN TestGCTaskStore_StartNew545=== PAUSE TestGCTaskStore_StartNew546=== RUN TestGCTaskStore_DeduplicateSameParams547=== PAUSE TestGCTaskStore_DeduplicateSameParams548=== RUN TestGCTaskStore_ConflictDifferentParams549=== PAUSE TestGCTaskStore_ConflictDifferentParams550=== RUN TestGCTaskStore_GetEmpty551=== PAUSE TestGCTaskStore_GetEmpty552=== RUN TestGCTaskStore_GetReturnsLatest553=== PAUSE TestGCTaskStore_GetReturnsLatest554=== RUN TestGCTaskStore_CompletedAllowsNewTask555=== PAUSE TestGCTaskStore_CompletedAllowsNewTask556=== RUN TestGCTaskStore_PhaseUpdates557=== PAUSE TestGCTaskStore_PhaseUpdates558=== RUN TestGCTaskStore_Fail559=== PAUSE TestGCTaskStore_Fail560=== RUN TestGracefulShutdownDrainsInflight561=== PAUSE TestGracefulShutdownDrainsInflight562=== RUN TestService_healthCheckHandler563=== PAUSE TestService_healthCheckHandler564=== RUN TestService_readinessHandler565=== PAUSE TestService_readinessHandler566=== RUN TestGenerateLandingPage567=== PAUSE TestGenerateLandingPage568=== RUN TestCacheConfigHandlerMaxNarSize569=== PAUSE TestCacheConfigHandlerMaxNarSize570=== RUN TestCreatePendingClosureRejectsOversizedNAR571=== PAUSE TestCreatePendingClosureRejectsOversizedNAR572=== RUN TestNARDeduplicationMetadataUploadBug573=== PAUSE TestNARDeduplicationMetadataUploadBug574=== RUN TestMetricsInventory575=== PAUSE TestMetricsInventory576=== RUN TestService_NativeMTLS577=== PAUSE TestService_NativeMTLS578=== RUN TestServerTLSConfig579=== PAUSE TestServerTLSConfig580=== RUN TestMultipartCleanup581=== PAUSE TestMultipartCleanup582=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded584=== RUN TestPendingCleanupUsesOneCutoff585=== PAUSE TestPendingCleanupUsesOneCutoff586=== RUN TestObjectStatsTrigger587=== PAUSE TestObjectStatsTrigger588=== RUN TestOrphanedObjectsGC589=== PAUSE TestOrphanedObjectsGC590=== RUN TestOrphanedObjectsGCStressTest591=== PAUSE TestOrphanedObjectsGCStressTest592=== RUN TestCreatePin_ReservedPins593=== PAUSE TestCreatePin_ReservedPins594=== RUN TestPresentReportsOnlyClosureRoots595=== PAUSE TestPresentReportsOnlyClosureRoots596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyNarStreaming609=== PAUSE TestReadProxyNarStreaming610=== RUN TestReadProxy404611=== PAUSE TestReadProxy404612=== RUN TestReadProxyInvalidPath613=== PAUSE TestReadProxyInvalidPath614=== RUN TestReadProxyHead615=== PAUSE TestReadProxyHead616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/01 10:22:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 10:22:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/01 10:22:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 10:22:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 10:22:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/01 10:22:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/01 10:22:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/01 10:22:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/01 10:22:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/01 10:22:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestPendingClosureWriteTimeout675=== PAUSE TestPendingClosureWriteTimeout676=== 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 TestPush_CompleteCommitsEveryRoot693=== CONT TestService_AuthMiddleware694=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle695=== CONT TestCompletedNarNotReofferedAcrossClosures696=== CONT TestGCTaskStore_GetEmpty697=== CONT TestLeadEndsOnShutdown698--- PASS: TestGCTaskStore_GetEmpty (0.00s)699=== CONT TestPush_OverlappingRootsStoreOneRowPerKey700=== CONT TestReadRedirectUsesPublicS3URL701=== CONT TestReadProxyRangeRequest702=== CONT TestReadRedirectKeepsNarinfoProxied703=== CONT TestReadRedirectNar7042026-10-01 10:22:28.052 UTC [32147] ERROR: relation "goose_db_version" does not exist at character 367052026-10-01 10:22:28.052 UTC [32147] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7062026-10-01 10:22:28.053 UTC [32149] ERROR: relation "goose_db_version" does not exist at character 367072026-10-01 10:22:28.053 UTC [32149] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7082026-10-01 10:22:28.053 UTC [32148] ERROR: relation "goose_db_version" does not exist at character 367092026-10-01 10:22:28.053 UTC [32148] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7102026-10-01 10:22:28.055 UTC [32151] ERROR: relation "goose_db_version" does not exist at character 367112026-10-01 10:22:28.055 UTC [32151] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7122026-10-01 10:22:28.056 UTC [32150] ERROR: relation "goose_db_version" does not exist at character 367132026-10-01 10:22:28.056 UTC [32150] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7142026-10-01 10:22:28.056 UTC [32153] ERROR: relation "goose_db_version" does not exist at character 367152026-10-01 10:22:28.056 UTC [32153] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7162026-10-01 10:22:28.057 UTC [32152] ERROR: relation "goose_db_version" does not exist at character 367172026-10-01 10:22:28.057 UTC [32152] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7182026-10-01 10:22:28.057 UTC [32156] ERROR: relation "goose_db_version" does not exist at character 367192026-10-01 10:22:28.057 UTC [32156] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7202026-10-01 10:22:28.058 UTC [32155] ERROR: relation "goose_db_version" does not exist at character 367212026-10-01 10:22:28.058 UTC [32155] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026-10-01 10:22:28.058 UTC [32154] ERROR: relation "goose_db_version" does not exist at character 367232026-10-01 10:22:28.058 UTC [32154] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026/10/01 10:22:28 OK 20241026095416_initial_model.sql (6.74ms)7252026/10/01 10:22:28 OK 20241026095416_initial_model.sql (7.02ms)7262026/10/01 10:22:28 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)7272026/10/01 10:22:28 OK 20251210153512_drop_unused_gin_index.sql (900.54µs)7282026/10/01 10:22:28 OK 20241026095416_initial_model.sql (8.29ms)7292026/10/01 10:22:28 OK 20251218171726_add_pins.sql (1.73ms)7302026/10/01 10:22:28 OK 20251218171726_add_pins.sql (2.16ms)7312026/10/01 10:22:28 OK 20251210153512_drop_unused_gin_index.sql (929.25µs)7322026/10/01 10:22:28 OK 20260628120000_add_object_size_and_stats.sql (1.52ms)7332026/10/01 10:22:28 OK 20241026095416_initial_model.sql (8.87ms)7342026/10/01 10:22:28 OK 20260628120000_add_object_size_and_stats.sql (1.7ms)7352026/10/01 10:22:28 OK 20241026095416_initial_model.sql (8.63ms)7362026/10/01 10:22:28 OK 20251218171726_add_pins.sql (2.31ms)7372026/10/01 10:22:28 OK 20251210153512_drop_unused_gin_index.sql (899µs)7382026/10/01 10:22:28 OK 20241026095416_initial_model.sql (7.88ms)7392026/10/01 10:22:28 OK 20241026095416_initial_model.sql (8.3ms)7402026/10/01 10:22:28 OK 20251210153512_drop_unused_gin_index.sql (764.75µs)7412026/10/01 10:22:28 OK 20251210153512_drop_unused_gin_index.sql (828.42µs)7422026/10/01 10:22:28 OK 20251210153512_drop_unused_gin_index.sql (906.17µs)7432026/10/01 10:22:28 OK 20241026095416_initial_model.sql (8.82ms)7442026/10/01 10:22:28 OK 20260905000000_add_claims.sql (2.65ms)7452026/10/01 10:22:28 OK 20241026095416_initial_model.sql (9.39ms)7462026/10/01 10:22:28 OK 20260905000000_add_claims.sql (2.54ms)7472026/10/01 10:22:28 OK 20251218171726_add_pins.sql (1.61ms)7482026/10/01 10:22:28 OK 20251210153512_drop_unused_gin_index.sql (736.17µs)7492026/10/01 10:22:28 OK 20241026095416_initial_model.sql (9.36ms)7502026/10/01 10:22:28 OK 20260628120000_add_object_size_and_stats.sql (2.4ms)7512026/10/01 10:22:28 OK 20251218171726_add_pins.sql (2.36ms)7522026/10/01 10:22:28 OK 20251210153512_drop_unused_gin_index.sql (843.46µs)7532026/10/01 10:22:28 OK 20251218171726_add_pins.sql (1.36ms)7542026/10/01 10:22:28 OK 20251218171726_add_pins.sql (1.74ms)7552026/10/01 10:22:28 OK 20260920000000_drop_claims.sql (1.51ms)7562026/10/01 10:22:28 OK 20251218171726_add_pins.sql (1.1ms)7572026/10/01 10:22:28 OK 20260920000000_drop_claims.sql (1.61ms)7582026/10/01 10:22:28 OK 20251210153512_drop_unused_gin_index.sql (858.96µs)7592026/10/01 10:22:28 OK 20260628120000_add_object_size_and_stats.sql (1.84ms)7602026/10/01 10:22:28 OK 20260628120000_add_object_size_and_stats.sql (1.55ms)7612026/10/01 10:22:28 OK 20260923120000_add_pushes.sql (871.5µs)7622026/10/01 10:22:28 goose: successfully migrated database to version: 202609231200007632026/10/01 10:22:28 OK 20260905000000_add_claims.sql (2.07ms)7642026/10/01 10:22:28 OK 20260923120000_add_pushes.sql (1.44ms)7652026/10/01 10:22:28 goose: successfully migrated database to version: 202609231200007662026/10/01 10:22:28 OK 20260628120000_add_object_size_and_stats.sql (1.91ms)7672026/10/01 10:22:28 OK 20251218171726_add_pins.sql (2.14ms)7682026/10/01 10:22:28 OK 20260628120000_add_object_size_and_stats.sql (2.18ms)7692026/10/01 10:22:28 OK 20260628120000_add_object_size_and_stats.sql (1.73ms)7702026/10/01 10:22:28 OK 20251218171726_add_pins.sql (1.98ms)7712026/10/01 10:22:28 OK 20260920000000_drop_claims.sql (1.13ms)7722026/10/01 10:22:28 OK 1_commit_pending_closure.sql (1.36ms)7732026/10/01 10:22:28 OK 1_commit_pending_closure.sql (1.44ms)7742026/10/01 10:22:28 OK 20260905000000_add_claims.sql (2.02ms)7752026/10/01 10:22:28 OK 2_object_stats_trigger.sql (251.42µs)7762026/10/01 10:22:28 OK 2_object_stats_trigger.sql (607.79µs)7772026/10/01 10:22:28 OK 20260905000000_add_claims.sql (2.2ms)7782026/10/01 10:22:28 OK 20260905000000_add_claims.sql (1.9ms)7792026/10/01 10:22:28 OK 3_commit_push.sql (270.33µs)7802026/10/01 10:22:28 goose: up to current file version: 37812026/10/01 10:22:28 OK 3_commit_push.sql (493.79µs)7822026/10/01 10:22:28 goose: up to current file version: 37832026/10/01 10:22:28 OK 20260923120000_add_pushes.sql (1.25ms)7842026/10/01 10:22:28 goose: successfully migrated database to version: 202609231200007852026/10/01 10:22:28 OK 20260905000000_add_claims.sql (2.08ms)7862026/10/01 10:22:28 OK 20260905000000_add_claims.sql (1.79ms)7872026/10/01 10:22:28 OK 20260628120000_add_object_size_and_stats.sql (2.21ms)7882026/10/01 10:22:28 OK 20260628120000_add_object_size_and_stats.sql (2ms)7892026/10/01 10:22:28 OK 20260920000000_drop_claims.sql (1.47ms)7902026/10/01 10:22:28 OK 20260920000000_drop_claims.sql (1.51ms)7912026/10/01 10:22:28 OK 1_commit_pending_closure.sql (1.1ms)7922026/10/01 10:22:28 OK 20260920000000_drop_claims.sql (1.39ms)7932026/10/01 10:22:28 OK 20260920000000_drop_claims.sql (1.19ms)7942026/10/01 10:22:28 OK 20260920000000_drop_claims.sql (1.25ms)7952026/10/01 10:22:28 OK 2_object_stats_trigger.sql (511.67µs)7962026/10/01 10:22:28 OK 20260923120000_add_pushes.sql (864.54µs)7972026/10/01 10:22:28 goose: successfully migrated database to version: 202609231200007982026/10/01 10:22:28 OK 20260923120000_add_pushes.sql (580.13µs)7992026/10/01 10:22:28 goose: successfully migrated database to version: 202609231200008002026/10/01 10:22:28 OK 20260923120000_add_pushes.sql (763.42µs)8012026/10/01 10:22:28 goose: successfully migrated database to version: 202609231200008022026/10/01 10:22:28 OK 3_commit_push.sql (420.5µs)8032026/10/01 10:22:28 goose: up to current file version: 38042026/10/01 10:22:28 OK 20260923120000_add_pushes.sql (762.29µs)8052026/10/01 10:22:28 goose: successfully migrated database to version: 202609231200008062026/10/01 10:22:28 OK 20260905000000_add_claims.sql (2.02ms)8072026/10/01 10:22:28 OK 20260923120000_add_pushes.sql (1.06ms)8082026/10/01 10:22:28 goose: successfully migrated database to version: 202609231200008092026/10/01 10:22:28 OK 20260905000000_add_claims.sql (1.88ms)8102026/10/01 10:22:28 OK 1_commit_pending_closure.sql (1.2ms)8112026/10/01 10:22:28 OK 1_commit_pending_closure.sql (885.17µs)8122026/10/01 10:22:28 OK 1_commit_pending_closure.sql (1.38ms)8132026/10/01 10:22:28 OK 2_object_stats_trigger.sql (297.42µs)8142026/10/01 10:22:28 OK 1_commit_pending_closure.sql (1.59ms)8152026/10/01 10:22:28 OK 1_commit_pending_closure.sql (909.75µs)8162026/10/01 10:22:28 OK 2_object_stats_trigger.sql (365.38µs)8172026/10/01 10:22:28 OK 2_object_stats_trigger.sql (263.33µs)8182026/10/01 10:22:28 OK 3_commit_push.sql (246.96µs)8192026/10/01 10:22:28 goose: up to current file version: 38202026/10/01 10:22:28 OK 2_object_stats_trigger.sql (255.79µs)8212026/10/01 10:22:28 OK 2_object_stats_trigger.sql (248.04µs)8222026/10/01 10:22:28 OK 3_commit_push.sql (196.33µs)8232026/10/01 10:22:28 goose: up to current file version: 38242026/10/01 10:22:28 OK 3_commit_push.sql (169.17µs)8252026/10/01 10:22:28 goose: up to current file version: 38262026/10/01 10:22:28 OK 3_commit_push.sql (150.92µs)8272026/10/01 10:22:28 goose: up to current file version: 38282026/10/01 10:22:28 OK 3_commit_push.sql (217µs)8292026/10/01 10:22:28 goose: up to current file version: 38302026/10/01 10:22:28 OK 20260920000000_drop_claims.sql (2.98ms)8312026/10/01 10:22:28 OK 20260920000000_drop_claims.sql (3.28ms)8322026/10/01 10:22:28 OK 20260923120000_add_pushes.sql (645.75µs)8332026/10/01 10:22:28 goose: successfully migrated database to version: 202609231200008342026/10/01 10:22:28 OK 20260923120000_add_pushes.sql (705.88µs)8352026/10/01 10:22:28 goose: successfully migrated database to version: 202609231200008362026/10/01 10:22:28 OK 1_commit_pending_closure.sql (740.46µs)8372026/10/01 10:22:28 OK 1_commit_pending_closure.sql (734.13µs)8382026/10/01 10:22:28 OK 2_object_stats_trigger.sql (195.17µs)8392026/10/01 10:22:28 OK 2_object_stats_trigger.sql (198.08µs)8402026/10/01 10:22:28 OK 3_commit_push.sql (158.96µs)8412026/10/01 10:22:28 goose: up to current file version: 38422026/10/01 10:22:28 OK 3_commit_push.sql (161.79µs)8432026/10/01 10:22:28 goose: up to current file version: 38442026/10/01 10:22:28 INFO lead: acquired remote=192.0.2.1:12348452026/10/01 10:22:28 INFO lead: released remote=192.0.2.1:1234846--- PASS: TestLeadEndsOnShutdown (0.44s)847=== CONT TestReadProxyDisabled8482026/10/01 10:22:28 INFO Received uploads request method=POST path=/api/pending_closures849--- PASS: TestReadRedirectKeepsNarinfoProxied (0.76s)850=== CONT TestReadProxyRootRedirectsToIndexHTML8512026/10/01 10:22:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8522026/10/01 10:22:28 INFO Received uploads request method=POST path=/api/pending_closures8532026/10/01 10:22:28 INFO Received push request method=POST path=/api/pushes8542026/10/01 10:22:28 INFO Received complete push request method=POST path=/api/pushes/1/complete855--- PASS: TestPush_CompleteCommitsEveryRoot (1.18s)856=== CONT TestReadProxyConditionalGet8572026-10-01 10:22:29.014 UTC [32164] ERROR: relation "goose_db_version" does not exist at character 368582026-10-01 10:22:29.014 UTC [32164] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8592026/10/01 10:22:29 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"860--- PASS: TestService_AuthMiddleware (1.31s)861=== CONT TestReadProxyHead8622026/10/01 10:22:29 OK 20241026095416_initial_model.sql (102.84ms)8632026/10/01 10:22:29 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)8642026/10/01 10:22:29 OK 20251218171726_add_pins.sql (15.62ms)8652026/10/01 10:22:29 OK 20260628120000_add_object_size_and_stats.sql (19.87ms)8662026/10/01 10:22:29 OK 20260905000000_add_claims.sql (31.22ms)867--- PASS: TestReadRedirectNar (1.52s)868=== CONT TestReadProxyInvalidPath8692026/10/01 10:22:29 OK 20260920000000_drop_claims.sql (22.91ms)8702026/10/01 10:22:29 OK 20260923120000_add_pushes.sql (14.14ms)8712026/10/01 10:22:29 goose: successfully migrated database to version: 202609231200008722026/10/01 10:22:29 OK 1_commit_pending_closure.sql (1.77ms)8732026/10/01 10:22:29 OK 2_object_stats_trigger.sql (462.58µs)8742026/10/01 10:22:29 OK 3_commit_push.sql (376.04µs)8752026/10/01 10:22:29 goose: up to current file version: 38762026-10-01 10:22:29.347 UTC [32169] ERROR: relation "goose_db_version" does not exist at character 368772026-10-01 10:22:29.347 UTC [32169] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8782026/10/01 10:22:29 INFO Received push request method=POST path=/api/pushes879--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.76s)880=== CONT TestReadProxy4048812026/10/01 10:22:29 OK 20241026095416_initial_model.sql (123.88ms)8822026/10/01 10:22:29 OK 20251210153512_drop_unused_gin_index.sql (12.95ms)8832026/10/01 10:22:29 OK 20251218171726_add_pins.sql (18ms)8842026/10/01 10:22:29 OK 20260628120000_add_object_size_and_stats.sql (46.44ms)8852026/10/01 10:22:29 OK 20260905000000_add_claims.sql (48.33ms)8862026/10/01 10:22:29 OK 20260920000000_drop_claims.sql (28.23ms)8872026/10/01 10:22:29 OK 20260923120000_add_pushes.sql (15.58ms)8882026/10/01 10:22:29 goose: successfully migrated database to version: 202609231200008892026/10/01 10:22:29 OK 1_commit_pending_closure.sql (2.98ms)8902026/10/01 10:22:29 OK 2_object_stats_trigger.sql (628.67µs)8912026/10/01 10:22:29 OK 3_commit_push.sql (356.38µs)8922026/10/01 10:22:29 goose: up to current file version: 3893--- PASS: TestReadRedirectUsesPublicS3URL (1.95s)894=== CONT TestReadProxyNarStreaming8952026-10-01 10:22:29.844 UTC [32175] ERROR: relation "goose_db_version" does not exist at character 368962026-10-01 10:22:29.844 UTC [32175] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC897--- PASS: TestReadProxyRangeRequest (2.15s)898=== CONT TestReadProxyNarinfoAlreadyDecompressed8992026/10/01 10:22:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9002026/10/01 10:22:30 OK 20241026095416_initial_model.sql (113.62ms)9012026/10/01 10:22:30 OK 20251210153512_drop_unused_gin_index.sql (9.99ms)9022026/10/01 10:22:30 OK 20251218171726_add_pins.sql (18.09ms)9032026/10/01 10:22:30 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MDZhZmRjZjYtNGQxMS00NzNmLWE3N2ItNjg1OTY0OTI3ZjA4LmU4MzYxM2Q3LTU0YmEtNDMxYi1hNmNhLWQ5OThhZDA4MjFjMngxNzkwODUwMTQ4NzA1NjE0MDAw parts=129042026/10/01 10:22:30 INFO Received uploads request method=POST path=/api/pending_closures905--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.31s)906=== CONT TestReadProxyNarinfo9072026/10/01 10:22:30 OK 20260628120000_add_object_size_and_stats.sql (34.83ms)908--- PASS: TestReadProxyDisabled (1.92s)909=== CONT TestIsValidCachePath910=== RUN TestIsValidCachePath/narinfo911=== PAUSE TestIsValidCachePath/narinfo912=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars913=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars914=== RUN TestIsValidCachePath/nar_zst915=== PAUSE TestIsValidCachePath/nar_zst916=== RUN TestIsValidCachePath/nar_xz917=== PAUSE TestIsValidCachePath/nar_xz918=== RUN TestIsValidCachePath/nar_bz2919=== PAUSE TestIsValidCachePath/nar_bz2920=== RUN TestIsValidCachePath/nar_uncompressed921=== PAUSE TestIsValidCachePath/nar_uncompressed922=== RUN TestIsValidCachePath/ls923=== PAUSE TestIsValidCachePath/ls924=== RUN TestIsValidCachePath/log925=== PAUSE TestIsValidCachePath/log926=== RUN TestIsValidCachePath/realisation927=== PAUSE TestIsValidCachePath/realisation928=== RUN TestIsValidCachePath/nix-cache-info929=== PAUSE TestIsValidCachePath/nix-cache-info930=== RUN TestIsValidCachePath/index.html931=== PAUSE TestIsValidCachePath/index.html932=== RUN TestIsValidCachePath/traversal_parent933=== PAUSE TestIsValidCachePath/traversal_parent934=== RUN TestIsValidCachePath/traversal_in_middle935=== PAUSE TestIsValidCachePath/traversal_in_middle936=== RUN TestIsValidCachePath/invalid_char_e937=== PAUSE TestIsValidCachePath/invalid_char_e938=== RUN TestIsValidCachePath/invalid_char_u939=== PAUSE TestIsValidCachePath/invalid_char_u940=== RUN TestIsValidCachePath/random_path941=== PAUSE TestIsValidCachePath/random_path942=== RUN TestIsValidCachePath/empty943=== PAUSE TestIsValidCachePath/empty944=== RUN TestIsValidCachePath/leading_slash945=== PAUSE TestIsValidCachePath/leading_slash946=== RUN TestIsValidCachePath/wrong_extension947=== PAUSE TestIsValidCachePath/wrong_extension948=== RUN TestIsValidCachePath/short_hash949=== PAUSE TestIsValidCachePath/short_hash950=== CONT TestProxyHeadersOnlyTrustedOnSocket9512026/10/01 10:22:30 OK 20260905000000_add_claims.sql (24.87ms)9522026/10/01 10:22:30 OK 20260920000000_drop_claims.sql (33.69ms)9532026/10/01 10:22:30 OK 20260923120000_add_pushes.sql (5.58ms)9542026/10/01 10:22:30 goose: successfully migrated database to version: 202609231200009552026-10-01 10:22:30.134 UTC [32181] ERROR: relation "goose_db_version" does not exist at character 369562026-10-01 10:22:30.134 UTC [32181] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9572026/10/01 10:22:30 OK 1_commit_pending_closure.sql (2.62ms)9582026/10/01 10:22:30 OK 2_object_stats_trigger.sql (568.71µs)9592026/10/01 10:22:30 OK 3_commit_push.sql (465.04µs)9602026/10/01 10:22:30 goose: up to current file version: 39612026/10/01 10:22:30 OK 20241026095416_initial_model.sql (59.93ms)9622026/10/01 10:22:30 OK 20251210153512_drop_unused_gin_index.sql (5.35ms)9632026/10/01 10:22:30 OK 20251218171726_add_pins.sql (21.98ms)964--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.78s)965=== CONT TestParseSingleRange966=== RUN TestParseSingleRange/none967=== PAUSE TestParseSingleRange/none968=== RUN TestParseSingleRange/unknown_unit969=== PAUSE TestParseSingleRange/unknown_unit970=== RUN TestParseSingleRange/multi-range_ignored971=== PAUSE TestParseSingleRange/multi-range_ignored972=== RUN TestParseSingleRange/malformed_no_dash973=== PAUSE TestParseSingleRange/malformed_no_dash974=== RUN TestParseSingleRange/malformed_both_empty975=== PAUSE TestParseSingleRange/malformed_both_empty976=== RUN TestParseSingleRange/malformed_end_before_start977=== PAUSE TestParseSingleRange/malformed_end_before_start978=== RUN TestParseSingleRange/closed979=== PAUSE TestParseSingleRange/closed980=== RUN TestParseSingleRange/open-ended981=== PAUSE TestParseSingleRange/open-ended982=== RUN TestParseSingleRange/end_clamped_to_size983=== PAUSE TestParseSingleRange/end_clamped_to_size984=== RUN TestParseSingleRange/suffix985=== PAUSE TestParseSingleRange/suffix986=== RUN TestParseSingleRange/suffix_exceeds_size987=== PAUSE TestParseSingleRange/suffix_exceeds_size988=== RUN TestParseSingleRange/single_byte989=== PAUSE TestParseSingleRange/single_byte990=== RUN TestParseSingleRange/start_past_EOF991=== PAUSE TestParseSingleRange/start_past_EOF992=== RUN TestParseSingleRange/start_far_past_EOF993=== PAUSE TestParseSingleRange/start_far_past_EOF994=== CONT TestPresentNotReportedWhileGCDeletesClosure9952026/10/01 10:22:30 OK 20260628120000_add_object_size_and_stats.sql (40.26ms)9962026/10/01 10:22:30 OK 20260905000000_add_claims.sql (59.66ms)9972026/10/01 10:22:30 OK 20260920000000_drop_claims.sql (19.24ms)9982026-10-01 10:22:30.367 UTC [32185] ERROR: relation "goose_db_version" does not exist at character 369992026-10-01 10:22:30.367 UTC [32185] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10002026/10/01 10:22:30 OK 20260923120000_add_pushes.sql (8.2ms)10012026/10/01 10:22:30 goose: successfully migrated database to version: 2026092312000010022026/10/01 10:22:30 OK 1_commit_pending_closure.sql (2.74ms)10032026/10/01 10:22:30 OK 2_object_stats_trigger.sql (508.21µs)10042026/10/01 10:22:30 OK 3_commit_push.sql (362.79µs)10052026/10/01 10:22:30 goose: up to current file version: 31006--- PASS: TestReadProxyConditionalGet (1.56s)1007=== CONT TestPresentReportsOnlyClosureRoots10082026/10/01 10:22:30 OK 20241026095416_initial_model.sql (80.73ms)10092026/10/01 10:22:30 OK 20251210153512_drop_unused_gin_index.sql (16.29ms)10102026/10/01 10:22:30 OK 20251218171726_add_pins.sql (30.19ms)10112026/10/01 10:22:30 OK 20260628120000_add_object_size_and_stats.sql (19.37ms)10122026/10/01 10:22:30 OK 20260905000000_add_claims.sql (21.04ms)10132026/10/01 10:22:30 OK 20260920000000_drop_claims.sql (10.31ms)10142026/10/01 10:22:30 OK 20260923120000_add_pushes.sql (17.43ms)10152026/10/01 10:22:30 goose: successfully migrated database to version: 2026092312000010162026/10/01 10:22:30 OK 1_commit_pending_closure.sql (3.47ms)10172026/10/01 10:22:30 OK 2_object_stats_trigger.sql (929.38µs)10182026/10/01 10:22:30 OK 3_commit_push.sql (866.79µs)10192026/10/01 10:22:30 goose: up to current file version: 31020--- PASS: TestReadProxyHead (1.64s)1021=== CONT TestCreatePin_ReservedPins10222026-10-01 10:22:30.700 UTC [32188] ERROR: relation "goose_db_version" does not exist at character 3610232026-10-01 10:22:30.700 UTC [32188] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10242026/10/01 10:22:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60772/oidc10252026-10-01 10:22:30.791 UTC [32192] ERROR: relation "goose_db_version" does not exist at character 3610262026-10-01 10:22:30.791 UTC [32192] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10272026/10/01 10:22:30 OK 20241026095416_initial_model.sql (84.03ms)1028--- PASS: TestReadProxyInvalidPath (1.58s)1029=== CONT TestOrphanedObjectsGCStressTest10302026/10/01 10:22:30 OK 20251210153512_drop_unused_gin_index.sql (11.91ms)10312026/10/01 10:22:30 OK 20251218171726_add_pins.sql (16.18ms)10322026/10/01 10:22:30 OK 20260628120000_add_object_size_and_stats.sql (9.09ms)10332026-10-01 10:22:30.864 UTC [32195] ERROR: relation "goose_db_version" does not exist at character 3610342026-10-01 10:22:30.864 UTC [32195] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10352026/10/01 10:22:30 OK 20260905000000_add_claims.sql (5.94ms)10362026/10/01 10:22:30 OK 20260920000000_drop_claims.sql (805.88µs)10372026/10/01 10:22:30 OK 20260923120000_add_pushes.sql (589.88µs)10382026/10/01 10:22:30 goose: successfully migrated database to version: 2026092312000010392026/10/01 10:22:30 OK 1_commit_pending_closure.sql (1.25ms)10402026/10/01 10:22:30 OK 2_object_stats_trigger.sql (267.38µs)10412026/10/01 10:22:30 OK 3_commit_push.sql (211.25µs)10422026/10/01 10:22:30 goose: up to current file version: 310432026/10/01 10:22:30 OK 20241026095416_initial_model.sql (41.85ms)10442026/10/01 10:22:30 OK 20251210153512_drop_unused_gin_index.sql (5.33ms)10452026/10/01 10:22:30 OK 20251218171726_add_pins.sql (14.37ms)10462026/10/01 10:22:30 OK 20260628120000_add_object_size_and_stats.sql (16.26ms)10472026/10/01 10:22:30 OK 20260905000000_add_claims.sql (21.03ms)10482026/10/01 10:22:30 OK 20260920000000_drop_claims.sql (8.18ms)10492026/10/01 10:22:30 OK 20241026095416_initial_model.sql (49.14ms)10502026/10/01 10:22:30 OK 20251210153512_drop_unused_gin_index.sql (10.53ms)10512026/10/01 10:22:30 OK 20260923120000_add_pushes.sql (13.74ms)10522026/10/01 10:22:30 goose: successfully migrated database to version: 2026092312000010532026/10/01 10:22:30 OK 1_commit_pending_closure.sql (1.53ms)10542026/10/01 10:22:30 OK 2_object_stats_trigger.sql (335.96µs)10552026/10/01 10:22:30 OK 3_commit_push.sql (289.96µs)10562026/10/01 10:22:30 goose: up to current file version: 310572026/10/01 10:22:30 OK 20251218171726_add_pins.sql (12.39ms)10582026/10/01 10:22:30 OK 20260628120000_add_object_size_and_stats.sql (20.42ms)10592026/10/01 10:22:31 OK 20260905000000_add_claims.sql (24.85ms)10602026/10/01 10:22:31 OK 20260920000000_drop_claims.sql (25.33ms)10612026/10/01 10:22:31 OK 20260923120000_add_pushes.sql (4.37ms)10622026/10/01 10:22:31 goose: successfully migrated database to version: 2026092312000010632026/10/01 10:22:31 OK 1_commit_pending_closure.sql (3.63ms)10642026/10/01 10:22:31 OK 2_object_stats_trigger.sql (484.63µs)10652026/10/01 10:22:31 OK 3_commit_push.sql (478.96µs)10662026/10/01 10:22:31 goose: up to current file version: 31067--- PASS: TestReadProxy404 (1.64s)1068=== CONT TestOrphanedObjectsGC10692026-10-01 10:22:31.139 UTC [32197] ERROR: relation "goose_db_version" does not exist at character 3610702026-10-01 10:22:31.139 UTC [32197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10712026-10-01 10:22:31.188 UTC [32199] ERROR: relation "goose_db_version" does not exist at character 3610722026-10-01 10:22:31.188 UTC [32199] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1073--- PASS: TestReadProxyNarStreaming (1.59s)1074=== CONT TestObjectStatsTrigger10752026/10/01 10:22:31 OK 20241026095416_initial_model.sql (98.6ms)10762026/10/01 10:22:31 OK 20251210153512_drop_unused_gin_index.sql (12.13ms)10772026/10/01 10:22:31 OK 20251218171726_add_pins.sql (11.42ms)10782026/10/01 10:22:31 OK 20241026095416_initial_model.sql (101.31ms)10792026/10/01 10:22:31 OK 20251210153512_drop_unused_gin_index.sql (8.02ms)10802026/10/01 10:22:31 OK 20260628120000_add_object_size_and_stats.sql (37.04ms)10812026/10/01 10:22:31 OK 20251218171726_add_pins.sql (22.05ms)10822026/10/01 10:22:31 OK 20260905000000_add_claims.sql (17.46ms)10832026/10/01 10:22:31 OK 20260628120000_add_object_size_and_stats.sql (17.78ms)10842026-10-01 10:22:31.367 UTC [32203] ERROR: relation "goose_db_version" does not exist at character 3610852026-10-01 10:22:31.367 UTC [32203] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10862026/10/01 10:22:31 OK 20260920000000_drop_claims.sql (15.9ms)10872026/10/01 10:22:31 OK 20260923120000_add_pushes.sql (8.61ms)10882026/10/01 10:22:31 goose: successfully migrated database to version: 2026092312000010892026/10/01 10:22:31 OK 20260905000000_add_claims.sql (24.27ms)10902026/10/01 10:22:31 OK 1_commit_pending_closure.sql (2.13ms)10912026/10/01 10:22:31 OK 2_object_stats_trigger.sql (475.08µs)10922026/10/01 10:22:31 OK 3_commit_push.sql (367.79µs)10932026/10/01 10:22:31 goose: up to current file version: 310942026/10/01 10:22:31 OK 20260920000000_drop_claims.sql (20.62ms)10952026/10/01 10:22:31 OK 20260923120000_add_pushes.sql (5.89ms)10962026/10/01 10:22:31 goose: successfully migrated database to version: 2026092312000010972026/10/01 10:22:31 OK 1_commit_pending_closure.sql (1.92ms)10982026/10/01 10:22:31 OK 2_object_stats_trigger.sql (422.71µs)10992026/10/01 10:22:31 OK 3_commit_push.sql (326.92µs)11002026/10/01 10:22:31 goose: up to current file version: 31101--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.58s)1102=== CONT TestPendingCleanupUsesOneCutoff11032026/10/01 10:22:31 OK 20241026095416_initial_model.sql (121.15ms)11042026/10/01 10:22:31 OK 20251210153512_drop_unused_gin_index.sql (6.01ms)11052026/10/01 10:22:31 OK 20251218171726_add_pins.sql (8.01ms)11062026/10/01 10:22:31 OK 20260628120000_add_object_size_and_stats.sql (16.88ms)11072026/10/01 10:22:31 OK 20260905000000_add_claims.sql (49.14ms)11082026/10/01 10:22:31 OK 20260920000000_drop_claims.sql (26.22ms)11092026-10-01 10:22:31.642 UTC [32206] ERROR: relation "goose_db_version" does not exist at character 3611102026-10-01 10:22:31.642 UTC [32206] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11112026/10/01 10:22:31 INFO Starting HTTP server address=127.0.0.1:6079011122026/10/01 10:22:31 INFO Starting HTTP server address=/nix/var/nix/builds/nix-32041-4233760698/TestProxyHeadersOnlyTrustedOnSocket885877104/001/proxy.sock11132026/10/01 10:22:31 OK 20260923120000_add_pushes.sql (4.56ms)11142026/10/01 10:22:31 goose: successfully migrated database to version: 2026092312000011152026/10/01 10:22:31 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11162026/10/01 10:22:31 INFO Shutdown signal received, draining in-flight requests timeout=10s1117--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.56s)1118=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11192026/10/01 10:22:31 OK 1_commit_pending_closure.sql (7.04ms)11202026/10/01 10:22:31 OK 2_object_stats_trigger.sql (893.83µs)11212026/10/01 10:22:31 OK 3_commit_push.sql (461.63µs)11222026/10/01 10:22:31 goose: up to current file version: 311232026/10/01 10:22:31 OK 20241026095416_initial_model.sql (51.6ms)11242026/10/01 10:22:31 OK 20251210153512_drop_unused_gin_index.sql (6.25ms)11252026/10/01 10:22:31 OK 20251218171726_add_pins.sql (14.76ms)11262026-10-01 10:22:31.771 UTC [32209] ERROR: relation "goose_db_version" does not exist at character 3611272026-10-01 10:22:31.771 UTC [32209] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11282026/10/01 10:22:31 OK 20260628120000_add_object_size_and_stats.sql (10.86ms)11292026/10/01 10:22:31 OK 20260905000000_add_claims.sql (30.13ms)11302026/10/01 10:22:31 OK 20260920000000_drop_claims.sql (20.07ms)11312026/10/01 10:22:31 OK 20260923120000_add_pushes.sql (15.59ms)11322026/10/01 10:22:31 goose: successfully migrated database to version: 2026092312000011332026/10/01 10:22:31 OK 1_commit_pending_closure.sql (6.67ms)11342026/10/01 10:22:31 OK 2_object_stats_trigger.sql (864.79µs)11352026/10/01 10:22:31 OK 3_commit_push.sql (459µs)11362026/10/01 10:22:31 goose: up to current file version: 31137--- PASS: TestReadProxyNarinfo (1.82s)1138=== CONT TestMultipartCleanup11392026/10/01 10:22:31 OK 20241026095416_initial_model.sql (134.22ms)11402026-10-01 10:22:31.939 UTC [32212] ERROR: relation "goose_db_version" does not exist at character 3611412026-10-01 10:22:31.939 UTC [32212] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11422026/10/01 10:22:31 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)11432026/10/01 10:22:31 OK 20251218171726_add_pins.sql (16ms)11442026/10/01 10:22:31 OK 20260628120000_add_object_size_and_stats.sql (23.72ms)11452026/10/01 10:22:32 OK 20260905000000_add_claims.sql (21.5ms)11462026/10/01 10:22:32 OK 20260920000000_drop_claims.sql (31.38ms)11472026/10/01 10:22:32 OK 20260923120000_add_pushes.sql (6.78ms)11482026/10/01 10:22:32 goose: successfully migrated database to version: 2026092312000011492026/10/01 10:22:32 OK 1_commit_pending_closure.sql (3.21ms)11502026/10/01 10:22:32 OK 2_object_stats_trigger.sql (622.54µs)11512026/10/01 10:22:32 OK 3_commit_push.sql (417.04µs)11522026/10/01 10:22:32 goose: up to current file version: 311532026/10/01 10:22:32 OK 20241026095416_initial_model.sql (102.24ms)11542026/10/01 10:22:32 OK 20251210153512_drop_unused_gin_index.sql (7.7ms)11552026/10/01 10:22:32 OK 20251218171726_add_pins.sql (12.71ms)11562026/10/01 10:22:32 OK 20260628120000_add_object_size_and_stats.sql (11.35ms)11572026/10/01 10:22:32 OK 20260905000000_add_claims.sql (16.87ms)11582026/10/01 10:22:32 OK 20260920000000_drop_claims.sql (13.45ms)11592026/10/01 10:22:32 OK 20260923120000_add_pushes.sql (4.93ms)11602026/10/01 10:22:32 goose: successfully migrated database to version: 2026092312000011612026/10/01 10:22:32 OK 1_commit_pending_closure.sql (4.03ms)11622026/10/01 10:22:32 OK 2_object_stats_trigger.sql (799.08µs)11632026/10/01 10:22:32 OK 3_commit_push.sql (521.67µs)11642026/10/01 10:22:32 goose: up to current file version: 311652026-10-01 10:22:32.256 UTC [32215] ERROR: relation "goose_db_version" does not exist at character 3611662026-10-01 10:22:32.256 UTC [32215] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1167--- PASS: TestPresentReportsOnlyClosureRoots (1.82s)1168=== CONT TestServerTLSConfig1169=== RUN TestServerTLSConfig/no_client_CA1170=== PAUSE TestServerTLSConfig/no_client_CA1171=== RUN TestServerTLSConfig/missing_CA_file1172=== PAUSE TestServerTLSConfig/missing_CA_file1173=== RUN TestServerTLSConfig/not_a_PEM_file1174=== PAUSE TestServerTLSConfig/not_a_PEM_file1175=== CONT TestService_NativeMTLS11762026-10-01 10:22:32.358 UTC [32218] ERROR: relation "goose_db_version" does not exist at character 3611772026-10-01 10:22:32.358 UTC [32218] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11782026/10/01 10:22:32 OK 20241026095416_initial_model.sql (62.92ms)11792026/10/01 10:22:32 OK 20251210153512_drop_unused_gin_index.sql (8.19ms)11802026/10/01 10:22:32 OK 20251218171726_add_pins.sql (18.36ms)11812026/10/01 10:22:32 OK 20260628120000_add_object_size_and_stats.sql (25.29ms)11822026-10-01 10:22:32.437 UTC [32219] ERROR: relation "goose_db_version" does not exist at character 3611832026-10-01 10:22:32.437 UTC [32219] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11842026/10/01 10:22:32 OK 20260905000000_add_claims.sql (17.76ms)11852026/10/01 10:22:32 OK 20241026095416_initial_model.sql (61.02ms)11862026/10/01 10:22:32 OK 20251210153512_drop_unused_gin_index.sql (11.92ms)11872026/10/01 10:22:32 OK 20260920000000_drop_claims.sql (25.47ms)11882026/10/01 10:22:32 OK 20260923120000_add_pushes.sql (4.34ms)11892026/10/01 10:22:32 goose: successfully migrated database to version: 2026092312000011902026/10/01 10:22:32 OK 20251218171726_add_pins.sql (16.73ms)11912026/10/01 10:22:32 OK 1_commit_pending_closure.sql (4.25ms)11922026/10/01 10:22:32 OK 2_object_stats_trigger.sql (732.33µs)11932026/10/01 10:22:32 OK 3_commit_push.sql (462.38µs)11942026/10/01 10:22:32 goose: up to current file version: 311952026/10/01 10:22:32 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11962026/10/01 10:22:32 WARN Refused reserved pin name=worker-x86_64-linux11972026/10/01 10:22:32 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11982026/10/01 10:22:32 INFO Received create pin request method=POST path=/api/pins/my-app11992026/10/01 10:22:32 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1200--- PASS: TestCreatePin_ReservedPins (1.82s)1201=== CONT TestMetricsInventory12022026/10/01 10:22:32 OK 20260628120000_add_object_size_and_stats.sql (41.7ms)12032026/10/01 10:22:32 OK 20260905000000_add_claims.sql (15.7ms)12042026/10/01 10:22:32 OK 20260920000000_drop_claims.sql (8.44ms)12052026/10/01 10:22:32 OK 20260923120000_add_pushes.sql (6.61ms)12062026/10/01 10:22:32 goose: successfully migrated database to version: 2026092312000012072026/10/01 10:22:32 OK 1_commit_pending_closure.sql (2.27ms)12082026/10/01 10:22:32 OK 2_object_stats_trigger.sql (469.08µs)12092026/10/01 10:22:32 OK 3_commit_push.sql (336.42µs)12102026/10/01 10:22:32 goose: up to current file version: 312112026/10/01 10:22:32 OK 20241026095416_initial_model.sql (80.38ms)12122026/10/01 10:22:32 OK 20251210153512_drop_unused_gin_index.sql (6.27ms)1213--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.30s)1214=== CONT TestNARDeduplicationMetadataUploadBug12152026/10/01 10:22:32 OK 20251218171726_add_pins.sql (4.7ms)12162026/10/01 10:22:32 OK 20260628120000_add_object_size_and_stats.sql (15.13ms)12172026/10/01 10:22:32 OK 20260905000000_add_claims.sql (20.33ms)12182026/10/01 10:22:32 OK 20260920000000_drop_claims.sql (21.52ms)12192026-10-01 10:22:32.626 UTC [32224] ERROR: relation "goose_db_version" does not exist at character 3612202026-10-01 10:22:32.626 UTC [32224] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12212026/10/01 10:22:32 OK 20260923120000_add_pushes.sql (5.02ms)12222026/10/01 10:22:32 goose: successfully migrated database to version: 2026092312000012232026/10/01 10:22:32 OK 1_commit_pending_closure.sql (1.76ms)12242026/10/01 10:22:32 OK 2_object_stats_trigger.sql (412.08µs)12252026/10/01 10:22:32 OK 3_commit_push.sql (348.38µs)12262026/10/01 10:22:32 goose: up to current file version: 312272026/10/01 10:22:32 OK 20241026095416_initial_model.sql (150.88ms)12282026/10/01 10:22:32 OK 20251210153512_drop_unused_gin_index.sql (11.78ms)12292026-10-01 10:22:32.838 UTC [32225] ERROR: relation "goose_db_version" does not exist at character 3612302026-10-01 10:22:32.838 UTC [32225] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12312026/10/01 10:22:32 OK 20251218171726_add_pins.sql (18.9ms)12322026/10/01 10:22:32 WARN Rate limiter enabled after throttle name=s3-test rate=512332026/10/01 10:22:32 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1234=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1235 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101236 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001237--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.15s)1238=== CONT TestCreatePendingClosureRejectsOversizedNAR12392026/10/01 10:22:32 INFO Received uploads request method=POST path=/api/pending_closures1240--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1241=== CONT TestCacheConfigHandlerMaxNarSize1242--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1243=== CONT TestGenerateLandingPage12442026/10/01 10:22:32 OK 20260628120000_add_object_size_and_stats.sql (33.54ms)1245--- PASS: TestGenerateLandingPage (0.01s)1246=== CONT TestService_readinessHandler12472026/10/01 10:22:32 OK 20260905000000_add_claims.sql (20.51ms)12482026/10/01 10:22:32 OK 20260920000000_drop_claims.sql (31.99ms)12492026/10/01 10:22:32 OK 20260923120000_add_pushes.sql (7.35ms)12502026/10/01 10:22:32 goose: successfully migrated database to version: 2026092312000012512026/10/01 10:22:32 OK 1_commit_pending_closure.sql (3.89ms)12522026/10/01 10:22:32 OK 2_object_stats_trigger.sql (487.29µs)12532026/10/01 10:22:32 OK 3_commit_push.sql (346.21µs)12542026/10/01 10:22:32 goose: up to current file version: 312552026/10/01 10:22:33 OK 20241026095416_initial_model.sql (116.59ms)12562026/10/01 10:22:33 OK 20251210153512_drop_unused_gin_index.sql (12.85ms)12572026/10/01 10:22:33 OK 20251218171726_add_pins.sql (8.97ms)12582026/10/01 10:22:33 OK 20260628120000_add_object_size_and_stats.sql (25.82ms)12592026/10/01 10:22:33 OK 20260905000000_add_claims.sql (46.98ms)12602026/10/01 10:22:33 OK 20260920000000_drop_claims.sql (24.66ms)1261--- PASS: TestObjectStatsTrigger (1.88s)1262=== CONT TestService_healthCheckHandler12632026/10/01 10:22:33 OK 20260923120000_add_pushes.sql (12.7ms)12642026/10/01 10:22:33 goose: successfully migrated database to version: 2026092312000012652026/10/01 10:22:33 OK 1_commit_pending_closure.sql (3.38ms)12662026/10/01 10:22:33 OK 2_object_stats_trigger.sql (832.63µs)12672026/10/01 10:22:33 OK 3_commit_push.sql (1.45ms)12682026/10/01 10:22:33 goose: up to current file version: 312692026/10/01 10:22:33 INFO Received uploads request method=POST path=/api/pending_closures12702026/10/01 10:22:33 INFO Received uploads request method=POST path=/api/pending_closures12712026/10/01 10:22:33 INFO Received cleanup request method=DELETE path=/api/pending_closures12722026-10-01 10:22:33.523 UTC [32230] ERROR: relation "goose_db_version" does not exist at character 3612732026-10-01 10:22:33.523 UTC [32230] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12742026/10/01 10:22:33 INFO Received uploads request method=POST path=/api/pending_closures1275=== NAME TestOrphanedObjectsGC1276 orphaned_objects_gc_test.go:290: GC Test Summary:1277 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1278 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1279 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1280 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1281 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1282--- PASS: TestOrphanedObjectsGC (2.49s)1283=== CONT TestGracefulShutdownDrainsInflight12842026/10/01 10:22:33 INFO Starting HTTP server address=127.0.0.1:6081912852026/10/01 10:22:33 INFO Shutdown signal received, draining in-flight requests timeout=10s1286--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.03s)1287=== CONT TestGCTaskStore_Fail1288--- PASS: TestGCTaskStore_Fail (0.00s)1289=== CONT TestGCTaskStore_PhaseUpdates1290--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1291=== CONT TestGCTaskStore_CompletedAllowsNewTask1292--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1293=== CONT TestGCTaskStore_GetReturnsLatest1294--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1295=== CONT TestParseSize1296--- PASS: TestParseSize (0.00s)1297=== CONT TestSkippedUploadsHandler12982026/10/01 10:22:33 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001299--- PASS: TestSkippedUploadsHandler (0.00s)1300=== CONT TestService_Rustfstest1301--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1302=== CONT TestClientIntegration13032026/10/01 10:22:33 OK 20241026095416_initial_model.sql (178.36ms)13042026/10/01 10:22:33 OK 20251210153512_drop_unused_gin_index.sql (15.44ms)13052026/10/01 10:22:33 OK 20251218171726_add_pins.sql (36.79ms)13062026/10/01 10:22:33 OK 20260628120000_add_object_size_and_stats.sql (30ms)13072026/10/01 10:22:33 OK 20260905000000_add_claims.sql (74.14ms)13082026/10/01 10:22:33 INFO Received uploads request method=POST path=/api/pending_closures13092026/10/01 10:22:33 OK 20260920000000_drop_claims.sql (54.26ms)13102026/10/01 10:22:34 OK 20260923120000_add_pushes.sql (18.72ms)13112026/10/01 10:22:34 goose: successfully migrated database to version: 2026092312000013122026/10/01 10:22:34 OK 1_commit_pending_closure.sql (5.44ms)13132026/10/01 10:22:34 OK 2_object_stats_trigger.sql (994.71µs)13142026/10/01 10:22:34 OK 3_commit_push.sql (2.27ms)13152026/10/01 10:22:34 goose: up to current file version: 313162026-10-01 10:22:34.072 UTC [32235] ERROR: relation "goose_db_version" does not exist at character 3613172026-10-01 10:22:34.072 UTC [32235] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13182026/10/01 10:22:34 INFO Received cleanup request method=DELETE path=/api/pending_closures13192026/10/01 10:22:34 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket31/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13202026/10/01 10:22:34 INFO Aborted multipart uploads count=0 kept=113212026/10/01 10:22:34 INFO Received cleanup request method=DELETE path=/api/pending_closures13222026/10/01 10:22:34 INFO Aborted multipart uploads count=1 kept=01323--- PASS: TestMultipartCleanup (2.31s)1324=== CONT TestLeadElectsOneAndHandsOver13252026/10/01 10:22:34 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13262026/10/01 10:22:34 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1327--- PASS: TestService_NativeMTLS (2.04s)1328=== CONT TestResolveDBConnectionString1329=== RUN TestResolveDBConnectionString/flag_wins1330=== PAUSE TestResolveDBConnectionString/flag_wins1331=== RUN TestResolveDBConnectionString/file_when_flag_empty1332=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1333=== RUN TestResolveDBConnectionString/missing_file_is_an_error1334=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1335=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1336=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1337=== RUN TestResolveDBConnectionString/nothing_configured1338=== PAUSE TestResolveDBConnectionString/nothing_configured1339=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13402026/10/01 10:22:34 OK 20241026095416_initial_model.sql (216.4ms)13412026/10/01 10:22:34 OK 20251210153512_drop_unused_gin_index.sql (11.15ms)13422026-10-01 10:22:34.383 UTC [32239] ERROR: relation "goose_db_version" does not exist at character 3613432026-10-01 10:22:34.383 UTC [32239] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13442026/10/01 10:22:34 OK 20251218171726_add_pins.sql (32.1ms)13452026/10/01 10:22:34 OK 20260628120000_add_object_size_and_stats.sql (35.2ms)13462026/10/01 10:22:34 OK 20260905000000_add_claims.sql (71.61ms)13472026/10/01 10:22:34 OK 20260920000000_drop_claims.sql (43.33ms)13482026/10/01 10:22:34 OK 20260923120000_add_pushes.sql (22.92ms)13492026/10/01 10:22:34 goose: successfully migrated database to version: 2026092312000013502026/10/01 10:22:34 OK 1_commit_pending_closure.sql (5.34ms)13512026/10/01 10:22:34 OK 2_object_stats_trigger.sql (808.42µs)13522026/10/01 10:22:34 OK 3_commit_push.sql (577.04µs)13532026/10/01 10:22:34 goose: up to current file version: 313542026/10/01 10:22:34 OK 20241026095416_initial_model.sql (169.26ms)13552026/10/01 10:22:34 OK 20251210153512_drop_unused_gin_index.sql (82.48ms)13562026/10/01 10:22:34 OK 20251218171726_add_pins.sql (52.78ms)13572026/10/01 10:22:34 OK 20260628120000_add_object_size_and_stats.sql (58.62ms)13582026/10/01 10:22:34 OK 20260905000000_add_claims.sql (63.55ms)13592026-10-01 10:22:34.904 UTC [32241] ERROR: relation "goose_db_version" does not exist at character 3613602026-10-01 10:22:34.904 UTC [32241] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13612026/10/01 10:22:34 OK 20260920000000_drop_claims.sql (43.13ms)13622026/10/01 10:22:34 OK 20260923120000_add_pushes.sql (31.74ms)13632026/10/01 10:22:34 goose: successfully migrated database to version: 2026092312000013642026/10/01 10:22:34 OK 1_commit_pending_closure.sql (5.79ms)13652026/10/01 10:22:34 OK 2_object_stats_trigger.sql (1.52ms)13662026/10/01 10:22:34 OK 3_commit_push.sql (1.5ms)13672026/10/01 10:22:34 goose: up to current file version: 31368--- PASS: TestMetricsInventory (2.52s)1369=== CONT TestClientFallsBackToClosures13702026/10/01 10:22:35 OK 20241026095416_initial_model.sql (149.83ms)13712026/10/01 10:22:35 OK 20251210153512_drop_unused_gin_index.sql (13.08ms)13722026/10/01 10:22:35 OK 20251218171726_add_pins.sql (8.85ms)13732026/10/01 10:22:35 OK 20260628120000_add_object_size_and_stats.sql (34.59ms)13742026/10/01 10:22:35 OK 20260905000000_add_claims.sql (22.37ms)13752026/10/01 10:22:35 OK 20260920000000_drop_claims.sql (37.86ms)13762026-10-01 10:22:35.242 UTC [32244] ERROR: relation "goose_db_version" does not exist at character 3613772026-10-01 10:22:35.242 UTC [32244] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13782026/10/01 10:22:35 OK 20260923120000_add_pushes.sql (6.15ms)13792026/10/01 10:22:35 goose: successfully migrated database to version: 2026092312000013802026/10/01 10:22:35 OK 1_commit_pending_closure.sql (3.29ms)13812026/10/01 10:22:35 OK 2_object_stats_trigger.sql (2.06ms)13822026/10/01 10:22:35 OK 3_commit_push.sql (2.44ms)13832026/10/01 10:22:35 goose: up to current file version: 313842026/10/01 10:22:35 OK 20241026095416_initial_model.sql (135.44ms)13852026/10/01 10:22:35 OK 20251210153512_drop_unused_gin_index.sql (7.79ms)1386=== NAME TestNARDeduplicationMetadataUploadBug1387 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-32041-4233760698/TestNARDeduplicationMetadataUploadBug842902280/001/store/zb0pgfh9bb939b0mbwggnr0b0vy7a9cm-file1.txt13882026/10/01 10:22:35 OK 20251218171726_add_pins.sql (23.61ms)13892026/10/01 10:22:35 OK 20260628120000_add_object_size_and_stats.sql (38.46ms)13902026/10/01 10:22:35 WARN readiness check failed error="closed pool"1391--- PASS: TestService_readinessHandler (2.61s)1392=== CONT TestClientPushesUseOnePush13932026/10/01 10:22:35 OK 20260905000000_add_claims.sql (19.67ms)13942026/10/01 10:22:35 OK 20260920000000_drop_claims.sql (7.72ms)13952026/10/01 10:22:35 OK 20260923120000_add_pushes.sql (8.58ms)13962026/10/01 10:22:35 goose: successfully migrated database to version: 2026092312000013972026/10/01 10:22:35 OK 1_commit_pending_closure.sql (1.47ms)13982026/10/01 10:22:35 OK 2_object_stats_trigger.sql (340.17µs)13992026/10/01 10:22:35 OK 3_commit_push.sql (211.58µs)14002026/10/01 10:22:35 goose: up to current file version: 314012026/10/01 10:22:35 INFO Received push request method=POST path=/api/pushes14022026-10-01 10:22:35.579 UTC [32253] ERROR: relation "goose_db_version" does not exist at character 3614032026-10-01 10:22:35.579 UTC [32253] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14042026/10/01 10:22:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14052026/10/01 10:22:35 INFO Uploading zb0pgfh9bb939b0mbwggnr0b0vy7a9cm-file1.txt (160B)14062026/10/01 10:22:35 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14072026/10/01 10:22:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14082026/10/01 10:22:35 WARN Failed to register uploaded object key=zb0pgfh9bb939b0mbwggnr0b0vy7a9cm.ls error="server returned 404: 404 page not found\n"14092026/10/01 10:22:35 INFO Signed narinfos id=1 count=114102026/10/01 10:22:35 INFO Uploading 1 narinfos14112026/10/01 10:22:35 INFO Received complete push request method=POST path=/api/pushes/1/complete14122026/10/01 10:22:35 WARN Failed to register uploaded object key=zb0pgfh9bb939b0mbwggnr0b0vy7a9cm.narinfo error="server returned 404: 404 page not found\n"14132026/10/01 10:22:35 INFO Upload complete. (131ms)1414=== NAME TestNARDeduplicationMetadataUploadBug1415 metadata_upload_test.go:54: Retrieved narinfo from S3:1416 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestNARDeduplicationMetadataUploadBug842902280/001/store/zb0pgfh9bb939b0mbwggnr0b0vy7a9cm-file1.txt1417 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1418 Compression: zstd1419 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1420 NarSize: 1601421 References: 1422 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1423 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1424 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1425 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14262026-10-01 10:22:35.662 UTC [32255] ERROR: relation "goose_db_version" does not exist at character 3614272026-10-01 10:22:35.662 UTC [32255] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1428 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-32041-4233760698/TestNARDeduplicationMetadataUploadBug842902280/001/store/dplf042fbdc0najh7shhjy7dq2bhq8pl-file2.txt14292026/10/01 10:22:35 OK 20241026095416_initial_model.sql (161.95ms)1430--- PASS: TestService_healthCheckHandler (2.64s)1431=== CONT TestPinProtectsFromGC14322026/10/01 10:22:35 OK 20251210153512_drop_unused_gin_index.sql (10.34ms)14332026/10/01 10:22:35 INFO Received push request method=POST path=/api/pushes14342026/10/01 10:22:35 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14352026/10/01 10:22:35 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14362026/10/01 10:22:35 OK 20251218171726_add_pins.sql (22.81ms)14372026/10/01 10:22:35 INFO Signed narinfos id=2 count=114382026/10/01 10:22:35 INFO Uploading 1 narinfos14392026/10/01 10:22:35 WARN Failed to register uploaded object key=dplf042fbdc0najh7shhjy7dq2bhq8pl.ls error="server returned 404: 404 page not found\n"14402026/10/01 10:22:35 INFO Received complete push request method=POST path=/api/pushes/2/complete14412026/10/01 10:22:35 WARN Failed to register uploaded object key=dplf042fbdc0najh7shhjy7dq2bhq8pl.narinfo error="server returned 404: 404 page not found\n"14422026/10/01 10:22:35 INFO Upload complete. (63ms)1443=== NAME TestNARDeduplicationMetadataUploadBug1444 metadata_upload_test.go:76: Retrieved narinfo from S3:1445 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestNARDeduplicationMetadataUploadBug842902280/001/store/dplf042fbdc0najh7shhjy7dq2bhq8pl-file2.txt1446 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1447 Compression: zstd1448 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1449 NarSize: 1601450 References: 1451 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1452 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1453 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1454 {"version":1,"root":{"type":"regular","size":44}}14552026/10/01 10:22:35 OK 20260628120000_add_object_size_and_stats.sql (19.95ms)14562026/10/01 10:22:35 OK 20260905000000_add_claims.sql (36.59ms)1457--- PASS: TestNARDeduplicationMetadataUploadBug (3.31s)1458=== CONT TestClientSharedPathCommittedMidPush14592026/10/01 10:22:35 OK 20241026095416_initial_model.sql (154.13ms)14602026/10/01 10:22:35 OK 20251210153512_drop_unused_gin_index.sql (13.56ms)14612026/10/01 10:22:35 OK 20260920000000_drop_claims.sql (27.15ms)14622026/10/01 10:22:35 OK 20260923120000_add_pushes.sql (12.7ms)14632026/10/01 10:22:35 goose: successfully migrated database to version: 2026092312000014642026/10/01 10:22:35 OK 20251218171726_add_pins.sql (19.4ms)14652026/10/01 10:22:35 OK 1_commit_pending_closure.sql (1.04ms)14662026/10/01 10:22:35 OK 2_object_stats_trigger.sql (235.54µs)14672026/10/01 10:22:35 OK 3_commit_push.sql (202.83µs)14682026/10/01 10:22:35 goose: up to current file version: 314692026/10/01 10:22:35 OK 20260628120000_add_object_size_and_stats.sql (35.65ms)14702026/10/01 10:22:35 OK 20260905000000_add_claims.sql (42.81ms)14712026/10/01 10:22:36 OK 20260920000000_drop_claims.sql (47.24ms)14722026/10/01 10:22:36 OK 20260923120000_add_pushes.sql (24.43ms)14732026/10/01 10:22:36 goose: successfully migrated database to version: 2026092312000014742026/10/01 10:22:36 OK 1_commit_pending_closure.sql (1.81ms)14752026/10/01 10:22:36 OK 2_object_stats_trigger.sql (434.58µs)14762026/10/01 10:22:36 OK 3_commit_push.sql (342.13µs)14772026/10/01 10:22:36 goose: up to current file version: 314782026-10-01 10:22:36.086 UTC [32265] ERROR: relation "goose_db_version" does not exist at character 3614792026-10-01 10:22:36.086 UTC [32265] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14802026-10-01 10:22:36.261 UTC [32266] ERROR: relation "goose_db_version" does not exist at character 3614812026-10-01 10:22:36.261 UTC [32266] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14822026/10/01 10:22:36 OK 20241026095416_initial_model.sql (165.22ms)14832026/10/01 10:22:36 OK 20251210153512_drop_unused_gin_index.sql (9.63ms)14842026/10/01 10:22:36 OK 20251218171726_add_pins.sql (51.39ms)14852026/10/01 10:22:36 OK 20260628120000_add_object_size_and_stats.sql (31.7ms)14862026/10/01 10:22:36 OK 20260905000000_add_claims.sql (87.06ms)1487--- PASS: TestService_Rustfstest (2.84s)1488=== CONT TestClientWithDependencies14892026/10/01 10:22:36 OK 20260920000000_drop_claims.sql (30.93ms)1490=== NAME TestClientIntegration1491 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-32041-4233760698/TestClientIntegration423502448/002/store/6rcqi8nnrf1qzhaj5dhvmn0l6knqmhs9-test-file.txt14922026/10/01 10:22:36 OK 20260923120000_add_pushes.sql (17.46ms)14932026/10/01 10:22:36 goose: successfully migrated database to version: 2026092312000014942026/10/01 10:22:36 OK 1_commit_pending_closure.sql (1.97ms)14952026/10/01 10:22:36 OK 2_object_stats_trigger.sql (412µs)14962026/10/01 10:22:36 OK 3_commit_push.sql (311.88µs)14972026/10/01 10:22:36 goose: up to current file version: 314982026/10/01 10:22:36 OK 20241026095416_initial_model.sql (242.85ms)14992026/10/01 10:22:36 OK 20251210153512_drop_unused_gin_index.sql (6.49ms)15002026/10/01 10:22:36 OK 20251218171726_add_pins.sql (27.7ms)15012026/10/01 10:22:36 OK 20260628120000_add_object_size_and_stats.sql (36.59ms)15022026/10/01 10:22:36 INFO Received push request method=POST path=/api/pushes15032026/10/01 10:22:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15042026/10/01 10:22:36 INFO Uploading 6rcqi8nnrf1qzhaj5dhvmn0l6knqmhs9-test-file.txt (152B)15052026/10/01 10:22:36 OK 20260905000000_add_claims.sql (80.84ms)15062026/10/01 10:22:36 WARN Failed to register uploaded object key=6rcqi8nnrf1qzhaj5dhvmn0l6knqmhs9.ls error="server returned 404: 404 page not found\n"15072026/10/01 10:22:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15082026/10/01 10:22:36 INFO Signed narinfos id=1 count=115092026/10/01 10:22:36 INFO Uploading 1 narinfos15102026/10/01 10:22:36 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15112026/10/01 10:22:36 INFO Received complete push request method=POST path=/api/pushes/1/complete15122026/10/01 10:22:36 WARN Failed to register uploaded object key=6rcqi8nnrf1qzhaj5dhvmn0l6knqmhs9.narinfo error="server returned 404: 404 page not found\n"15132026/10/01 10:22:36 INFO Upload complete. (176ms)15142026/10/01 10:22:36 OK 20260920000000_drop_claims.sql (52.28ms)15152026/10/01 10:22:36 OK 20260923120000_add_pushes.sql (15.42ms)15162026/10/01 10:22:36 goose: successfully migrated database to version: 2026092312000015172026/10/01 10:22:36 OK 1_commit_pending_closure.sql (1.1ms)15182026/10/01 10:22:36 OK 2_object_stats_trigger.sql (259.46µs)15192026/10/01 10:22:36 OK 3_commit_push.sql (218.5µs)15202026/10/01 10:22:36 goose: up to current file version: 315212026/10/01 10:22:36 INFO All 1 paths already cached1522 client_integration_test.go:312: Retrieved narinfo from S3:1523 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestClientIntegration423502448/002/store/6rcqi8nnrf1qzhaj5dhvmn0l6knqmhs9-test-file.txt1524 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1525 Compression: zstd1526 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11527 NarSize: 1521528 References: 1529 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11530 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1531 client_integration_test.go:313: Decompressed .ls content (64 bytes):1532 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1533 client_integration_test.go:316: Testing garbage collection...15342026/10/01 10:22:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures15352026/10/01 10:22:36 INFO Garbage collection started15362026/10/01 10:22:36 INFO lead: acquired remote=192.0.2.1:123415372026/10/01 10:22:36 INFO Aborted multipart uploads count=0 kept=015382026/10/01 10:22:36 WARN Force mode enabled - objects will be deleted immediately without grace period15392026-10-01 10:22:36.854 UTC [32278] ERROR: relation "goose_db_version" does not exist at character 3615402026-10-01 10:22:36.854 UTC [32278] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15412026/10/01 10:22:36 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=015422026/10/01 10:22:36 INFO Vacuumed table table=pending_closures15432026/10/01 10:22:36 INFO Vacuumed table table=pending_objects15442026/10/01 10:22:36 INFO Vacuumed table table=multipart_uploads15452026/10/01 10:22:36 INFO Vacuumed table table=closures15462026/10/01 10:22:37 INFO lead: released remote=192.0.2.1:123415472026/10/01 10:22:37 INFO Vacuumed table table=objects15482026/10/01 10:22:37 INFO lead: acquired remote=192.0.2.1:123415492026/10/01 10:22:37 INFO lead: released remote=192.0.2.1:12341550--- PASS: TestLeadElectsOneAndHandsOver (2.88s)1551=== CONT TestClientMultipleUploads15522026/10/01 10:22:37 OK 20241026095416_initial_model.sql (208.54ms)15532026/10/01 10:22:37 OK 20251210153512_drop_unused_gin_index.sql (6.16ms)15542026/10/01 10:22:37 OK 20251218171726_add_pins.sql (35.76ms)15552026/10/01 10:22:37 OK 20260628120000_add_object_size_and_stats.sql (34.21ms)15562026/10/01 10:22:37 OK 20260905000000_add_claims.sql (80.77ms)15572026/10/01 10:22:37 OK 20260920000000_drop_claims.sql (56.91ms)15582026/10/01 10:22:37 OK 20260923120000_add_pushes.sql (26.72ms)15592026/10/01 10:22:37 goose: successfully migrated database to version: 2026092312000015602026/10/01 10:22:37 OK 1_commit_pending_closure.sql (4.84ms)15612026/10/01 10:22:37 OK 2_object_stats_trigger.sql (1.1ms)15622026/10/01 10:22:37 OK 3_commit_push.sql (1.12ms)15632026/10/01 10:22:37 goose: up to current file version: 315642026-10-01 10:22:37.799 UTC [32285] ERROR: relation "goose_db_version" does not exist at character 3615652026-10-01 10:22:37.799 UTC [32285] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15662026/10/01 10:22:37 OK 20241026095416_initial_model.sql (112.62ms)15672026-10-01 10:22:37.964 UTC [32289] ERROR: relation "goose_db_version" does not exist at character 3615682026-10-01 10:22:37.964 UTC [32289] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15692026/10/01 10:22:37 OK 20251210153512_drop_unused_gin_index.sql (4.54ms)15702026-10-01 10:22:37.977 UTC [32290] ERROR: relation "goose_db_version" does not exist at character 3615712026-10-01 10:22:37.977 UTC [32290] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15722026/10/01 10:22:37 OK 20251218171726_add_pins.sql (8.71ms)15732026/10/01 10:22:38 OK 20260628120000_add_object_size_and_stats.sql (23.41ms)15742026/10/01 10:22:38 OK 20260905000000_add_claims.sql (15.17ms)15752026/10/01 10:22:38 OK 20260920000000_drop_claims.sql (10.04ms)15762026/10/01 10:22:38 OK 20260923120000_add_pushes.sql (8.16ms)15772026/10/01 10:22:38 goose: successfully migrated database to version: 2026092312000015782026/10/01 10:22:38 OK 1_commit_pending_closure.sql (1.15ms)15792026/10/01 10:22:38 OK 2_object_stats_trigger.sql (244.42µs)15802026/10/01 10:22:38 OK 3_commit_push.sql (173.08µs)15812026/10/01 10:22:38 goose: up to current file version: 315822026/10/01 10:22:38 OK 20241026095416_initial_model.sql (74.4ms)15832026/10/01 10:22:38 OK 20251210153512_drop_unused_gin_index.sql (6.49ms)15842026/10/01 10:22:38 OK 20251218171726_add_pins.sql (27.11ms)15852026/10/01 10:22:38 OK 20241026095416_initial_model.sql (88.1ms)15862026/10/01 10:22:38 OK 20251210153512_drop_unused_gin_index.sql (20.91ms)15872026/10/01 10:22:38 OK 20260628120000_add_object_size_and_stats.sql (33.95ms)15882026/10/01 10:22:38 OK 20251218171726_add_pins.sql (25.05ms)1589=== NAME TestOrphanedObjectsGCStressTest1590 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains15912026/10/01 10:22:38 OK 20260905000000_add_claims.sql (32.3ms)15922026/10/01 10:22:38 OK 20260628120000_add_object_size_and_stats.sql (22.86ms)15932026/10/01 10:22:38 INFO Received uploads request method=POST path=/api/pending_closures15942026/10/01 10:22:38 OK 20260920000000_drop_claims.sql (26.02ms)1595 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion15962026/10/01 10:22:38 OK 20260905000000_add_claims.sql (29.51ms)15972026/10/01 10:22:38 OK 20260923120000_add_pushes.sql (7.58ms)15982026/10/01 10:22:38 goose: successfully migrated database to version: 2026092312000015992026/10/01 10:22:38 OK 1_commit_pending_closure.sql (1.19ms)16002026/10/01 10:22:38 OK 2_object_stats_trigger.sql (249.63µs)16012026/10/01 10:22:38 OK 3_commit_push.sql (180.17µs)16022026/10/01 10:22:38 goose: up to current file version: 316032026/10/01 10:22:38 INFO Received uploads request method=POST path=/api/pending_closures16042026/10/01 10:22:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16052026/10/01 10:22:38 INFO Uploading znaz3hryaq1jcxx4wbf7y91rfhss9rwl-shared-dep (136B)16062026/10/01 10:22:38 INFO Uploading 4fgswp9zr0k9w6iwyjaj8yjwss5nwjjk-b (248B)16072026/10/01 10:22:38 OK 20260920000000_drop_claims.sql (23.94ms)16082026/10/01 10:22:38 WARN Failed to register uploaded object key=znaz3hryaq1jcxx4wbf7y91rfhss9rwl.ls error="server returned 404: 404 page not found\n"16092026/10/01 10:22:38 WARN Failed to register uploaded object key=2wy81ad0vxccb1ja0jrn3nsxhs339ch9.ls error="server returned 404: 404 page not found\n"16102026/10/01 10:22:38 WARN Failed to register uploaded object key=4fgswp9zr0k9w6iwyjaj8yjwss5nwjjk.ls error="server returned 404: 404 page not found\n"16112026/10/01 10:22:38 WARN Failed to register uploaded object key=nar/129hxfkwkvpgshbv90lwvq4mkb36a3hcnz7jnp6wrnnadjzb17xm.nar.zst error="server returned 404: 404 page not found\n"16122026/10/01 10:22:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16132026/10/01 10:22:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16142026/10/01 10:22:38 INFO Signed narinfos id=1 count=216152026/10/01 10:22:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16162026/10/01 10:22:38 INFO Signed narinfos id=2 count=216172026/10/01 10:22:38 INFO Uploading 4 narinfos16182026/10/01 10:22:38 OK 20260923120000_add_pushes.sql (9.98ms)16192026/10/01 10:22:38 goose: successfully migrated database to version: 2026092312000016202026/10/01 10:22:38 OK 1_commit_pending_closure.sql (913.38µs)16212026/10/01 10:22:38 OK 2_object_stats_trigger.sql (244.92µs)16222026/10/01 10:22:38 OK 3_commit_push.sql (177.33µs)16232026/10/01 10:22:38 goose: up to current file version: 316242026/10/01 10:22:38 WARN Failed to register uploaded object key=4fgswp9zr0k9w6iwyjaj8yjwss5nwjjk.narinfo error="server returned 404: 404 page not found\n"16252026/10/01 10:22:38 WARN Failed to register uploaded object key=2wy81ad0vxccb1ja0jrn3nsxhs339ch9.narinfo error="server returned 404: 404 page not found\n"16262026/10/01 10:22:38 WARN Failed to register uploaded object key=znaz3hryaq1jcxx4wbf7y91rfhss9rwl.narinfo error="server returned 404: 404 page not found\n"16272026/10/01 10:22:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16282026/10/01 10:22:38 WARN Failed to register uploaded object key=znaz3hryaq1jcxx4wbf7y91rfhss9rwl.narinfo error="server returned 404: 404 page not found\n"16292026/10/01 10:22:38 INFO Completed upload id=116302026/10/01 10:22:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16312026/10/01 10:22:38 INFO Completed upload id=216322026/10/01 10:22:38 INFO Upload complete. (160ms)1633=== NAME TestClientFallsBackToClosures1634 client_pushes_test.go:112: Retrieved narinfo from S3:1635 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestClientFallsBackToClosures2092257766/001/store/znaz3hryaq1jcxx4wbf7y91rfhss9rwl-shared-dep1636 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1637 Compression: zstd1638 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821639 NarSize: 1361640 References: 1641 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1642 client_pushes_test.go:112: Retrieved narinfo from S3:1643 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestClientFallsBackToClosures2092257766/001/store/2wy81ad0vxccb1ja0jrn3nsxhs339ch9-a1644 URL: nar/129hxfkwkvpgshbv90lwvq4mkb36a3hcnz7jnp6wrnnadjzb17xm.nar.zst1645 Compression: zstd1646 NarHash: sha256:129hxfkwkvpgshbv90lwvq4mkb36a3hcnz7jnp6wrnnadjzb17xm1647 NarSize: 2481648 References: /nix/var/nix/builds/nix-32041-4233760698/TestClientFallsBackToClosures2092257766/001/store/znaz3hryaq1jcxx4wbf7y91rfhss9rwl-shared-dep1649 CA: text:sha256:14w06s6hl23nmghn9zpx1h2y1rpjwbgnyppk9fb93y1ffd0jw3hy1650 client_pushes_test.go:112: Retrieved narinfo from S3:1651 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestClientFallsBackToClosures2092257766/001/store/4fgswp9zr0k9w6iwyjaj8yjwss5nwjjk-b1652 URL: nar/129hxfkwkvpgshbv90lwvq4mkb36a3hcnz7jnp6wrnnadjzb17xm.nar.zst1653 Compression: zstd1654 NarHash: sha256:129hxfkwkvpgshbv90lwvq4mkb36a3hcnz7jnp6wrnnadjzb17xm1655 NarSize: 2481656 References: /nix/var/nix/builds/nix-32041-4233760698/TestClientFallsBackToClosures2092257766/001/store/znaz3hryaq1jcxx4wbf7y91rfhss9rwl-shared-dep1657 CA: text:sha256:14w06s6hl23nmghn9zpx1h2y1rpjwbgnyppk9fb93y1ffd0jw3hy1658--- PASS: TestClientFallsBackToClosures (3.32s)1659=== CONT TestSweepSkipsRowsLockedByPush16602026-10-01 10:22:38.331 UTC [32301] ERROR: relation "goose_db_version" does not exist at character 3616612026-10-01 10:22:38.331 UTC [32301] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1662--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (4.05s)1663=== CONT TestGCTaskStore_ConflictDifferentParams1664--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1665=== CONT TestGCTaskStore_DeduplicateSameParams1666--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1667=== CONT TestGCTaskStore_StartNew1668--- PASS: TestGCTaskStore_StartNew (0.00s)1669=== CONT TestGCEndsOnShutdown16702026/10/01 10:22:38 OK 20241026095416_initial_model.sql (54ms)16712026/10/01 10:22:38 OK 20251210153512_drop_unused_gin_index.sql (4.86ms)16722026/10/01 10:22:38 OK 20251218171726_add_pins.sql (28.4ms)16732026-10-01 10:22:38.483 UTC [32311] ERROR: relation "goose_db_version" does not exist at character 3616742026-10-01 10:22:38.483 UTC [32311] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16752026/10/01 10:22:38 OK 20260628120000_add_object_size_and_stats.sql (30.89ms)16762026/10/01 10:22:38 OK 20260905000000_add_claims.sql (48.01ms)16772026/10/01 10:22:38 OK 20260920000000_drop_claims.sql (2.47ms)16782026/10/01 10:22:38 OK 20260923120000_add_pushes.sql (14.93ms)16792026/10/01 10:22:38 goose: successfully migrated database to version: 2026092312000016802026/10/01 10:22:38 OK 1_commit_pending_closure.sql (962.42µs)16812026/10/01 10:22:38 OK 2_object_stats_trigger.sql (253.38µs)16822026/10/01 10:22:38 OK 3_commit_push.sql (192.25µs)16832026/10/01 10:22:38 goose: up to current file version: 316842026/10/01 10:22:38 OK 20241026095416_initial_model.sql (73.62ms)16852026/10/01 10:22:38 OK 20251210153512_drop_unused_gin_index.sql (7.97ms)16862026/10/01 10:22:38 OK 20251218171726_add_pins.sql (13.87ms)16872026/10/01 10:22:38 INFO Received push request method=POST path=/api/pushes16882026/10/01 10:22:38 OK 20260628120000_add_object_size_and_stats.sql (8.29ms)16892026/10/01 10:22:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16902026/10/01 10:22:38 INFO Uploading vzkn7gg02mq82ysrsfal3kmj7w2l6i44-shared-dep (136B)16912026/10/01 10:22:38 INFO Uploading xbwb4hfjxmhh3s23icgy3xhzqv8adax5-a (248B)16922026/10/01 10:22:38 WARN Failed to register uploaded object key=rhp8ardnryy2mhriycl1hqw1wygy3zvc.ls error="server returned 404: 404 page not found\n"16932026/10/01 10:22:38 OK 20260905000000_add_claims.sql (27.26ms)16942026/10/01 10:22:38 WARN Failed to register uploaded object key=nar/010g7236zmk9jwi1yn48siclqs0iadz408qw6vhd7vwqca0y02ln.nar.zst error="server returned 404: 404 page not found\n"16952026/10/01 10:22:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16962026/10/01 10:22:38 WARN Failed to register uploaded object key=vzkn7gg02mq82ysrsfal3kmj7w2l6i44.ls error="server returned 404: 404 page not found\n"16972026/10/01 10:22:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16982026/10/01 10:22:38 WARN Failed to register uploaded object key=xbwb4hfjxmhh3s23icgy3xhzqv8adax5.ls error="server returned 404: 404 page not found\n"16992026/10/01 10:22:38 INFO Signed narinfos id=1 count=317002026/10/01 10:22:38 INFO Uploading 3 narinfos17012026/10/01 10:22:38 WARN Failed to register uploaded object key=xbwb4hfjxmhh3s23icgy3xhzqv8adax5.narinfo error="server returned 404: 404 page not found\n"17022026/10/01 10:22:38 OK 20260920000000_drop_claims.sql (17.18ms)17032026/10/01 10:22:38 WARN Failed to register uploaded object key=rhp8ardnryy2mhriycl1hqw1wygy3zvc.narinfo error="server returned 404: 404 page not found\n"17042026/10/01 10:22:38 INFO Received complete push request method=POST path=/api/pushes/1/complete17052026/10/01 10:22:38 WARN Failed to register uploaded object key=vzkn7gg02mq82ysrsfal3kmj7w2l6i44.narinfo error="server returned 404: 404 page not found\n"17062026/10/01 10:22:38 OK 20260923120000_add_pushes.sql (11.84ms)17072026/10/01 10:22:38 goose: successfully migrated database to version: 2026092312000017082026/10/01 10:22:38 OK 1_commit_pending_closure.sql (1.08ms)17092026/10/01 10:22:38 OK 2_object_stats_trigger.sql (252.75µs)17102026/10/01 10:22:38 OK 3_commit_push.sql (191.25µs)17112026/10/01 10:22:38 goose: up to current file version: 317122026/10/01 10:22:38 INFO Upload complete. (116ms)1713=== NAME TestClientPushesUseOnePush1714 client_pushes_test.go:97: Retrieved narinfo from S3:1715 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestClientPushesUseOnePush2668874134/001/store/vzkn7gg02mq82ysrsfal3kmj7w2l6i44-shared-dep1716 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1717 Compression: zstd1718 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821719 NarSize: 1361720 References: 1721 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1722=== NAME TestPinProtectsFromGC1723 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-32041-4233760698/TestPinProtectsFromGC1608608533/001/store/y6sr9b7rhi7q1j32d2p7rkhm5hsmsjbk-pinned-file.txt1724 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-32041-4233760698/TestPinProtectsFromGC1608608533/001/store/ajjjf6ilr63cg7v6qgyl6868kk1lrg1w-unpinned-file.txt1725=== NAME TestClientPushesUseOnePush1726 client_pushes_test.go:97: Retrieved narinfo from S3:1727 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestClientPushesUseOnePush2668874134/001/store/xbwb4hfjxmhh3s23icgy3xhzqv8adax5-a1728 URL: nar/010g7236zmk9jwi1yn48siclqs0iadz408qw6vhd7vwqca0y02ln.nar.zst1729 Compression: zstd1730 NarHash: sha256:010g7236zmk9jwi1yn48siclqs0iadz408qw6vhd7vwqca0y02ln1731 NarSize: 2481732 References: /nix/var/nix/builds/nix-32041-4233760698/TestClientPushesUseOnePush2668874134/001/store/vzkn7gg02mq82ysrsfal3kmj7w2l6i44-shared-dep1733 CA: text:sha256:177w0372vms3gb2d41c6i1jjby8pv9dbq11hhsskxjlxdhgqg2ng1734 client_pushes_test.go:97: Retrieved narinfo from S3:1735 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestClientPushesUseOnePush2668874134/001/store/rhp8ardnryy2mhriycl1hqw1wygy3zvc-b1736 URL: nar/010g7236zmk9jwi1yn48siclqs0iadz408qw6vhd7vwqca0y02ln.nar.zst1737 Compression: zstd1738 NarHash: sha256:010g7236zmk9jwi1yn48siclqs0iadz408qw6vhd7vwqca0y02ln1739 NarSize: 2481740 References: /nix/var/nix/builds/nix-32041-4233760698/TestClientPushesUseOnePush2668874134/001/store/vzkn7gg02mq82ysrsfal3kmj7w2l6i44-shared-dep1741 CA: text:sha256:177w0372vms3gb2d41c6i1jjby8pv9dbq11hhsskxjlxdhgqg2ng1742--- PASS: TestClientPushesUseOnePush (3.22s)1743=== CONT TestCommitRacingPendingCleanupKeepsObjects17442026/10/01 10:22:38 INFO Received push request method=POST path=/api/pushes17452026/10/01 10:22:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17462026/10/01 10:22:38 INFO Uploading y6sr9b7rhi7q1j32d2p7rkhm5hsmsjbk-pinned-file.txt (128B)17472026/10/01 10:22:38 WARN Failed to register uploaded object key=y6sr9b7rhi7q1j32d2p7rkhm5hsmsjbk.ls error="server returned 404: 404 page not found\n"17482026/10/01 10:22:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17492026/10/01 10:22:38 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17502026/10/01 10:22:38 INFO Signed narinfos id=1 count=117512026/10/01 10:22:38 INFO Uploading 1 narinfos17522026/10/01 10:22:38 INFO Received complete push request method=POST path=/api/pushes/1/complete17532026/10/01 10:22:38 WARN Failed to register uploaded object key=y6sr9b7rhi7q1j32d2p7rkhm5hsmsjbk.narinfo error="server returned 404: 404 page not found\n"17542026/10/01 10:22:38 INFO Upload complete. (104ms)17552026/10/01 10:22:38 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01756=== NAME TestClientIntegration1757 client_integration_test.go:323: Objects in database after GC:1758 client_integration_test.go:323: Successfully deleted all objects with GC --force1759--- PASS: TestClientIntegration (5.21s)1760=== CONT TestPushWaitsForSweepHoldingRow17612026/10/01 10:22:38 INFO Received push request method=POST path=/api/pushes17622026/10/01 10:22:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17632026/10/01 10:22:38 INFO Uploading ajjjf6ilr63cg7v6qgyl6868kk1lrg1w-unpinned-file.txt (128B)17642026/10/01 10:22:38 WARN Failed to register uploaded object key=ajjjf6ilr63cg7v6qgyl6868kk1lrg1w.ls error="server returned 404: 404 page not found\n"17652026/10/01 10:22:38 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17662026/10/01 10:22:38 INFO Signed narinfos id=2 count=117672026/10/01 10:22:38 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17682026/10/01 10:22:38 INFO Uploading 1 narinfos17692026/10/01 10:22:38 INFO Received complete push request method=POST path=/api/pushes/2/complete17702026/10/01 10:22:38 WARN Failed to register uploaded object key=ajjjf6ilr63cg7v6qgyl6868kk1lrg1w.narinfo error="server returned 404: 404 page not found\n"17712026/10/01 10:22:38 INFO Upload complete. (89ms)17722026/10/01 10:22:38 INFO Received push request method=POST path=/api/pushes17732026/10/01 10:22:38 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17742026/10/01 10:22:38 INFO Uploading djrivqaz71xkalmqxs8fg697ic0vl37b-shared-dep (136B)17752026/10/01 10:22:38 INFO Uploading x8l4px46a4kaxy714kv4mmx7h7d4pidn-top (256B)17762026/10/01 10:22:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures17772026/10/01 10:22:38 INFO Garbage collection started17782026/10/01 10:22:38 INFO Aborted multipart uploads count=0 kept=017792026/10/01 10:22:38 WARN Failed to register uploaded object key=x8l4px46a4kaxy714kv4mmx7h7d4pidn.ls error="server returned 404: 404 page not found\n"17802026/10/01 10:22:38 WARN Failed to register uploaded object key=djrivqaz71xkalmqxs8fg697ic0vl37b.ls error="server returned 404: 404 page not found\n"17812026/10/01 10:22:38 WARN Force mode enabled - objects will be deleted immediately without grace period17822026/10/01 10:22:38 WARN Failed to register uploaded object key=nar/0apip6ygp67dd2mlkqdikrmfzgji2fm50i7c0ahr30xbcgljcrwy.nar.zst error="server returned 404: 404 page not found\n"17832026/10/01 10:22:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17842026/10/01 10:22:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17852026/10/01 10:22:38 INFO Signed narinfos id=1 count=217862026/10/01 10:22:38 INFO Uploading 2 narinfos17872026/10/01 10:22:39 WARN Failed to register uploaded object key=djrivqaz71xkalmqxs8fg697ic0vl37b.narinfo error="server returned 404: 404 page not found\n"17882026/10/01 10:22:39 INFO Received complete push request method=POST path=/api/pushes/1/complete17892026/10/01 10:22:39 WARN Failed to register uploaded object key=x8l4px46a4kaxy714kv4mmx7h7d4pidn.narinfo error="server returned 404: 404 page not found\n"17902026/10/01 10:22:39 INFO Upload complete. (127ms)1791=== NAME TestClientSharedPathCommittedMidPush1792 client_integration_test.go:680: Retrieved narinfo from S3:1793 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestClientSharedPathCommittedMidPush2182280509/001/store/djrivqaz71xkalmqxs8fg697ic0vl37b-shared-dep1794 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1795 Compression: zstd1796 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821797 NarSize: 1361798 References: 1799 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1800 client_integration_test.go:680: Retrieved narinfo from S3:1801 StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestClientSharedPathCommittedMidPush2182280509/001/store/x8l4px46a4kaxy714kv4mmx7h7d4pidn-top1802 URL: nar/0apip6ygp67dd2mlkqdikrmfzgji2fm50i7c0ahr30xbcgljcrwy.nar.zst1803 Compression: zstd1804 NarHash: sha256:0apip6ygp67dd2mlkqdikrmfzgji2fm50i7c0ahr30xbcgljcrwy1805 NarSize: 2561806 References: /nix/var/nix/builds/nix-32041-4233760698/TestClientSharedPathCommittedMidPush2182280509/001/store/djrivqaz71xkalmqxs8fg697ic0vl37b-shared-dep1807 CA: text:sha256:02vpwbybah3ihf9bdhg8yyjsmbiahqy9nfrb7ah5hj4bagvp23ii18082026/10/01 10:22:39 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=018092026/10/01 10:22:39 INFO Vacuumed table table=pending_closures1810--- PASS: TestClientSharedPathCommittedMidPush (3.22s)1811=== CONT TestSweepRechecksPendingAfterLocking18122026/10/01 10:22:39 INFO Vacuumed table table=pending_objects18132026/10/01 10:22:39 INFO Vacuumed table table=multipart_uploads18142026/10/01 10:22:39 INFO Vacuumed table table=closures18152026/10/01 10:22:39 INFO Vacuumed table table=objects18162026-10-01 10:22:39.149 UTC [32354] ERROR: relation "goose_db_version" does not exist at character 3618172026-10-01 10:22:39.149 UTC [32354] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1818=== NAME TestClientMultipleUploads1819 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-32041-4233760698/TestClientMultipleUploads3726076315/001/store/949iz9087kih9284axhhf4alzmrhrl46-test-file-0.txt18202026/10/01 10:22:39 OK 20241026095416_initial_model.sql (29.53ms)1821=== NAME TestClientWithDependencies1822 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-32041-4233760698/TestClientWithDependencies1784382444/001/store/qpwm97414dg8i07fmrcr365pjw034fpp-test-script18232026/10/01 10:22:39 OK 20251210153512_drop_unused_gin_index.sql (904.79µs)18242026/10/01 10:22:39 OK 20251218171726_add_pins.sql (1ms)18252026-10-01 10:22:39.193 UTC [32357] ERROR: relation "goose_db_version" does not exist at character 3618262026-10-01 10:22:39.193 UTC [32357] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18272026/10/01 10:22:39 OK 20260628120000_add_object_size_and_stats.sql (9.5ms)18282026/10/01 10:22:39 OK 20260905000000_add_claims.sql (2.3ms)18292026/10/01 10:22:39 OK 20260920000000_drop_claims.sql (1.31ms)18302026/10/01 10:22:39 OK 20260923120000_add_pushes.sql (693.58µs)18312026/10/01 10:22:39 goose: successfully migrated database to version: 2026092312000018322026/10/01 10:22:39 OK 1_commit_pending_closure.sql (1.04ms)18332026/10/01 10:22:39 OK 2_object_stats_trigger.sql (341.67µs)18342026/10/01 10:22:39 OK 3_commit_push.sql (416.79µs)18352026/10/01 10:22:39 goose: up to current file version: 31836 client_integration_test.go:615: Found 1 dependencies (including self)18372026/10/01 10:22:39 OK 20241026095416_initial_model.sql (33.47ms)18382026/10/01 10:22:39 OK 20251210153512_drop_unused_gin_index.sql (4.04ms)1839=== NAME TestClientMultipleUploads1840 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-32041-4233760698/TestClientMultipleUploads3726076315/001/store/wsmm7h0k40xpy2ic2132rpr47fnamfw1-test-file-1.txt18412026/10/01 10:22:39 OK 20251218171726_add_pins.sql (16.73ms)18422026/10/01 10:22:39 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)18432026/10/01 10:22:39 OK 20260905000000_add_claims.sql (22.08ms)18442026/10/01 10:22:39 OK 20260920000000_drop_claims.sql (11.37ms)18452026/10/01 10:22:39 OK 20260923120000_add_pushes.sql (5.26ms)18462026/10/01 10:22:39 goose: successfully migrated database to version: 2026092312000018472026/10/01 10:22:39 OK 1_commit_pending_closure.sql (1.98ms)18482026/10/01 10:22:39 OK 2_object_stats_trigger.sql (224.79µs)18492026/10/01 10:22:39 OK 3_commit_push.sql (176µs)18502026/10/01 10:22:39 goose: up to current file version: 31851 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-32041-4233760698/TestClientMultipleUploads3726076315/001/store/h7qb9651b324qmfmdnflbxymn7g3wpvz-test-file-2.txt18522026/10/01 10:22:39 INFO Received push request method=POST path=/api/pushes18532026/10/01 10:22:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18542026/10/01 10:22:39 INFO Uploading qpwm97414dg8i07fmrcr365pjw034fpp-test-script (136B)18552026/10/01 10:22:39 WARN Failed to register uploaded object key=qpwm97414dg8i07fmrcr365pjw034fpp.ls error="server returned 404: 404 page not found\n"18562026/10/01 10:22:39 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18572026/10/01 10:22:39 WARN Failed to register uploaded object key=log/zx6m2prsa7r5bhnsikq6vqd66p6ia4fh-test-script.drv error="server returned 404: 404 page not found\n"18582026/10/01 10:22:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18592026/10/01 10:22:39 INFO Signed narinfos id=1 count=118602026/10/01 10:22:39 INFO Uploading 1 narinfos18612026/10/01 10:22:39 INFO Received push request method=POST path=/api/pushes18622026/10/01 10:22:39 INFO Received complete push request method=POST path=/api/pushes/1/complete18632026/10/01 10:22:39 WARN Failed to register uploaded object key=qpwm97414dg8i07fmrcr365pjw034fpp.narinfo error="server returned 404: 404 page not found\n"18642026/10/01 10:22:39 INFO Upload complete. (168ms)1865=== NAME TestClientWithDependencies1866 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-32041-4233760698/TestClientWithDependencies1784382444/001/store) requires matching store prefix18672026/10/01 10:22:39 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18682026/10/01 10:22:39 INFO Aborted multipart uploads count=1 kept=018692026/10/01 10:22:39 INFO Uploading 949iz9087kih9284axhhf4alzmrhrl46-test-file-0.txt (160B)18702026/10/01 10:22:39 INFO Uploading wsmm7h0k40xpy2ic2132rpr47fnamfw1-test-file-1.txt (160B)18712026/10/01 10:22:39 INFO Uploading h7qb9651b324qmfmdnflbxymn7g3wpvz-test-file-2.txt (160B)18722026/10/01 10:22:39 INFO Aborted multipart uploads count=0 kept=018732026/10/01 10:22:39 WARN Force mode enabled - objects will be deleted immediately without grace period18742026/10/01 10:22:39 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=018752026/10/01 10:22:39 INFO Vacuumed table table=pending_closures18762026/10/01 10:22:39 INFO Vacuumed table table=pending_objects18772026/10/01 10:22:39 INFO Vacuumed table table=multipart_uploads18782026/10/01 10:22:39 INFO Vacuumed table table=closures18792026/10/01 10:22:39 WARN Failed to register uploaded object key=wsmm7h0k40xpy2ic2132rpr47fnamfw1.ls error="server returned 404: 404 page not found\n"18802026/10/01 10:22:39 INFO Received cleanup request method=DELETE path=/api/pending_closures18812026/10/01 10:22:39 INFO Vacuumed table table=objects18822026/10/01 10:22:39 WARN Failed to register uploaded object key=h7qb9651b324qmfmdnflbxymn7g3wpvz.ls error="server returned 404: 404 page not found\n"18832026/10/01 10:22:39 WARN Failed to register uploaded object key=949iz9087kih9284axhhf4alzmrhrl46.ls error="server returned 404: 404 page not found\n"18842026/10/01 10:22:39 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18852026/10/01 10:22:39 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18862026/10/01 10:22:39 INFO Aborted multipart uploads count=1 kept=018872026/10/01 10:22:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18882026/10/01 10:22:39 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18892026/10/01 10:22:39 INFO Signed narinfos id=1 count=318902026/10/01 10:22:39 INFO Uploading 3 narinfos1891--- PASS: TestPendingCleanupUsesOneCutoff (8.01s)1892=== CONT TestGetExistingObjectsLocksRows18932026/10/01 10:22:39 INFO Aborted multipart uploads count=0 kept=018942026/10/01 10:22:39 WARN Force mode enabled - objects will be deleted immediately without grace period18952026/10/01 10:22:39 WARN Failed to register uploaded object key=h7qb9651b324qmfmdnflbxymn7g3wpvz.narinfo error="server returned 404: 404 page not found\n"18962026/10/01 10:22:39 WARN Failed to register uploaded object key=949iz9087kih9284axhhf4alzmrhrl46.narinfo error="server returned 404: 404 page not found\n"18972026/10/01 10:22:39 INFO Received complete push request method=POST path=/api/pushes/1/complete18982026/10/01 10:22:39 WARN Failed to register uploaded object key=wsmm7h0k40xpy2ic2132rpr47fnamfw1.narinfo error="server returned 404: 404 page not found\n"1899--- PASS: TestClientWithDependencies (2.98s)1900=== CONT TestRegisterCompletedObjectNeedsPendingRow19012026/10/01 10:22:39 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=019022026/10/01 10:22:39 INFO Vacuumed table table=pending_closures19032026/10/01 10:22:39 INFO Vacuumed table table=pending_objects19042026/10/01 10:22:39 INFO Vacuumed table table=multipart_uploads19052026/10/01 10:22:39 INFO Vacuumed table table=closures19062026/10/01 10:22:39 INFO Upload complete. (160ms)1907=== NAME TestClientMultipleUploads1908 client_integration_test.go:369: Uploaded 3 paths in 201.587917ms19092026/10/01 10:22:39 INFO Vacuumed table table=objects1910--- PASS: TestSweepSkipsRowsLockedByPush (1.20s)1911=== CONT TestService_ReadScope_PublicByDefault1912=== NAME TestOrphanedObjectsGCStressTest1913 orphaned_objects_gc_test.go:509: Stress test completed successfully:1914 orphaned_objects_gc_test.go:510: - Active objects preserved: 201915 orphaned_objects_gc_test.go:511: - Objects deleted: 2101916 orphaned_objects_gc_test.go:512: - Total GC'd: 2101917--- PASS: TestOrphanedObjectsGCStressTest (8.75s)1918=== CONT TestClientErrorHandling1919=== RUN TestClientErrorHandling/InvalidStorePath1920=== PAUSE TestClientErrorHandling/InvalidStorePath1921=== RUN TestClientErrorHandling/InvalidAuthToken1922=== PAUSE TestClientErrorHandling/InvalidAuthToken1923=== RUN TestClientErrorHandling/ServerNotAvailable1924=== PAUSE TestClientErrorHandling/ServerNotAvailable1925=== CONT TestClientCADerivations1926--- PASS: TestClientMultipleUploads (2.55s)1927=== CONT TestCacheStatsHandler1928--- PASS: TestGCEndsOnShutdown (1.34s)1929=== CONT TestCacheConfigHandler1930=== RUN TestCacheConfigHandler/full_config,_no_issuer1931=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1932=== RUN TestCacheConfigHandler/no_cache_url_configured1933=== PAUSE TestCacheConfigHandler/no_cache_url_configured1934=== RUN TestCacheConfigHandler/no_signing_keys1935=== PAUSE TestCacheConfigHandler/no_signing_keys1936=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1937=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1938=== CONT TestService_ReadAuthMiddleware19392026-10-01 10:22:39.760 UTC [32384] ERROR: relation "goose_db_version" does not exist at character 3619402026-10-01 10:22:39.760 UTC [32384] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19412026/10/01 10:22:39 OK 20241026095416_initial_model.sql (10.56ms)19422026/10/01 10:22:39 OK 20251210153512_drop_unused_gin_index.sql (511.33µs)19432026/10/01 10:22:39 OK 20251218171726_add_pins.sql (847.38µs)19442026-10-01 10:22:39.778 UTC [32385] ERROR: relation "goose_db_version" does not exist at character 3619452026-10-01 10:22:39.778 UTC [32385] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19462026/10/01 10:22:39 OK 20260628120000_add_object_size_and_stats.sql (9.05ms)19472026/10/01 10:22:39 OK 20260905000000_add_claims.sql (2.61ms)19482026/10/01 10:22:39 OK 20260920000000_drop_claims.sql (1.59ms)19492026/10/01 10:22:39 OK 20260923120000_add_pushes.sql (691.04µs)19502026/10/01 10:22:39 goose: successfully migrated database to version: 2026092312000019512026/10/01 10:22:39 OK 1_commit_pending_closure.sql (2.61ms)19522026/10/01 10:22:39 OK 2_object_stats_trigger.sql (449.29µs)19532026/10/01 10:22:39 OK 3_commit_push.sql (190.67µs)19542026/10/01 10:22:39 goose: up to current file version: 319552026/10/01 10:22:39 OK 20241026095416_initial_model.sql (8.76ms)19562026/10/01 10:22:39 OK 20251210153512_drop_unused_gin_index.sql (16.63ms)19572026/10/01 10:22:39 OK 20251218171726_add_pins.sql (12.8ms)19582026/10/01 10:22:39 OK 20260628120000_add_object_size_and_stats.sql (21.68ms)19592026/10/01 10:22:39 OK 20260905000000_add_claims.sql (12.54ms)19602026/10/01 10:22:39 OK 20260920000000_drop_claims.sql (13.25ms)19612026/10/01 10:22:39 OK 20260923120000_add_pushes.sql (1.74ms)19622026/10/01 10:22:39 goose: successfully migrated database to version: 2026092312000019632026/10/01 10:22:39 OK 1_commit_pending_closure.sql (1.26ms)19642026/10/01 10:22:39 OK 2_object_stats_trigger.sql (254µs)19652026/10/01 10:22:39 OK 3_commit_push.sql (256.92µs)19662026/10/01 10:22:39 goose: up to current file version: 319672026-10-01 10:22:40.041 UTC [32386] ERROR: relation "goose_db_version" does not exist at character 3619682026-10-01 10:22:40.041 UTC [32386] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19692026/10/01 10:22:40 INFO Aborted multipart uploads count=0 kept=019702026/10/01 10:22:40 WARN Force mode enabled - objects will be deleted immediately without grace period19712026/10/01 10:22:40 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=019722026/10/01 10:22:40 INFO Vacuumed table table=pending_closures19732026/10/01 10:22:40 INFO Vacuumed table table=pending_objects19742026/10/01 10:22:40 INFO Vacuumed table table=multipart_uploads19752026/10/01 10:22:40 INFO Vacuumed table table=closures19762026/10/01 10:22:40 INFO Vacuumed table table=objects19772026/10/01 10:22:40 OK 20241026095416_initial_model.sql (123.41ms)19782026/10/01 10:22:40 INFO Received uploads request method=POST path=/api/pending_closures1979--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.49s)1980=== CONT TestService_RequireScope_OIDC19812026/10/01 10:22:40 OK 20251210153512_drop_unused_gin_index.sql (9.61ms)19822026/10/01 10:22:40 OK 20251218171726_add_pins.sql (17.72ms)19832026/10/01 10:22:40 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)19842026/10/01 10:22:40 OK 20260905000000_add_claims.sql (3.39ms)19852026/10/01 10:22:40 OK 20260920000000_drop_claims.sql (1.16ms)19862026/10/01 10:22:40 OK 20260923120000_add_pushes.sql (1.51ms)19872026/10/01 10:22:40 goose: successfully migrated database to version: 2026092312000019882026/10/01 10:22:40 OK 1_commit_pending_closure.sql (1.75ms)19892026/10/01 10:22:40 OK 2_object_stats_trigger.sql (301.04µs)19902026/10/01 10:22:40 OK 3_commit_push.sql (255.38µs)19912026/10/01 10:22:40 goose: up to current file version: 319922026/10/01 10:22:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60968/oidc19932026/10/01 10:22:40 INFO Aborted multipart uploads count=0 kept=019942026/10/01 10:22:40 WARN Force mode enabled - objects will be deleted immediately without grace period19952026/10/01 10:22:40 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=019962026/10/01 10:22:40 INFO Vacuumed table table=pending_closures19972026-10-01 10:22:40.494 UTC [32395] ERROR: relation "goose_db_version" does not exist at character 3619982026-10-01 10:22:40.494 UTC [32395] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19992026/10/01 10:22:40 INFO Vacuumed table table=pending_objects20002026/10/01 10:22:40 INFO Vacuumed table table=multipart_uploads20012026/10/01 10:22:40 INFO Vacuumed table table=closures20022026-10-01 10:22:40.503 UTC [32396] ERROR: relation "goose_db_version" does not exist at character 3620032026-10-01 10:22:40.503 UTC [32396] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20042026/10/01 10:22:40 INFO Vacuumed table table=objects20052026-10-01 10:22:40.504 UTC [32397] ERROR: relation "goose_db_version" does not exist at character 3620062026-10-01 10:22:40.504 UTC [32397] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2007--- PASS: TestSweepRechecksPendingAfterLocking (1.41s)2008=== CONT TestService_AuthMiddleware_OIDC20092026-10-01 10:22:40.506 UTC [32398] ERROR: relation "goose_db_version" does not exist at character 3620102026-10-01 10:22:40.506 UTC [32398] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20112026-10-01 10:22:40.508 UTC [32399] ERROR: relation "goose_db_version" does not exist at character 3620122026-10-01 10:22:40.508 UTC [32399] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20132026-10-01 10:22:40.509 UTC [32400] ERROR: relation "goose_db_version" does not exist at character 3620142026-10-01 10:22:40.509 UTC [32400] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20152026/10/01 10:22:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60970/oidc20162026/10/01 10:22:40 OK 20241026095416_initial_model.sql (22.59ms)20172026/10/01 10:22:40 OK 20251210153512_drop_unused_gin_index.sql (521.54µs)20182026/10/01 10:22:40 OK 20241026095416_initial_model.sql (10.28ms)20192026/10/01 10:22:40 OK 20251218171726_add_pins.sql (877.58µs)20202026/10/01 10:22:40 OK 20251210153512_drop_unused_gin_index.sql (334.63µs)20212026/10/01 10:22:40 OK 20251218171726_add_pins.sql (856.38µs)20222026/10/01 10:22:40 OK 20241026095416_initial_model.sql (4.59ms)20232026/10/01 10:22:40 OK 20251210153512_drop_unused_gin_index.sql (338.79µs)20242026/10/01 10:22:40 OK 20260628120000_add_object_size_and_stats.sql (951.21µs)20252026/10/01 10:22:40 OK 20260628120000_add_object_size_and_stats.sql (2.48ms)20262026/10/01 10:22:40 OK 20251218171726_add_pins.sql (1.44ms)20272026/10/01 10:22:40 OK 20241026095416_initial_model.sql (14.51ms)20282026/10/01 10:22:40 OK 20251210153512_drop_unused_gin_index.sql (387.79µs)20292026/10/01 10:22:40 OK 20260905000000_add_claims.sql (1.5ms)20302026/10/01 10:22:40 OK 20260628120000_add_object_size_and_stats.sql (1.17ms)20312026/10/01 10:22:40 OK 20260920000000_drop_claims.sql (669.96µs)20322026/10/01 10:22:40 OK 20260905000000_add_claims.sql (981.33µs)20332026/10/01 10:22:40 OK 20260923120000_add_pushes.sql (405.54µs)20342026/10/01 10:22:40 goose: successfully migrated database to version: 2026092312000020352026/10/01 10:22:40 OK 20260920000000_drop_claims.sql (614.63µs)20362026/10/01 10:22:40 OK 1_commit_pending_closure.sql (889.04µs)20372026/10/01 10:22:40 OK 20260923120000_add_pushes.sql (369.08µs)20382026/10/01 10:22:40 goose: successfully migrated database to version: 2026092312000020392026/10/01 10:22:40 OK 2_object_stats_trigger.sql (212.29µs)20402026/10/01 10:22:40 OK 3_commit_push.sql (182.17µs)20412026/10/01 10:22:40 goose: up to current file version: 320422026/10/01 10:22:40 OK 1_commit_pending_closure.sql (800.5µs)20432026/10/01 10:22:40 OK 2_object_stats_trigger.sql (204.96µs)20442026/10/01 10:22:40 OK 3_commit_push.sql (148.5µs)20452026/10/01 10:22:40 goose: up to current file version: 320462026/10/01 10:22:40 OK 20260905000000_add_claims.sql (35.23ms)20472026/10/01 10:22:40 OK 20251218171726_add_pins.sql (33.58ms)20482026/10/01 10:22:40 OK 20260920000000_drop_claims.sql (687.75µs)20492026/10/01 10:22:40 OK 20260923120000_add_pushes.sql (7.82ms)20502026/10/01 10:22:40 goose: successfully migrated database to version: 2026092312000020512026/10/01 10:22:40 OK 1_commit_pending_closure.sql (816.63µs)20522026/10/01 10:22:40 OK 2_object_stats_trigger.sql (194.79µs)20532026/10/01 10:22:40 OK 3_commit_push.sql (150.21µs)20542026/10/01 10:22:40 goose: up to current file version: 320552026/10/01 10:22:40 OK 20260628120000_add_object_size_and_stats.sql (14.87ms)20562026/10/01 10:22:40 OK 20241026095416_initial_model.sql (56.26ms)20572026/10/01 10:22:40 OK 20251210153512_drop_unused_gin_index.sql (6.78ms)20582026/10/01 10:22:40 OK 20260905000000_add_claims.sql (20.23ms)20592026/10/01 10:22:40 OK 20251218171726_add_pins.sql (13.04ms)20602026/10/01 10:22:40 OK 20241026095416_initial_model.sql (71.5ms)20612026/10/01 10:22:40 OK 20260920000000_drop_claims.sql (1.56ms)20622026/10/01 10:22:40 OK 20251210153512_drop_unused_gin_index.sql (5.75ms)20632026/10/01 10:22:40 OK 20260923120000_add_pushes.sql (5.97ms)20642026/10/01 10:22:40 goose: successfully migrated database to version: 2026092312000020652026/10/01 10:22:40 OK 20260628120000_add_object_size_and_stats.sql (7.51ms)20662026/10/01 10:22:40 OK 1_commit_pending_closure.sql (924.46µs)20672026/10/01 10:22:40 OK 2_object_stats_trigger.sql (226.5µs)20682026/10/01 10:22:40 OK 3_commit_push.sql (184.25µs)20692026/10/01 10:22:40 goose: up to current file version: 320702026/10/01 10:22:40 OK 20251218171726_add_pins.sql (5.76ms)20712026/10/01 10:22:40 OK 20260628120000_add_object_size_and_stats.sql (9.3ms)20722026/10/01 10:22:40 OK 20260905000000_add_claims.sql (14.75ms)20732026/10/01 10:22:40 OK 20260920000000_drop_claims.sql (1.29ms)20742026/10/01 10:22:40 OK 20260905000000_add_claims.sql (6.04ms)20752026/10/01 10:22:40 OK 20260923120000_add_pushes.sql (9.33ms)20762026/10/01 10:22:40 goose: successfully migrated database to version: 2026092312000020772026/10/01 10:22:40 OK 1_commit_pending_closure.sql (1.13ms)20782026/10/01 10:22:40 OK 2_object_stats_trigger.sql (215.25µs)20792026/10/01 10:22:40 OK 3_commit_push.sql (179.5µs)20802026/10/01 10:22:40 goose: up to current file version: 320812026/10/01 10:22:40 OK 20260920000000_drop_claims.sql (11.42ms)20822026/10/01 10:22:40 OK 20260923120000_add_pushes.sql (5.02ms)20832026/10/01 10:22:40 goose: successfully migrated database to version: 2026092312000020842026/10/01 10:22:40 OK 1_commit_pending_closure.sql (1.05ms)20852026/10/01 10:22:40 OK 2_object_stats_trigger.sql (221.75µs)20862026/10/01 10:22:40 OK 3_commit_push.sql (197.75µs)20872026/10/01 10:22:40 goose: up to current file version: 32088--- PASS: TestPushWaitsForSweepHoldingRow (1.80s)2089=== CONT TestTombstonedObjectOfferedWithoutWaiting2090--- PASS: TestGetExistingObjectsLocksRows (1.25s)2091=== CONT TestService_AuthMiddleware_MTLSBoundSubjects2092--- PASS: TestService_ReadScope_PublicByDefault (1.31s)2093=== CONT TestService_AuthMiddleware_MTLSProxyHeader20942026/10/01 10:22:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020952026/10/01 10:22:40 INFO Received create pin request method=POST path=/api/pins/myapp20962026/10/01 10:22:41 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-32041-4233760698/TestPinProtectsFromGC1608608533/001/store/y6sr9b7rhi7q1j32d2p7rkhm5hsmsjbk-pinned-file.txt narinfo_key=y6sr9b7rhi7q1j32d2p7rkhm5hsmsjbk.narinfo20972026/10/01 10:22:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures20982026/10/01 10:22:41 INFO Garbage collection started20992026/10/01 10:22:41 INFO Aborted multipart uploads count=0 kept=02100--- PASS: TestCacheStatsHandler (1.42s)2101=== CONT TestPush_SignsNarinfosOfItsPendingObjects21022026/10/01 10:22:41 WARN Force mode enabled - objects will be deleted immediately without grace period21032026/10/01 10:22:41 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=021042026/10/01 10:22:41 INFO Vacuumed table table=pending_closures21052026/10/01 10:22:41 INFO Vacuumed table table=pending_objects21062026/10/01 10:22:41 INFO Vacuumed table table=multipart_uploads21072026/10/01 10:22:41 INFO Vacuumed table table=closures21082026/10/01 10:22:41 INFO Vacuumed table table=objects2109--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.67s)2110=== CONT TestCompleteMultipartUpload_ErrorButObjectExists21112026-10-01 10:22:41.299 UTC [32414] ERROR: relation "goose_db_version" does not exist at character 3621122026-10-01 10:22:41.299 UTC [32414] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2113--- PASS: TestService_ReadAuthMiddleware (1.68s)2114=== CONT TestRedundantMultipartUpload21152026/10/01 10:22:41 OK 20241026095416_initial_model.sql (124.62ms)21162026/10/01 10:22:41 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)21172026/10/01 10:22:41 OK 20251218171726_add_pins.sql (17.49ms)21182026/10/01 10:22:41 OK 20260628120000_add_object_size_and_stats.sql (20.29ms)21192026-10-01 10:22:41.493 UTC [32417] ERROR: relation "goose_db_version" does not exist at character 3621202026-10-01 10:22:41.493 UTC [32417] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21212026/10/01 10:22:41 OK 20260905000000_add_claims.sql (38.21ms)21222026/10/01 10:22:41 OK 20260920000000_drop_claims.sql (13.38ms)21232026/10/01 10:22:41 OK 20260923120000_add_pushes.sql (13.37ms)21242026/10/01 10:22:41 goose: successfully migrated database to version: 2026092312000021252026/10/01 10:22:41 OK 1_commit_pending_closure.sql (2.81ms)21262026/10/01 10:22:41 OK 2_object_stats_trigger.sql (537.67µs)21272026/10/01 10:22:41 OK 3_commit_push.sql (388.58µs)21282026/10/01 10:22:41 goose: up to current file version: 321292026/10/01 10:22:41 OK 20241026095416_initial_model.sql (102.95ms)21302026/10/01 10:22:41 OK 20251210153512_drop_unused_gin_index.sql (25.22ms)21312026/10/01 10:22:41 OK 20251218171726_add_pins.sql (34.7ms)21322026/10/01 10:22:41 OK 20260628120000_add_object_size_and_stats.sql (41.4ms)21332026/10/01 10:22:41 OK 20260905000000_add_claims.sql (20.96ms)21342026/10/01 10:22:41 OK 20260920000000_drop_claims.sql (16.1ms)21352026/10/01 10:22:41 OK 20260923120000_add_pushes.sql (20.62ms)21362026/10/01 10:22:41 goose: successfully migrated database to version: 2026092312000021372026/10/01 10:22:41 OK 1_commit_pending_closure.sql (1.82ms)21382026/10/01 10:22:41 OK 2_object_stats_trigger.sql (296.33µs)21392026/10/01 10:22:41 OK 3_commit_push.sql (222.42µs)21402026/10/01 10:22:41 goose: up to current file version: 32141=== RUN TestService_RequireScope_OIDC/builder_may_write2142=== PAUSE TestService_RequireScope_OIDC/builder_may_write2143=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2144=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2145=== RUN TestService_RequireScope_OIDC/ops_may_admin2146=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2147=== RUN TestService_RequireScope_OIDC/ops_may_not_write2148=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2149=== RUN TestService_RequireScope_OIDC/reader_may_not_write2150=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2151=== RUN TestService_RequireScope_OIDC/static_token_may_admin2152=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2153=== RUN TestService_RequireScope_OIDC/static_token_may_write2154=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2155=== RUN TestService_RequireScope_OIDC/reader_may_read2156=== PAUSE TestService_RequireScope_OIDC/reader_may_read2157=== RUN TestService_RequireScope_OIDC/writer_implies_read2158=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2159=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2160=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2161=== CONT TestFailedS3DeleteKeepsTombstone21622026-10-01 10:22:41.902 UTC [32420] ERROR: relation "goose_db_version" does not exist at character 3621632026-10-01 10:22:41.902 UTC [32420] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21642026-10-01 10:22:41.916 UTC [32421] ERROR: relation "goose_db_version" does not exist at character 3621652026-10-01 10:22:41.916 UTC [32421] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21662026/10/01 10:22:41 OK 20241026095416_initial_model.sql (58.66ms)21672026/10/01 10:22:41 OK 20241026095416_initial_model.sql (63.58ms)21682026/10/01 10:22:41 OK 20251210153512_drop_unused_gin_index.sql (7.15ms)21692026/10/01 10:22:41 OK 20251210153512_drop_unused_gin_index.sql (7.39ms)21702026-10-01 10:22:42.005 UTC [32427] ERROR: relation "goose_db_version" does not exist at character 3621712026-10-01 10:22:42.005 UTC [32427] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21722026/10/01 10:22:42 OK 20251218171726_add_pins.sql (9.78ms)21732026/10/01 10:22:42 OK 20251218171726_add_pins.sql (18.55ms)21742026/10/01 10:22:42 OK 20260628120000_add_object_size_and_stats.sql (27.89ms)21752026/10/01 10:22:42 OK 20260628120000_add_object_size_and_stats.sql (19.65ms)21762026/10/01 10:22:42 OK 20260905000000_add_claims.sql (27.88ms)21772026/10/01 10:22:42 OK 20260905000000_add_claims.sql (27.83ms)2178=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2179=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2180=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2181=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2182=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2183=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2184=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2185=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2186=== CONT TestForceGCDuringPushOffersSweptObject2187=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows2188=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows2189=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check2190=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check2191=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection21922026/10/01 10:22:42 OK 20260920000000_drop_claims.sql (10.29ms)21932026/10/01 10:22:42 OK 20260920000000_drop_claims.sql (22.73ms)21942026/10/01 10:22:42 OK 20260923120000_add_pushes.sql (13.43ms)21952026/10/01 10:22:42 goose: successfully migrated database to version: 2026092312000021962026/10/01 10:22:42 OK 1_commit_pending_closure.sql (831µs)21972026/10/01 10:22:42 OK 2_object_stats_trigger.sql (507.04µs)21982026/10/01 10:22:42 OK 3_commit_push.sql (351.88µs)21992026/10/01 10:22:42 goose: up to current file version: 322002026/10/01 10:22:42 OK 20260923120000_add_pushes.sql (9.37ms)22012026/10/01 10:22:42 goose: successfully migrated database to version: 2026092312000022022026/10/01 10:22:42 OK 1_commit_pending_closure.sql (805µs)22032026/10/01 10:22:42 OK 2_object_stats_trigger.sql (272.54µs)22042026/10/01 10:22:42 OK 3_commit_push.sql (451.33µs)22052026/10/01 10:22:42 goose: up to current file version: 32206=== NAME TestClientCADerivations2207 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-32041-4233760698/TestClientCADerivations545807136/001/store/kwb669idpxlwa8nsy6m4nmwjxgva5w95-ca-test22082026/10/01 10:22:42 OK 20241026095416_initial_model.sql (88.34ms)22092026/10/01 10:22:42 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)22102026/10/01 10:22:42 OK 20251218171726_add_pins.sql (8.36ms)22112026/10/01 10:22:42 OK 20260628120000_add_object_size_and_stats.sql (14.75ms)22122026-10-01 10:22:42.155 UTC [32431] ERROR: relation "goose_db_version" does not exist at character 3622132026-10-01 10:22:42.155 UTC [32431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2214 client_ca_test.go:139: Found 1 dependencies (including self)22152026/10/01 10:22:42 OK 20260905000000_add_claims.sql (21.32ms)22162026/10/01 10:22:42 OK 20260920000000_drop_claims.sql (8.03ms)22172026/10/01 10:22:42 OK 20260923120000_add_pushes.sql (7.75ms)22182026/10/01 10:22:42 goose: successfully migrated database to version: 2026092312000022192026/10/01 10:22:42 OK 1_commit_pending_closure.sql (943.92µs)22202026/10/01 10:22:42 OK 2_object_stats_trigger.sql (232.33µs)22212026/10/01 10:22:42 OK 3_commit_push.sql (156.21µs)22222026/10/01 10:22:42 goose: up to current file version: 322232026/10/01 10:22:42 OK 20241026095416_initial_model.sql (56.83ms)22242026-10-01 10:22:42.233 UTC [32436] ERROR: relation "goose_db_version" does not exist at character 3622252026-10-01 10:22:42.233 UTC [32436] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22262026/10/01 10:22:42 OK 20251210153512_drop_unused_gin_index.sql (5.4ms)22272026/10/01 10:22:42 OK 20251218171726_add_pins.sql (12.1ms)22282026/10/01 10:22:42 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"22292026/10/01 10:22:42 WARN mTLS auth: bound subjects configured but subject DN unavailable22302026/10/01 10:22:42 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2231--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.54s)2232=== CONT TestService_cleanupPendingClosuresHandler22332026/10/01 10:22:42 OK 20260628120000_add_object_size_and_stats.sql (21.82ms)22342026/10/01 10:22:42 INFO Received push request method=POST path=/api/pushes22352026/10/01 10:22:42 OK 20260905000000_add_claims.sql (56.71ms)22362026/10/01 10:22:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22372026/10/01 10:22:42 INFO Uploading kwb669idpxlwa8nsy6m4nmwjxgva5w95-ca-test (144B)22382026/10/01 10:22:42 OK 20260920000000_drop_claims.sql (1.32ms)22392026/10/01 10:22:42 OK 20260923120000_add_pushes.sql (9.51ms)22402026/10/01 10:22:42 goose: successfully migrated database to version: 2026092312000022412026/10/01 10:22:42 WARN Failed to register uploaded object key=kwb669idpxlwa8nsy6m4nmwjxgva5w95.ls error="server returned 404: 404 page not found\n"22422026/10/01 10:22:42 WARN Failed to register uploaded object key=log/60vmvqd84dbwmq3z515lr6hcy1qd613k-ca-test.drv error="server returned 404: 404 page not found\n"22432026/10/01 10:22:42 OK 1_commit_pending_closure.sql (1.31ms)22442026/10/01 10:22:42 OK 2_object_stats_trigger.sql (233.04µs)22452026/10/01 10:22:42 OK 3_commit_push.sql (196.75µs)22462026/10/01 10:22:42 goose: up to current file version: 322472026/10/01 10:22:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22482026/10/01 10:22:42 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"22492026/10/01 10:22:42 INFO Signed narinfos id=1 count=122502026/10/01 10:22:42 INFO Uploading 1 narinfos22512026/10/01 10:22:42 INFO Received complete push request method=POST path=/api/pushes/1/complete22522026/10/01 10:22:42 WARN Failed to register uploaded object key=kwb669idpxlwa8nsy6m4nmwjxgva5w95.narinfo error="server returned 404: 404 page not found\n"22532026/10/01 10:22:42 OK 20241026095416_initial_model.sql (102.59ms)22542026/10/01 10:22:42 INFO Upload complete. (182ms)22552026/10/01 10:22:42 OK 20251210153512_drop_unused_gin_index.sql (8.08ms)2256=== NAME TestClientCADerivations2257 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-32041-4233760698/TestClientCADerivations545807136/001/store/kwb669idpxlwa8nsy6m4nmwjxgva5w95-ca-test2258 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2259 Compression: zstd2260 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2261 NarSize: 1442262 References: 2263 Deriver: /nix/var/nix/builds/nix-32041-4233760698/TestClientCADerivations545807136/001/store/60vmvqd84dbwmq3z515lr6hcy1qd613k-ca-test.drv2264 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2265 client_ca_test.go:185: Checking for realisation files in S3...2266 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2267 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache22682026/10/01 10:22:42 OK 20251218171726_add_pins.sql (14.89ms)22692026/10/01 10:22:42 OK 20260628120000_add_object_size_and_stats.sql (37.54ms)22702026/10/01 10:22:42 OK 20260905000000_add_claims.sql (23.04ms)2271 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket57?endpoint=http://localhost:60688®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-32041-4233760698/TestClientCADerivations545807136/001/store'2272 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 122732026/10/01 10:22:42 OK 20260920000000_drop_claims.sql (20.73ms)22742026/10/01 10:22:42 OK 20260923120000_add_pushes.sql (7.58ms)22752026/10/01 10:22:42 goose: successfully migrated database to version: 2026092312000022762026/10/01 10:22:42 OK 1_commit_pending_closure.sql (1.18ms)22772026/10/01 10:22:42 OK 2_object_stats_trigger.sql (235.17µs)22782026/10/01 10:22:42 OK 3_commit_push.sql (180.17µs)22792026/10/01 10:22:42 goose: up to current file version: 322802026/10/01 10:22:42 INFO Received uploads request method=POST path=/api/pending_closures2281--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.82s)2282=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT2283--- PASS: TestClientCADerivations (2.97s)2284=== CONT TestGCSweepDeliversEachKeyOnce22852026-10-01 10:22:42.545 UTC [32446] ERROR: relation "goose_db_version" does not exist at character 3622862026-10-01 10:22:42.545 UTC [32446] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22872026/10/01 10:22:42 OK 20241026095416_initial_model.sql (85.74ms)22882026/10/01 10:22:42 OK 20251210153512_drop_unused_gin_index.sql (14.92ms)22892026/10/01 10:22:42 OK 20251218171726_add_pins.sql (23.4ms)2290--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.87s)2291=== CONT TestCompleteMultipartUnregistered22922026/10/01 10:22:42 OK 20260628120000_add_object_size_and_stats.sql (25.17ms)22932026/10/01 10:22:42 OK 20260905000000_add_claims.sql (51.36ms)22942026/10/01 10:22:42 OK 20260920000000_drop_claims.sql (28.15ms)22952026/10/01 10:22:42 OK 20260923120000_add_pushes.sql (10.14ms)22962026/10/01 10:22:42 goose: successfully migrated database to version: 2026092312000022972026-10-01 10:22:42.818 UTC [32451] ERROR: relation "goose_db_version" does not exist at character 3622982026-10-01 10:22:42.818 UTC [32451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22992026/10/01 10:22:42 OK 1_commit_pending_closure.sql (3.32ms)23002026/10/01 10:22:42 OK 2_object_stats_trigger.sql (586.54µs)23012026/10/01 10:22:42 OK 3_commit_push.sql (371.96µs)23022026/10/01 10:22:42 goose: up to current file version: 323032026/10/01 10:22:42 OK 20241026095416_initial_model.sql (82.38ms)23042026/10/01 10:22:42 INFO Received push request method=POST path=/api/pushes23052026/10/01 10:22:42 OK 20251210153512_drop_unused_gin_index.sql (9.7ms)23062026/10/01 10:22:43 OK 20251218171726_add_pins.sql (45.43ms)2307=== NAME TestPinProtectsFromGC2308 client_integration_test.go:840: Pin successfully protected closure from garbage collection23092026/10/01 10:22:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23102026/10/01 10:22:43 INFO Signed narinfos id=1 count=12311--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.02s)2312=== CONT TestService_verifyS3Integrity23132026/10/01 10:22:43 OK 20260628120000_add_object_size_and_stats.sql (32.01ms)2314--- PASS: TestPinProtectsFromGC (7.32s)2315=== CONT TestService_createPendingClosureHandler23162026/10/01 10:22:43 OK 20260905000000_add_claims.sql (56.62ms)23172026/10/01 10:22:43 OK 20260920000000_drop_claims.sql (32.82ms)23182026/10/01 10:22:43 OK 20260923120000_add_pushes.sql (12.96ms)23192026/10/01 10:22:43 goose: successfully migrated database to version: 2026092312000023202026/10/01 10:22:43 OK 1_commit_pending_closure.sql (1.99ms)23212026/10/01 10:22:43 OK 2_object_stats_trigger.sql (366.46µs)23222026/10/01 10:22:43 OK 3_commit_push.sql (291.5µs)23232026/10/01 10:22:43 goose: up to current file version: 323242026/10/01 10:22:43 INFO Received uploads request method=POST path=/api/pending_closures23252026-10-01 10:22:43.353 UTC [32456] ERROR: relation "goose_db_version" does not exist at character 3623262026-10-01 10:22:43.353 UTC [32456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23272026/10/01 10:22:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23282026/10/01 10:22:43 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDZhZmRjZjYtNGQxMS00NzNmLWE3N2ItNjg1OTY0OTI3ZjA4LjZlMjlhZmQ4LTFlN2MtNDY0MC1hNTZlLTU0YTQ4YjRmZjhiM3gxNzkwODUwMTYzMjQ3NTEwMDAw23292026/10/01 10:22:43 INFO Received uploads request method=POST path=/api/pending_closures23302026/10/01 10:22:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDZhZmRjZjYtNGQxMS00NzNmLWE3N2ItNjg1OTY0OTI3ZjA4LjZlMjlhZmQ4LTFlN2MtNDY0MC1hNTZlLTU0YTQ4YjRmZjhiM3gxNzkwODUwMTYzMjQ3NTEwMDAw parts=12331--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.41s)2332=== CONT TestPush_RejectsBadRequests23332026/10/01 10:22:43 INFO Received uploads request method=POST path=/api/pending_closures23342026/10/01 10:22:43 OK 20241026095416_initial_model.sql (219.33ms)23352026/10/01 10:22:43 OK 20251210153512_drop_unused_gin_index.sql (16.48ms)23362026/10/01 10:22:43 OK 20251218171726_add_pins.sql (30.99ms)23372026/10/01 10:22:43 OK 20260628120000_add_object_size_and_stats.sql (49.26ms)23382026/10/01 10:22:43 OK 20260905000000_add_claims.sql (45.72ms)23392026/10/01 10:22:43 OK 20260920000000_drop_claims.sql (60.21ms)23402026/10/01 10:22:43 OK 20260923120000_add_pushes.sql (18.76ms)23412026/10/01 10:22:43 goose: successfully migrated database to version: 2026092312000023422026/10/01 10:22:43 OK 1_commit_pending_closure.sql (3.22ms)23432026/10/01 10:22:43 OK 2_object_stats_trigger.sql (616.29µs)23442026/10/01 10:22:43 OK 3_commit_push.sql (367.92µs)23452026/10/01 10:22:43 goose: up to current file version: 323462026/10/01 10:22:43 INFO Received uploads request method=POST path=/api/pending_closures23472026/10/01 10:22:44 INFO Aborted multipart uploads count=0 kept=023482026/10/01 10:22:44 WARN Force mode enabled - objects will be deleted immediately without grace period23492026/10/01 10:22:44 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."23502026/10/01 10:22:44 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."2351--- PASS: TestFailedS3DeleteKeepsTombstone (2.31s)2352=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit23532026/10/01 10:22:44 INFO Received uploads request method=POST path=/api/pending_closures23542026-10-01 10:22:44.408 UTC [32462] ERROR: relation "goose_db_version" does not exist at character 3623552026-10-01 10:22:44.408 UTC [32462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23562026-10-01 10:22:44.522 UTC [32463] ERROR: relation "goose_db_version" does not exist at character 3623572026-10-01 10:22:44.522 UTC [32463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23582026-10-01 10:22:44.538 UTC [32464] ERROR: relation "goose_db_version" does not exist at character 3623592026-10-01 10:22:44.538 UTC [32464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23602026/10/01 10:22:44 OK 20241026095416_initial_model.sql (86.09ms)23612026/10/01 10:22:44 OK 20251210153512_drop_unused_gin_index.sql (21.46ms)2362--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.51s)2363=== CONT TestIsValidUploadKey2364=== RUN TestIsValidUploadKey/narinfo2365=== PAUSE TestIsValidUploadKey/narinfo2366=== RUN TestIsValidUploadKey/nar_zst2367=== PAUSE TestIsValidUploadKey/nar_zst2368=== RUN TestIsValidUploadKey/nar_xz2369=== PAUSE TestIsValidUploadKey/nar_xz2370=== RUN TestIsValidUploadKey/nar_plain2371=== PAUSE TestIsValidUploadKey/nar_plain2372=== RUN TestIsValidUploadKey/listing2373=== PAUSE TestIsValidUploadKey/listing2374=== RUN TestIsValidUploadKey/build_log2375=== PAUSE TestIsValidUploadKey/build_log2376=== RUN TestIsValidUploadKey/build_log_home-manager_file2377=== PAUSE TestIsValidUploadKey/build_log_home-manager_file2378=== RUN TestIsValidUploadKey/build_log_plus_in_name2379=== PAUSE TestIsValidUploadKey/build_log_plus_in_name2380=== RUN TestIsValidUploadKey/build_log_question_mark2381=== PAUSE TestIsValidUploadKey/build_log_question_mark2382=== RUN TestIsValidUploadKey/build_log_equals2383=== PAUSE TestIsValidUploadKey/build_log_equals2384=== RUN TestIsValidUploadKey/realisation2385=== PAUSE TestIsValidUploadKey/realisation2386=== RUN TestIsValidUploadKey/realisation_plus_in_output2387=== PAUSE TestIsValidUploadKey/realisation_plus_in_output2388=== RUN TestIsValidUploadKey/nix-cache-info2389=== PAUSE TestIsValidUploadKey/nix-cache-info2390=== RUN TestIsValidUploadKey/index.html2391=== PAUSE TestIsValidUploadKey/index.html2392=== RUN TestIsValidUploadKey/narinfo_key,_nar_type2393=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type2394=== RUN TestIsValidUploadKey/nar_key,_narinfo_type2395=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type2396=== RUN TestIsValidUploadKey/listing_key,_narinfo_type2397=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type2398=== RUN TestIsValidUploadKey/traversal2399=== PAUSE TestIsValidUploadKey/traversal2400=== RUN TestIsValidUploadKey/traversal_nar2401=== PAUSE TestIsValidUploadKey/traversal_nar2402=== RUN TestIsValidUploadKey/absolute2403=== PAUSE TestIsValidUploadKey/absolute2404=== RUN TestIsValidUploadKey/empty_key2405=== PAUSE TestIsValidUploadKey/empty_key2406=== RUN TestIsValidUploadKey/unknown_type2407=== PAUSE TestIsValidUploadKey/unknown_type2408=== CONT TestUploadHandlersRejectOversizedBody24092026/10/01 10:22:44 OK 20251218171726_add_pins.sql (25.64ms)2410=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure2411=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure2412=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart2413=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart2414=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts2415=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts2416=== CONT TestPushDedupSurvivesConcurrentGC24172026/10/01 10:22:44 OK 20260628120000_add_object_size_and_stats.sql (39.45ms)24182026/10/01 10:22:44 OK 20260905000000_add_claims.sql (21.92ms)24192026-10-01 10:22:44.653 UTC [32467] ERROR: relation "goose_db_version" does not exist at character 3624202026-10-01 10:22:44.653 UTC [32467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24212026/10/01 10:22:44 OK 20241026095416_initial_model.sql (118.93ms)24222026/10/01 10:22:44 OK 20260920000000_drop_claims.sql (32.1ms)24232026/10/01 10:22:44 OK 20251210153512_drop_unused_gin_index.sql (5.27ms)24242026/10/01 10:22:44 OK 20260923120000_add_pushes.sql (10.6ms)24252026/10/01 10:22:44 goose: successfully migrated database to version: 2026092312000024262026/10/01 10:22:44 OK 1_commit_pending_closure.sql (1.46ms)24272026/10/01 10:22:44 OK 2_object_stats_trigger.sql (297.71µs)24282026/10/01 10:22:44 OK 3_commit_push.sql (229.67µs)24292026/10/01 10:22:44 goose: up to current file version: 324302026/10/01 10:22:44 OK 20241026095416_initial_model.sql (111.05ms)24312026/10/01 10:22:44 OK 20251218171726_add_pins.sql (29.55ms)24322026/10/01 10:22:44 OK 20251210153512_drop_unused_gin_index.sql (6.33ms)24332026/10/01 10:22:44 OK 20251218171726_add_pins.sql (28.07ms)24342026/10/01 10:22:44 OK 20260628120000_add_object_size_and_stats.sql (36.74ms)24352026/10/01 10:22:44 OK 20260628120000_add_object_size_and_stats.sql (34.04ms)24362026/10/01 10:22:44 OK 20260905000000_add_claims.sql (64.25ms)24372026/10/01 10:22:44 OK 20260905000000_add_claims.sql (72.6ms)24382026/10/01 10:22:44 OK 20260920000000_drop_claims.sql (44.8ms)24392026/10/01 10:22:44 OK 20260923120000_add_pushes.sql (13.99ms)24402026/10/01 10:22:44 goose: successfully migrated database to version: 2026092312000024412026/10/01 10:22:44 OK 20260920000000_drop_claims.sql (27.18ms)24422026/10/01 10:22:44 OK 1_commit_pending_closure.sql (4.09ms)24432026/10/01 10:22:44 OK 2_object_stats_trigger.sql (46.61ms)24442026/10/01 10:22:44 OK 20260923120000_add_pushes.sql (48.41ms)24452026/10/01 10:22:44 goose: successfully migrated database to version: 2026092312000024462026/10/01 10:22:44 OK 3_commit_push.sql (673.83µs)24472026/10/01 10:22:44 goose: up to current file version: 324482026/10/01 10:22:44 OK 1_commit_pending_closure.sql (2.37ms)24492026/10/01 10:22:44 OK 2_object_stats_trigger.sql (567.25µs)24502026/10/01 10:22:44 OK 3_commit_push.sql (362.25µs)24512026/10/01 10:22:44 goose: up to current file version: 324522026/10/01 10:22:44 OK 20241026095416_initial_model.sql (235.58ms)24532026/10/01 10:22:44 OK 20251210153512_drop_unused_gin_index.sql (12.83ms)24542026/10/01 10:22:44 OK 20251218171726_add_pins.sql (45.47ms)24552026/10/01 10:22:45 INFO Received cleanup request method=DELETE path=/api/pending_closures24562026/10/01 10:22:45 INFO Aborted multipart uploads count=0 kept=024572026/10/01 10:22:45 INFO Received uploads request method=POST path=/api/pending_closures24582026/10/01 10:22:45 OK 20260628120000_add_object_size_and_stats.sql (43.12ms)24592026/10/01 10:22:45 INFO Received cleanup request method=DELETE path=/api/pending_closures24602026/10/01 10:22:45 OK 20260905000000_add_claims.sql (65.07ms)24612026/10/01 10:22:45 INFO Aborted multipart uploads count=1 kept=024622026/10/01 10:22:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24632026-10-01 10:22:45.143 UTC [32462] ERROR: Closure does not exist: id=124642026-10-01 10:22:45.143 UTC [32462] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE24652026-10-01 10:22:45.143 UTC [32462] STATEMENT: -- name: CommitPendingClosure :exec2466 SELECT commit_pending_closure($1::bigint)2467 2468--- PASS: TestService_cleanupPendingClosuresHandler (2.88s)2469=== CONT TestUploadHandlersRejectInvalidKeys2470=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2471=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2472=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2473=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2474=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2475=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2476=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2477=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2478=== CONT TestGCSweepSkipsPendingObjects24792026/10/01 10:22:45 OK 20260920000000_drop_claims.sql (48.81ms)24802026/10/01 10:22:45 OK 20260923120000_add_pushes.sql (27.4ms)24812026/10/01 10:22:45 goose: successfully migrated database to version: 2026092312000024822026/10/01 10:22:45 OK 1_commit_pending_closure.sql (2.18ms)24832026/10/01 10:22:45 OK 2_object_stats_trigger.sql (433.08µs)24842026/10/01 10:22:45 OK 3_commit_push.sql (329.75µs)24852026/10/01 10:22:45 goose: up to current file version: 324862026/10/01 10:22:45 INFO Received uploads request method=POST path=/api/pending_closures2487--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.96s)2488=== CONT TestDeduplicatedObjectsRecordedAsPending24892026/10/01 10:22:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24902026-10-01 10:22:45.647 UTC [32472] ERROR: relation "goose_db_version" does not exist at character 3624912026-10-01 10:22:45.647 UTC [32472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24922026/10/01 10:22:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MDZhZmRjZjYtNGQxMS00NzNmLWE3N2ItNjg1OTY0OTI3ZjA4LmRlNTI3OGQ0LWVkMTEtNDBhMi04NmE5LWFkNGNlMjBkNWI1MHgxNzkwODUwMTYzNTkxODk4MDAw parts=1224932026/10/01 10:22:45 INFO Received uploads request method=POST path=/api/pending_closures24942026/10/01 10:22:45 INFO Received uploads request method=POST path=/api/pending_closures24952026-10-01 10:22:45.807 UTC [32473] ERROR: relation "goose_db_version" does not exist at character 3624962026-10-01 10:22:45.807 UTC [32473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24972026/10/01 10:22:45 INFO Aborted multipart uploads count=0 kept=024982026/10/01 10:22:45 WARN Force mode enabled - objects will be deleted immediately without grace period24992026/10/01 10:22:45 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=025002026/10/01 10:22:45 OK 20241026095416_initial_model.sql (226.69ms)25012026/10/01 10:22:45 INFO Vacuumed table table=pending_closures25022026/10/01 10:22:45 INFO Vacuumed table table=pending_objects25032026/10/01 10:22:45 INFO Vacuumed table table=multipart_uploads25042026/10/01 10:22:45 INFO Vacuumed table table=closures25052026/10/01 10:22:46 OK 20251210153512_drop_unused_gin_index.sql (19.66ms)25062026/10/01 10:22:46 OK 20251218171726_add_pins.sql (44.79ms)25072026/10/01 10:22:46 INFO Vacuumed table table=objects2508--- PASS: TestGCSweepDeliversEachKeyOnce (3.51s)2509=== CONT TestGCMetrics25102026/10/01 10:22:46 OK 20260628120000_add_object_size_and_stats.sql (62.68ms)25112026/10/01 10:22:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25122026/10/01 10:22:46 OK 20241026095416_initial_model.sql (240.15ms)25132026/10/01 10:22:46 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst2514--- PASS: TestCompleteMultipartUnregistered (3.41s)2515=== CONT TestGCBugBareHashReferences25162026/10/01 10:22:46 OK 20260905000000_add_claims.sql (26.33ms)25172026/10/01 10:22:46 OK 20251210153512_drop_unused_gin_index.sql (11.82ms)25182026/10/01 10:22:46 OK 20251218171726_add_pins.sql (23.28ms)25192026/10/01 10:22:46 OK 20260920000000_drop_claims.sql (26.89ms)25202026/10/01 10:22:46 OK 20260923120000_add_pushes.sql (7.95ms)25212026/10/01 10:22:46 goose: successfully migrated database to version: 2026092312000025222026/10/01 10:22:46 OK 1_commit_pending_closure.sql (1.89ms)25232026/10/01 10:22:46 OK 2_object_stats_trigger.sql (335.5µs)25242026/10/01 10:22:46 OK 3_commit_push.sql (282.21µs)25252026/10/01 10:22:46 goose: up to current file version: 325262026-10-01 10:22:46.182 UTC [32477] ERROR: relation "goose_db_version" does not exist at character 3625272026-10-01 10:22:46.182 UTC [32477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25282026/10/01 10:22:46 OK 20260628120000_add_object_size_and_stats.sql (38.82ms)25292026/10/01 10:22:46 OK 20260905000000_add_claims.sql (70.02ms)25302026/10/01 10:22:46 OK 20260920000000_drop_claims.sql (30.29ms)25312026/10/01 10:22:46 OK 20260923120000_add_pushes.sql (21.78ms)25322026/10/01 10:22:46 goose: successfully migrated database to version: 2026092312000025332026/10/01 10:22:46 OK 1_commit_pending_closure.sql (2.78ms)25342026/10/01 10:22:46 OK 2_object_stats_trigger.sql (601.08µs)25352026/10/01 10:22:46 OK 3_commit_push.sql (410.92µs)25362026/10/01 10:22:46 goose: up to current file version: 325372026/10/01 10:22:46 INFO Received uploads request method=POST path=/api/pending_closures25382026/10/01 10:22:46 INFO Received uploads request method=POST path=/api/pending_closures25392026/10/01 10:22:46 INFO Received uploads request method=POST path=/api/pending_closures25402026/10/01 10:22:46 OK 20241026095416_initial_model.sql (235.88ms)25412026/10/01 10:22:46 OK 20251210153512_drop_unused_gin_index.sql (13.2ms)25422026/10/01 10:22:46 OK 20251218171726_add_pins.sql (64.84ms)25432026/10/01 10:22:46 OK 20260628120000_add_object_size_and_stats.sql (47.23ms)25442026/10/01 10:22:46 OK 20260905000000_add_claims.sql (83.33ms)25452026/10/01 10:22:46 OK 20260920000000_drop_claims.sql (60.29ms)25462026-10-01 10:22:46.805 UTC [32480] ERROR: relation "goose_db_version" does not exist at character 3625472026-10-01 10:22:46.805 UTC [32480] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25482026/10/01 10:22:46 OK 20260923120000_add_pushes.sql (89.82ms)25492026/10/01 10:22:46 goose: successfully migrated database to version: 2026092312000025502026/10/01 10:22:46 OK 1_commit_pending_closure.sql (4.06ms)25512026/10/01 10:22:46 OK 2_object_stats_trigger.sql (692.38µs)25522026/10/01 10:22:46 OK 3_commit_push.sql (414.46µs)25532026/10/01 10:22:46 goose: up to current file version: 325542026/10/01 10:22:46 INFO Received uploads request method=POST path=/api/pending_closures25552026/10/01 10:22:47 OK 20241026095416_initial_model.sql (311.99ms)25562026/10/01 10:22:47 OK 20251210153512_drop_unused_gin_index.sql (12.87ms)25572026/10/01 10:22:47 OK 20251218171726_add_pins.sql (41.86ms)2558=== RUN TestPush_RejectsBadRequests/no_roots2559=== PAUSE TestPush_RejectsBadRequests/no_roots2560=== RUN TestPush_RejectsBadRequests/no_objects2561=== PAUSE TestPush_RejectsBadRequests/no_objects2562=== RUN TestPush_RejectsBadRequests/bad_root2563=== PAUSE TestPush_RejectsBadRequests/bad_root2564=== RUN TestPush_RejectsBadRequests/root_not_in_objects2565=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2566=== CONT TestPresignedUploadRegisteredBeforeCommit25672026/10/01 10:22:47 OK 20260628120000_add_object_size_and_stats.sql (62.05ms)25682026/10/01 10:22:47 OK 20260905000000_add_claims.sql (78ms)25692026/10/01 10:22:47 OK 20260920000000_drop_claims.sql (46.65ms)25702026/10/01 10:22:47 OK 20260923120000_add_pushes.sql (22.57ms)25712026/10/01 10:22:47 goose: successfully migrated database to version: 2026092312000025722026/10/01 10:22:47 OK 1_commit_pending_closure.sql (2.11ms)25732026/10/01 10:22:47 OK 2_object_stats_trigger.sql (405.96µs)25742026/10/01 10:22:47 OK 3_commit_push.sql (338.25µs)25752026/10/01 10:22:47 goose: up to current file version: 325762026-10-01 10:22:47.657 UTC [32483] ERROR: relation "goose_db_version" does not exist at character 3625772026-10-01 10:22:47.657 UTC [32483] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25782026/10/01 10:22:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25792026/10/01 10:22:47 INFO Received push request method=POST path=/api/pushes25802026/10/01 10:22:47 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MDZhZmRjZjYtNGQxMS00NzNmLWE3N2ItNjg1OTY0OTI3ZjA4LjI2MzhhOGE4LWRjNTMtNGJiNC1iNDNkLTk3YmI0MjNiNDAyMHgxNzkwODUwMTY1NzMxNDgxMDAw error="Get \"http://127.0.0.1:1/bucket65/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"25812026/10/01 10:22:47 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MDZhZmRjZjYtNGQxMS00NzNmLWE3N2ItNjg1OTY0OTI3ZjA4LjljODY5NGQ4LWZhYTItNGY3ZS05ODZhLTA0NDEyNWIxYTdmMXgxNzkwODUwMTY1Njg5NjQxMDAw parts=1225822026/10/01 10:22:47 INFO Received cleanup request method=DELETE path=/api/pending_closures25832026/10/01 10:22:47 INFO Aborted multipart uploads count=1 kept=02584--- PASS: TestRedundantMultipartUpload (6.48s)2585=== CONT TestPendingClosureWriteTimeout2586=== RUN TestPendingClosureWriteTimeout/empty2587=== PAUSE TestPendingClosureWriteTimeout/empty2588=== RUN TestPendingClosureWriteTimeout/400_objects2589=== PAUSE TestPendingClosureWriteTimeout/400_objects2590=== RUN TestPendingClosureWriteTimeout/670k_objects2591=== PAUSE TestPendingClosureWriteTimeout/670k_objects2592=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2593=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2594=== CONT TestProxyWriteTimeout2595=== RUN TestProxyWriteTimeout/narinfo2596=== PAUSE TestProxyWriteTimeout/narinfo2597=== RUN TestProxyWriteTimeout/1_GiB_nar2598=== PAUSE TestProxyWriteTimeout/1_GiB_nar2599=== RUN TestProxyWriteTimeout/10_GiB_nar2600=== PAUSE TestProxyWriteTimeout/10_GiB_nar2601=== RUN TestProxyWriteTimeout/unknown_size2602=== PAUSE TestProxyWriteTimeout/unknown_size2603=== CONT TestIsValidCachePath/narinfo2604=== CONT TestIsValidCachePath/index.html2605=== CONT TestIsValidCachePath/short_hash2606=== CONT TestIsValidCachePath/wrong_extension2607=== CONT TestIsValidCachePath/leading_slash2608=== CONT TestIsValidCachePath/empty2609=== CONT TestIsValidCachePath/random_path2610=== CONT TestIsValidCachePath/invalid_char_u2611=== CONT TestIsValidCachePath/invalid_char_e2612=== CONT TestIsValidCachePath/traversal_in_middle2613=== CONT TestIsValidCachePath/traversal_parent2614=== CONT TestIsValidCachePath/nar_uncompressed2615=== CONT TestIsValidCachePath/nix-cache-info2616=== CONT TestIsValidCachePath/realisation2617=== CONT TestIsValidCachePath/log2618=== CONT TestIsValidCachePath/ls2619=== CONT TestIsValidCachePath/nar_xz2620=== CONT TestIsValidCachePath/nar_bz22621=== CONT TestIsValidCachePath/nar_zst2622=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2623--- PASS: TestIsValidCachePath (0.00s)2624 --- PASS: TestIsValidCachePath/narinfo (0.00s)2625 --- PASS: TestIsValidCachePath/index.html (0.00s)2626 --- PASS: TestIsValidCachePath/short_hash (0.00s)2627 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2628 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2629 --- PASS: TestIsValidCachePath/empty (0.00s)2630 --- PASS: TestIsValidCachePath/random_path (0.00s)2631 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2632 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2633 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2634 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2635 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2636 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2637 --- PASS: TestIsValidCachePath/realisation (0.00s)2638 --- PASS: TestIsValidCachePath/log (0.00s)2639 --- PASS: TestIsValidCachePath/ls (0.00s)2640 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2641 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2642 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2643 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2644=== CONT TestParseSingleRange/none2645=== CONT TestParseSingleRange/open-ended2646=== CONT TestParseSingleRange/start_far_past_EOF2647=== CONT TestParseSingleRange/start_past_EOF2648=== CONT TestParseSingleRange/suffix2649=== CONT TestParseSingleRange/suffix_exceeds_size2650=== CONT TestParseSingleRange/malformed_both_empty2651=== CONT TestParseSingleRange/closed2652=== CONT TestParseSingleRange/malformed_end_before_start2653=== CONT TestParseSingleRange/end_clamped_to_size2654=== CONT TestParseSingleRange/multi-range_ignored2655=== CONT TestParseSingleRange/malformed_no_dash2656=== CONT TestParseSingleRange/unknown_unit2657=== CONT TestParseSingleRange/single_byte2658--- PASS: TestParseSingleRange (0.00s)2659 --- PASS: TestParseSingleRange/none (0.00s)2660 --- PASS: TestParseSingleRange/open-ended (0.00s)2661 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2662 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2663 --- PASS: TestParseSingleRange/suffix (0.00s)2664 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2665 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2666 --- PASS: TestParseSingleRange/closed (0.00s)2667 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2668 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2669 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2670 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2671 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2672 --- PASS: TestParseSingleRange/single_byte (0.00s)2673=== CONT TestServerTLSConfig/no_client_CA2674=== CONT TestServerTLSConfig/not_a_PEM_file2675=== CONT TestServerTLSConfig/missing_CA_file2676--- PASS: TestServerTLSConfig (0.00s)2677 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2678 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)2679 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2680=== CONT TestResolveDBConnectionString/flag_wins2681=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2682=== CONT TestResolveDBConnectionString/nothing_configured2683=== CONT TestResolveDBConnectionString/missing_file_is_an_error2684=== CONT TestResolveDBConnectionString/file_when_flag_empty2685=== CONT TestClientErrorHandling/InvalidStorePath26862026/10/01 10:22:47 INFO Received complete push request method=POST path=/api/pushes/1/complete2687--- PASS: TestResolveDBConnectionString (0.01s)2688 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2689 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2690 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2691 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2692 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)26932026/10/01 10:22:47 INFO Received push request method=POST path=/api/pushes26942026/10/01 10:22:48 OK 20241026095416_initial_model.sql (310.17ms)26952026/10/01 10:22:48 OK 20251210153512_drop_unused_gin_index.sql (14.73ms)26962026/10/01 10:22:48 INFO Aborted multipart uploads count=0 kept=026972026/10/01 10:22:48 WARN Force mode enabled - objects will be deleted immediately without grace period26982026/10/01 10:22:48 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=026992026/10/01 10:22:48 INFO Vacuumed table table=pending_closures27002026/10/01 10:22:48 OK 20251218171726_add_pins.sql (55.37ms)27012026/10/01 10:22:48 INFO Vacuumed table table=pending_objects27022026/10/01 10:22:48 INFO Vacuumed table table=multipart_uploads27032026/10/01 10:22:48 OK 20260628120000_add_object_size_and_stats.sql (57.43ms)27042026/10/01 10:22:48 INFO Vacuumed table table=closures27052026/10/01 10:22:48 INFO Vacuumed table table=objects27062026/10/01 10:22:48 INFO Received complete push request method=POST path=/api/pushes/2/complete2707--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (4.02s)2708=== CONT TestClientErrorHandling/ServerNotAvailable27092026/10/01 10:22:48 OK 20260905000000_add_claims.sql (62.88ms)27102026-10-01 10:22:48.234 UTC [32487] ERROR: relation "goose_db_version" does not exist at character 3627112026-10-01 10:22:48.234 UTC [32487] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27122026/10/01 10:22:48 OK 20260920000000_drop_claims.sql (28.45ms)27132026/10/01 10:22:48 OK 20260923120000_add_pushes.sql (23.62ms)27142026/10/01 10:22:48 goose: successfully migrated database to version: 2026092312000027152026/10/01 10:22:48 OK 1_commit_pending_closure.sql (1.02ms)27162026/10/01 10:22:48 OK 2_object_stats_trigger.sql (252.29µs)27172026/10/01 10:22:48 OK 3_commit_push.sql (175.83µs)27182026/10/01 10:22:48 goose: up to current file version: 327192026/10/01 10:22:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete27202026/10/01 10:22:48 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MDZhZmRjZjYtNGQxMS00NzNmLWE3N2ItNjg1OTY0OTI3ZjA4LjhlMjkxODdkLTg2YzYtNDJhOC04ZDM5LTRmMzY4NDVhZWIyY3gxNzkwODUwMTY2NTMzNjkwMDAw parts=1027212026/10/01 10:22:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete27222026/10/01 10:22:48 INFO Completed upload id=127232026/10/01 10:22:48 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000027242026/10/01 10:22:48 INFO Received uploads request method=POST path=/api/pending_closures27252026/10/01 10:22:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures27262026/10/01 10:22:48 INFO Aborted multipart uploads count=0 kept=027272026/10/01 10:22:48 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=027282026/10/01 10:22:48 INFO Vacuumed table table=pending_closures27292026/10/01 10:22:48 INFO Vacuumed table table=pending_objects27302026/10/01 10:22:48 INFO Vacuumed table table=multipart_uploads27312026/10/01 10:22:48 INFO Vacuumed table table=closures27322026/10/01 10:22:48 INFO Vacuumed table table=objects27332026/10/01 10:22:48 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002734--- PASS: TestService_createPendingClosureHandler (5.50s)2735=== CONT TestClientErrorHandling/InvalidAuthToken27362026/10/01 10:22:48 OK 20241026095416_initial_model.sql (314.87ms)27372026/10/01 10:22:48 OK 20251210153512_drop_unused_gin_index.sql (18.26ms)27382026/10/01 10:22:48 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/present27392026/10/01 10:22:48 OK 20251218171726_add_pins.sql (44.69ms)27402026/10/01 10:22:48 OK 20260628120000_add_object_size_and_stats.sql (31.1ms)27412026/10/01 10:22:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete27422026/10/01 10:22:48 INFO Received uploads request method=POST path=/api/pending_closures27432026/10/01 10:22:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.367995ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27442026-10-01 10:22:48.779 UTC [32494] ERROR: relation "goose_db_version" does not exist at character 3627452026-10-01 10:22:48.779 UTC [32494] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27462026/10/01 10:22:48 OK 20260905000000_add_claims.sql (79.22ms)27472026/10/01 10:22:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MDZhZmRjZjYtNGQxMS00NzNmLWE3N2ItNjg1OTY0OTI3ZjA4LmUwNGM5NTM3LTEyMTktNDI0Mi05OTVlLTczNjkzOTEwZjc2MngxNzkwODUwMTY2OTMyMjI4MDAw parts=1027482026/10/01 10:22:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete27492026/10/01 10:22:48 OK 20260920000000_drop_claims.sql (29.65ms)27502026/10/01 10:22:48 INFO Completed upload id=127512026/10/01 10:22:48 INFO Received uploads request method=POST path=/api/pending_closures27522026/10/01 10:22:48 INFO Received uploads request method=POST path=/api/pending_closures27532026/10/01 10:22:48 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo27542026/10/01 10:22:48 WARN Found objects in DB but missing from S3, will re-upload count=12755--- PASS: TestService_verifyS3Integrity (5.79s)2756=== CONT TestCacheConfigHandler/full_config,_no_issuer2757=== CONT TestCacheConfigHandler/no_signing_keys2758=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2759=== CONT TestCacheConfigHandler/no_cache_url_configured2760--- PASS: TestCacheConfigHandler (0.00s)2761 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2762 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2763 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2764 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2765=== CONT TestService_RequireScope_OIDC/builder_may_write2766=== CONT TestService_RequireScope_OIDC/static_token_may_admin2767=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2768=== CONT TestService_RequireScope_OIDC/writer_implies_read2769=== CONT TestService_RequireScope_OIDC/reader_may_read2770=== CONT TestService_RequireScope_OIDC/static_token_may_write2771=== CONT TestService_RequireScope_OIDC/ops_may_not_write2772=== CONT TestService_RequireScope_OIDC/reader_may_not_write2773=== CONT TestService_RequireScope_OIDC/ops_may_admin2774=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2775=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2776--- PASS: TestService_RequireScope_OIDC (1.68s)2777 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2778 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2779 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2780 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2781 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2782 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2783 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2784 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2785 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2786 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)27872026/10/01 10:22:48 OK 20260923120000_add_pushes.sql (15.9ms)27882026/10/01 10:22:48 goose: successfully migrated database to version: 202609231200002789=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected27902026/10/01 10:22:48 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]2791=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2792=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected27932026/10/01 10:22:48 OK 1_commit_pending_closure.sql (2.31ms)27942026/10/01 10:22:48 OK 2_object_stats_trigger.sql (412.58µs)27952026/10/01 10:22:48 WARN Authentication failed token_preview=eyJhbGciOi...6yUn0hEBLw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]27962026/10/01 10:22:48 OK 3_commit_push.sql (344.75µs)27972026/10/01 10:22:48 goose: up to current file version: 32798=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows27992026/10/01 10:22:48 INFO Aborted multipart uploads count=0 kept=028002026/10/01 10:22:48 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=02801--- PASS: TestService_AuthMiddleware_OIDC (1.58s)2802 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2803 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2804 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2805 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)28062026/10/01 10:22:48 INFO Vacuumed table table=pending_closures28072026/10/01 10:22:48 INFO Vacuumed table table=pending_objects28082026/10/01 10:22:48 INFO Vacuumed table table=multipart_uploads28092026/10/01 10:22:48 INFO Vacuumed table table=closures28102026/10/01 10:22:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=364.554662ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28112026/10/01 10:22:48 INFO Vacuumed table table=objects28122026-10-01 10:22:48.970 UTC [32499] ERROR: relation "goose_db_version" does not exist at character 3628132026-10-01 10:22:48.970 UTC [32499] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28142026/10/01 10:22:48 INFO Aborted multipart uploads count=0 kept=028152026/10/01 10:22:48 WARN Force mode enabled - objects will be deleted immediately without grace period28162026/10/01 10:22:48 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=028172026/10/01 10:22:48 INFO Vacuumed table table=pending_closures28182026-10-01 10:22:48.987 UTC [32500] ERROR: relation "goose_db_version" does not exist at character 3628192026-10-01 10:22:48.987 UTC [32500] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC28202026/10/01 10:22:48 INFO Vacuumed table table=pending_objects28212026/10/01 10:22:48 INFO Vacuumed table table=multipart_uploads28222026/10/01 10:22:48 INFO Vacuumed table table=closures28232026/10/01 10:22:48 INFO Vacuumed table table=objects28242026/10/01 10:22:48 OK 20241026095416_initial_model.sql (157.89ms)2825--- PASS: TestPushDedupSurvivesConcurrentGC (4.37s)2826=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check28272026/10/01 10:22:49 OK 20251210153512_drop_unused_gin_index.sql (7.43ms)28282026/10/01 10:22:49 OK 20251218171726_add_pins.sql (28.38ms)28292026/10/01 10:22:49 OK 20260628120000_add_object_size_and_stats.sql (26.44ms)28302026/10/01 10:22:49 OK 20260905000000_add_claims.sql (36.91ms)28312026/10/01 10:22:49 OK 20260920000000_drop_claims.sql (18.49ms)28322026/10/01 10:22:49 OK 20241026095416_initial_model.sql (117.14ms)28332026/10/01 10:22:49 INFO Received uploads request method=POST path=/api/pending_closures28342026/10/01 10:22:49 OK 20260923120000_add_pushes.sql (14.15ms)28352026/10/01 10:22:49 goose: successfully migrated database to version: 2026092312000028362026/10/01 10:22:49 OK 1_commit_pending_closure.sql (2.67ms)28372026/10/01 10:22:49 OK 2_object_stats_trigger.sql (474.13µs)28382026/10/01 10:22:49 OK 3_commit_push.sql (350.88µs)28392026/10/01 10:22:49 goose: up to current file version: 328402026/10/01 10:22:49 OK 20251210153512_drop_unused_gin_index.sql (16.53ms)28412026/10/01 10:22:49 OK 20241026095416_initial_model.sql (130.68ms)28422026/10/01 10:22:49 OK 20251210153512_drop_unused_gin_index.sql (13.86ms)28432026/10/01 10:22:49 OK 20251218171726_add_pins.sql (41.04ms)28442026/10/01 10:22:49 INFO Aborted multipart uploads count=0 kept=028452026/10/01 10:22:49 WARN Force mode enabled - objects will be deleted immediately without grace period28462026/10/01 10:22:49 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=028472026/10/01 10:22:49 OK 20251218171726_add_pins.sql (30.61ms)28482026/10/01 10:22:49 OK 20260628120000_add_object_size_and_stats.sql (33.27ms)28492026/10/01 10:22:49 INFO Vacuumed table table=pending_closures28502026/10/01 10:22:49 OK 20260628120000_add_object_size_and_stats.sql (48.37ms)28512026/10/01 10:22:49 INFO Vacuumed table table=pending_objects28522026/10/01 10:22:49 INFO Vacuumed table table=multipart_uploads28532026/10/01 10:22:49 INFO Vacuumed table table=closures28542026/10/01 10:22:49 INFO Vacuumed table table=objects28552026/10/01 10:22:49 OK 20260905000000_add_claims.sql (57.4ms)28562026/10/01 10:22:49 OK 20260905000000_add_claims.sql (25.03ms)28572026/10/01 10:22:49 OK 20260920000000_drop_claims.sql (14.45ms)2858--- PASS: TestGCSweepSkipsPendingObjects (4.14s)2859=== CONT TestIsValidUploadKey/narinfo2860=== CONT TestIsValidUploadKey/realisation_plus_in_output2861=== CONT TestIsValidUploadKey/unknown_type2862=== CONT TestIsValidUploadKey/empty_key2863=== CONT TestIsValidUploadKey/absolute2864=== CONT TestIsValidUploadKey/traversal_nar2865=== CONT TestIsValidUploadKey/traversal2866=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2867=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2868=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2869=== CONT TestIsValidUploadKey/index.html2870=== CONT TestIsValidUploadKey/nix-cache-info2871=== CONT TestIsValidUploadKey/build_log_home-manager_file2872=== CONT TestIsValidUploadKey/realisation2873=== CONT TestIsValidUploadKey/build_log_equals2874=== CONT TestIsValidUploadKey/build_log_question_mark2875=== CONT TestIsValidUploadKey/build_log_plus_in_name2876=== CONT TestIsValidUploadKey/nar_plain2877=== CONT TestIsValidUploadKey/build_log2878=== CONT TestIsValidUploadKey/listing2879=== CONT TestIsValidUploadKey/nar_xz2880=== CONT TestIsValidUploadKey/nar_zst2881=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure2882--- PASS: TestIsValidUploadKey (0.00s)2883 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2884 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2885 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2886 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2887 --- PASS: TestIsValidUploadKey/absolute (0.00s)2888 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2889 --- PASS: TestIsValidUploadKey/traversal (0.00s)2890 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2891 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2892 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2893 --- PASS: TestIsValidUploadKey/index.html (0.00s)2894 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2895 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2896 --- PASS: TestIsValidUploadKey/realisation (0.00s)2897 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2898 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2899 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2900 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2901 --- PASS: TestIsValidUploadKey/build_log (0.00s)2902 --- PASS: TestIsValidUploadKey/listing (0.00s)2903 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2904 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)29052026/10/01 10:22:49 INFO Received uploads request method=POST path=/29062026/10/01 10:22:49 OK 20260920000000_drop_claims.sql (20.99ms)29072026/10/01 10:22:49 OK 20260923120000_add_pushes.sql (9.39ms)29082026/10/01 10:22:49 goose: successfully migrated database to version: 2026092312000029092026/10/01 10:22:49 OK 1_commit_pending_closure.sql (2.77ms)29102026/10/01 10:22:49 OK 2_object_stats_trigger.sql (477.75µs)29112026/10/01 10:22:49 OK 3_commit_push.sql (362.75µs)29122026/10/01 10:22:49 goose: up to current file version: 329132026/10/01 10:22:49 OK 20260923120000_add_pushes.sql (10.52ms)29142026/10/01 10:22:49 goose: successfully migrated database to version: 2026092312000029152026/10/01 10:22:49 OK 1_commit_pending_closure.sql (1.76ms)29162026/10/01 10:22:49 OK 2_object_stats_trigger.sql (401.04µs)29172026/10/01 10:22:49 OK 3_commit_push.sql (265.88µs)29182026/10/01 10:22:49 goose: up to current file version: 329192026/10/01 10:22:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=724.81688ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29202026/10/01 10:22:49 INFO Received uploads request method=POST path=/api/pending_closures2921--- PASS: TestDeduplicatedObjectsRecordedAsPending (3.95s)2922=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts29232026/10/01 10:22:49 INFO Received request for more parts method=POST path=/2924=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart29252026/10/01 10:22:49 INFO Received complete multipart upload request method=POST path=/2926=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info29272026/10/01 10:22:49 INFO Received uploads request method=POST path=/2928=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key29292026/10/01 10:22:49 INFO Received complete multipart upload request method=POST path=/2930=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key29312026/10/01 10:22:49 INFO Received request for more parts method=POST path=/2932=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal29332026/10/01 10:22:49 INFO Received uploads request method=POST path=/2934--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2935 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2936 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2937 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2938 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2939=== CONT TestPush_RejectsBadRequests/no_roots29402026/10/01 10:22:49 INFO Received push request method=POST path=/api/pushes2941=== CONT TestPush_RejectsBadRequests/bad_root29422026/10/01 10:22:49 INFO Received push request method=POST path=/api/pushes2943=== CONT TestPush_RejectsBadRequests/root_not_in_objects29442026/10/01 10:22:49 INFO Received push request method=POST path=/api/pushes2945=== CONT TestPush_RejectsBadRequests/no_objects29462026/10/01 10:22:49 INFO Received push request method=POST path=/api/pushes2947=== CONT TestPendingClosureWriteTimeout/empty2948=== CONT TestPendingClosureWriteTimeout/670k_objects2949=== CONT TestPendingClosureWriteTimeout/400_objects2950=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2951--- PASS: TestPush_RejectsBadRequests (3.70s)2952 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2953 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2954 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2955 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)29562026-10-01 10:22:49.549 UTC [32506] ERROR: relation "goose_db_version" does not exist at character 3629572026-10-01 10:22:49.549 UTC [32506] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2958--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)2959 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2960 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2961 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)2962=== CONT TestProxyWriteTimeout/narinfo2963=== CONT TestProxyWriteTimeout/10_GiB_nar2964=== CONT TestProxyWriteTimeout/unknown_size2965=== CONT TestProxyWriteTimeout/1_GiB_nar2966--- PASS: TestProxyWriteTimeout (0.00s)2967 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2968 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2969 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2970 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)29712026/10/01 10:22:49 INFO Aborted multipart uploads count=0 kept=029722026/10/01 10:22:49 WARN Force mode enabled - objects will be deleted immediately without grace period29732026/10/01 10:22:49 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=029742026/10/01 10:22:49 INFO Vacuumed table table=pending_closures29752026/10/01 10:22:49 INFO Vacuumed table table=pending_objects29762026/10/01 10:22:49 INFO Vacuumed table table=multipart_uploads29772026/10/01 10:22:49 INFO Vacuumed table table=closures29782026/10/01 10:22:49 INFO Vacuumed table table=objects2979--- PASS: TestGCMetrics (3.58s)29802026/10/01 10:22:49 OK 20241026095416_initial_model.sql (121.2ms)29812026/10/01 10:22:49 OK 20251210153512_drop_unused_gin_index.sql (7.72ms)29822026/10/01 10:22:49 OK 20251218171726_add_pins.sql (31.24ms)29832026-10-01 10:22:49.744 UTC [32508] ERROR: relation "goose_db_version" does not exist at character 3629842026-10-01 10:22:49.744 UTC [32508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC29852026/10/01 10:22:49 OK 20260628120000_add_object_size_and_stats.sql (26.72ms)29862026/10/01 10:22:49 OK 20260905000000_add_claims.sql (64.11ms)29872026/10/01 10:22:49 OK 20260920000000_drop_claims.sql (44.98ms)29882026/10/01 10:22:49 OK 20260923120000_add_pushes.sql (14.73ms)29892026/10/01 10:22:49 goose: successfully migrated database to version: 2026092312000029902026/10/01 10:22:49 OK 1_commit_pending_closure.sql (4.57ms)29912026/10/01 10:22:49 OK 2_object_stats_trigger.sql (1.37ms)29922026/10/01 10:22:49 OK 3_commit_push.sql (1.42ms)29932026/10/01 10:22:49 goose: up to current file version: 329942026/10/01 10:22:50 OK 20241026095416_initial_model.sql (171.6ms)29952026/10/01 10:22:50 OK 20251210153512_drop_unused_gin_index.sql (9.95ms)29962026/10/01 10:22:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.619272665s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29972026/10/01 10:22:50 OK 20251218171726_add_pins.sql (46.65ms)2998--- PASS: TestGCBugBareHashReferences (4.00s)29992026/10/01 10:22:50 OK 20260628120000_add_object_size_and_stats.sql (46.46ms)30002026/10/01 10:22:50 OK 20260905000000_add_claims.sql (80.61ms)30012026/10/01 10:22:50 INFO Received uploads request method=POST path=/api/pending_closures30022026/10/01 10:22:50 OK 20260920000000_drop_claims.sql (50.69ms)30032026/10/01 10:22:50 OK 20260923120000_add_pushes.sql (21ms)30042026/10/01 10:22:50 goose: successfully migrated database to version: 2026092312000030052026/10/01 10:22:50 OK 1_commit_pending_closure.sql (4.31ms)30062026/10/01 10:22:50 OK 2_object_stats_trigger.sql (975.96µs)30072026/10/01 10:22:50 OK 3_commit_push.sql (1.13ms)30082026/10/01 10:22:50 goose: up to current file version: 330092026/10/01 10:22:50 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst30102026/10/01 10:22:50 INFO Received uploads request method=POST path=/api/pending_closures3011--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.02s)30122026-10-01 10:22:50.642 UTC [32509] ERROR: relation "goose_db_version" does not exist at character 3630132026-10-01 10:22:50.642 UTC [32509] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC30142026-10-01 10:22:50.667 UTC [32511] ERROR: relation "goose_db_version" does not exist at character 3630152026-10-01 10:22:50.667 UTC [32511] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC30162026-10-01 10:22:50.703 UTC [32513] ERROR: relation "goose_db_version" does not exist at character 3630172026-10-01 10:22:50.703 UTC [32513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC30182026/10/01 10:22:50 OK 20241026095416_initial_model.sql (60.92ms)30192026/10/01 10:22:50 OK 20251210153512_drop_unused_gin_index.sql (6.07ms)30202026/10/01 10:22:50 OK 20251218171726_add_pins.sql (6.07ms)30212026/10/01 10:22:50 OK 20260628120000_add_object_size_and_stats.sql (3.08ms)30222026/10/01 10:22:50 OK 20241026095416_initial_model.sql (35.13ms)30232026/10/01 10:22:50 OK 20251210153512_drop_unused_gin_index.sql (838.38µs)30242026/10/01 10:22:50 OK 20260905000000_add_claims.sql (17.33ms)30252026/10/01 10:22:50 OK 20251218171726_add_pins.sql (16.46ms)30262026/10/01 10:22:50 OK 20241026095416_initial_model.sql (32.91ms)30272026/10/01 10:22:50 OK 20260920000000_drop_claims.sql (14.58ms)30282026/10/01 10:22:50 OK 20251210153512_drop_unused_gin_index.sql (6.99ms)30292026/10/01 10:22:50 OK 20260628120000_add_object_size_and_stats.sql (20.35ms)30302026/10/01 10:22:50 OK 20260923120000_add_pushes.sql (6.27ms)30312026/10/01 10:22:50 goose: successfully migrated database to version: 2026092312000030322026/10/01 10:22:50 OK 1_commit_pending_closure.sql (1.51ms)30332026/10/01 10:22:50 OK 2_object_stats_trigger.sql (326.25µs)30342026/10/01 10:22:50 OK 3_commit_push.sql (267.33µs)30352026/10/01 10:22:50 goose: up to current file version: 330362026/10/01 10:22:50 OK 20251218171726_add_pins.sql (9.98ms)30372026/10/01 10:22:50 OK 20260628120000_add_object_size_and_stats.sql (37.65ms)30382026/10/01 10:22:50 OK 20260905000000_add_claims.sql (46.73ms)30392026/10/01 10:22:50 OK 20260920000000_drop_claims.sql (26.06ms)30402026/10/01 10:22:50 OK 20260923120000_add_pushes.sql (10.82ms)30412026/10/01 10:22:50 goose: successfully migrated database to version: 2026092312000030422026/10/01 10:22:50 OK 1_commit_pending_closure.sql (2.91ms)30432026/10/01 10:22:50 OK 2_object_stats_trigger.sql (636.21µs)30442026/10/01 10:22:50 OK 3_commit_push.sql (491.29µs)30452026/10/01 10:22:50 goose: up to current file version: 330462026/10/01 10:22:50 OK 20260905000000_add_claims.sql (43.91ms)30472026/10/01 10:22:50 OK 20260920000000_drop_claims.sql (38.56ms)30482026/10/01 10:22:50 OK 20260923120000_add_pushes.sql (15.78ms)30492026/10/01 10:22:50 goose: successfully migrated database to version: 2026092312000030502026/10/01 10:22:50 OK 1_commit_pending_closure.sql (4.61ms)30512026/10/01 10:22:50 OK 2_object_stats_trigger.sql (954.5µs)30522026/10/01 10:22:50 OK 3_commit_push.sql (726.42µs)30532026/10/01 10:22:50 goose: up to current file version: 330542026-10-01 10:22:51.013 UTC [32514] ERROR: relation "goose_db_version" does not exist at character 3630552026-10-01 10:22:51.013 UTC [32514] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC30562026/10/01 10:22:51 OK 20241026095416_initial_model.sql (97.11ms)30572026/10/01 10:22:51 OK 20251210153512_drop_unused_gin_index.sql (11.47ms)30582026/10/01 10:22:51 OK 20251218171726_add_pins.sql (33.26ms)30592026/10/01 10:22:51 OK 20260628120000_add_object_size_and_stats.sql (19.37ms)30602026/10/01 10:22:51 OK 20260905000000_add_claims.sql (28.37ms)30612026/10/01 10:22:51 INFO Received uploads request method=POST path=/api/pending_closures30622026/10/01 10:22:51 INFO Aborted multipart uploads count=0 kept=030632026/10/01 10:22:51 WARN Force mode enabled - objects will be deleted immediately without grace period30642026/10/01 10:22:51 OK 20260920000000_drop_claims.sql (36.97ms)30652026/10/01 10:22:51 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30662026/10/01 10:22:51 OK 20260923120000_add_pushes.sql (15.96ms)30672026/10/01 10:22:51 goose: successfully migrated database to version: 2026092312000030682026/10/01 10:22:51 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=030692026/10/01 10:22:51 INFO Vacuumed table table=pending_closures30702026/10/01 10:22:51 OK 1_commit_pending_closure.sql (895.08µs)30712026/10/01 10:22:51 INFO Vacuumed table table=pending_objects30722026/10/01 10:22:51 OK 2_object_stats_trigger.sql (255.88µs)30732026/10/01 10:22:51 INFO Vacuumed table table=multipart_uploads30742026/10/01 10:22:51 INFO Vacuumed table table=closures30752026/10/01 10:22:51 OK 3_commit_push.sql (164.71µs)30762026/10/01 10:22:51 goose: up to current file version: 330772026/10/01 10:22:51 INFO Vacuumed table table=objects30782026/10/01 10:22:51 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30792026/10/01 10:22:51 INFO Received uploads request method=POST path=/api/pending_closures30802026/10/01 10:22:51 INFO Aborted multipart uploads count=0 kept=030812026/10/01 10:22:51 WARN Force mode enabled - objects will be deleted immediately without grace period30822026/10/01 10:22:51 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=030832026/10/01 10:22:51 INFO Vacuumed table table=pending_closures30842026/10/01 10:22:51 INFO Vacuumed table table=pending_objects30852026/10/01 10:22:51 INFO Vacuumed table table=multipart_uploads30862026/10/01 10:22:51 INFO Vacuumed table table=closures30872026/10/01 10:22:51 INFO Vacuumed table table=objects3088--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)3089 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.52s)3090 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.64s)30912026/10/01 10:22:51 INFO Received uploads request method=POST path=/api/pending_closures30922026/10/01 10:22:51 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-config30932026/10/01 10:22:51 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.8149ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30942026/10/01 10:22:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=418.971926ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30952026/10/01 10:22:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=790.720381ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config3096--- PASS: TestPendingClosureWriteTimeout (0.00s)3097 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)3098 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)3099 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)3100 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.06s)31012026/10/01 10:22:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.507429332s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31022026/10/01 10:22:54 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"31032026/10/01 10:22:54 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-config31042026/10/01 10:22:54 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.344907ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31052026/10/01 10:22:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.077228ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31062026/10/01 10:22:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=830.664531ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31072026/10/01 10:22:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.592483392s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config31082026/10/01 10:22:57 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_closures31092026/10/01 10:22:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.047277ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures31102026/10/01 10:22:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=438.044253ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures31112026/10/01 10:22:58 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=835.926305ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures31122026/10/01 10:22:59 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.54736092s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3113--- PASS: TestClientErrorHandling (0.00s)3114 --- PASS: TestClientErrorHandling/InvalidStorePath (2.79s)3115 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.75s)3116 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.87s)3117PASS3118{"timestamp":"2026-10-01T10:23:01.076149Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:61054","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(3)"}31192026-10-01 10:23:01.219 UTC [32084] LOG: received smart shutdown request31202026-10-01 10:23:01.219 UTC [32084] LOG: background worker "logical replication launcher" (PID 32094) exited with exit code 131212026-10-01 10:23:01.225 UTC [32089] LOG: shutting down31222026-10-01 10:23:01.225 UTC [32089] LOG: checkpoint starting: shutdown immediate31232026-10-01 10:23:02.487 UTC [32089] LOG: checkpoint complete: wrote 12957 buffers (79.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.726 s, sync=0.496 s, total=1.262 s; sync files=28984, longest=0.001 s, average=0.001 s; distance=407893 kB, estimate=407893 kB; lsn=0/1A5E2630, redo lsn=0/1A5E263031242026-10-01 10:23:02.492 UTC [32084] LOG: database system is shut down3125Running OIDC tests...3126=== RUN TestAudienceForIssuer3127=== PAUSE TestAudienceForIssuer3128=== RUN TestGlobMatch3129=== PAUSE TestGlobMatch3130=== RUN TestValidateToken_ValidToken3131=== PAUSE TestValidateToken_ValidToken3132=== RUN TestValidateToken_WrongAudience3133=== PAUSE TestValidateToken_WrongAudience3134=== RUN TestValidateToken_Expired3135=== PAUSE TestValidateToken_Expired3136=== RUN TestValidateToken_BoundClaimsMismatch3137=== PAUSE TestValidateToken_BoundClaimsMismatch3138=== RUN TestValidateToken_BoundSubjectMismatch3139=== PAUSE TestValidateToken_BoundSubjectMismatch3140=== RUN TestValidateToken_MultipleProviders3141=== PAUSE TestValidateToken_MultipleProviders3142=== RUN TestValidateToken_NoMatchingProvider3143=== PAUSE TestValidateToken_NoMatchingProvider3144=== RUN TestValidateToken_KubernetesServiceAccount3145=== PAUSE TestValidateToken_KubernetesServiceAccount3146=== RUN TestNewValidator_KubernetesRequiresCA3147=== PAUSE TestNewValidator_KubernetesRequiresCA3148=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3149=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3150=== RUN TestPins_ReservedForMatchingRule3151=== PAUSE TestPins_ReservedForMatchingRule3152=== RUN TestPins_TopLevelShorthand3153=== PAUSE TestPins_TopLevelShorthand3154=== RUN TestPins_ConfigValidation3155=== PAUSE TestPins_ConfigValidation3156=== RUN TestScopes_LegacyProviderDefaultsToWrite3157=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3158=== RUN TestScopes_Rules3159=== PAUSE TestScopes_Rules3160=== RUN TestScopes_ConfigValidation3161=== PAUSE TestScopes_ConfigValidation3162=== CONT TestAudienceForIssuer3163=== CONT TestValidateToken_KubernetesServiceAccount3164=== CONT TestValidateToken_WrongAudience3165=== CONT TestValidateToken_ValidToken3166=== CONT TestPins_ConfigValidation3167=== CONT TestGlobMatch3168=== RUN TestGlobMatch/foo_foo3169=== PAUSE TestGlobMatch/foo_foo3170=== RUN TestGlobMatch/foo_bar3171--- PASS: TestAudienceForIssuer (0.00s)3172=== CONT TestValidateToken_NoMatchingProvider3173=== CONT TestValidateToken_MultipleProviders3174=== CONT TestValidateToken_BoundSubjectMismatch3175--- PASS: TestPins_ConfigValidation (0.00s)3176=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3177=== CONT TestValidateToken_BoundClaimsMismatch3178=== CONT TestValidateToken_Expired3179=== PAUSE TestGlobMatch/foo_bar3180=== RUN TestGlobMatch/*_3181=== PAUSE TestGlobMatch/*_3182=== RUN TestGlobMatch/*_anything3183=== PAUSE TestGlobMatch/*_anything3184=== RUN TestGlobMatch/foo*_foo3185=== PAUSE TestGlobMatch/foo*_foo3186=== RUN TestGlobMatch/foo*_foobar3187=== PAUSE TestGlobMatch/foo*_foobar3188=== RUN TestGlobMatch/foo*_bar3189=== PAUSE TestGlobMatch/foo*_bar3190=== RUN TestGlobMatch/*bar_bar3191=== PAUSE TestGlobMatch/*bar_bar3192=== RUN TestGlobMatch/*bar_foobar3193=== PAUSE TestGlobMatch/*bar_foobar3194=== RUN TestGlobMatch/*bar_foo3195=== PAUSE TestGlobMatch/*bar_foo3196=== RUN TestGlobMatch/foo*bar_foobar3197=== PAUSE TestGlobMatch/foo*bar_foobar3198=== RUN TestGlobMatch/foo*bar_foo123bar3199=== PAUSE TestGlobMatch/foo*bar_foo123bar3200=== RUN TestGlobMatch/foo*bar_foobarbaz3201=== PAUSE TestGlobMatch/foo*bar_foobarbaz3202=== RUN TestGlobMatch/*/*_foo/bar3203=== PAUSE TestGlobMatch/*/*_foo/bar3204=== RUN TestGlobMatch/*/*_foo3205=== PAUSE TestGlobMatch/*/*_foo3206=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3207=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3208=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03209=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03210=== RUN TestGlobMatch/refs/*/main_refs/heads/main3211=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3212=== RUN TestGlobMatch/fo?_foo3213=== PAUSE TestGlobMatch/fo?_foo3214=== RUN TestGlobMatch/fo?_fo3215=== PAUSE TestGlobMatch/fo?_fo3216=== RUN TestGlobMatch/fo?_fooo3217=== PAUSE TestGlobMatch/fo?_fooo3218=== RUN TestGlobMatch/?oo_foo3219=== PAUSE TestGlobMatch/?oo_foo3220=== RUN TestGlobMatch/?oo_boo3221=== PAUSE TestGlobMatch/?oo_boo3222=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3223=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3224=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3225=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3226=== CONT TestPins_TopLevelShorthand32272026/10/01 10:23:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61126/oidc3228--- PASS: TestValidateToken_Expired (0.03s)3229=== CONT TestPins_ReservedForMatchingRule32302026/10/01 10:23:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61128/oidc3231--- PASS: TestValidateToken_ValidToken (0.04s)3232=== CONT TestScopes_Rules32332026/10/01 10:23:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61130/oidc3234--- PASS: TestPins_TopLevelShorthand (0.07s)3235=== CONT TestScopes_ConfigValidation3236--- PASS: TestScopes_ConfigValidation (0.00s)3237=== CONT TestScopes_LegacyProviderDefaultsToWrite32382026/10/01 10:23:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61132/oidc3239--- PASS: TestScopes_Rules (0.04s)3240=== CONT TestNewValidator_KubernetesRequiresCA32412026/10/01 10:23:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61134/oidc3242--- PASS: TestValidateToken_WrongAudience (0.09s)3243=== CONT TestGlobMatch/foo_foo3244=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3245=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3246=== CONT TestGlobMatch/?oo_boo3247=== CONT TestGlobMatch/?oo_foo3248=== CONT TestGlobMatch/fo?_fooo3249=== CONT TestGlobMatch/fo?_fo3250=== CONT TestGlobMatch/fo?_foo3251=== CONT TestGlobMatch/refs/*/main_refs/heads/main3252=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03253=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3254=== CONT TestGlobMatch/*/*_foo3255=== CONT TestGlobMatch/*/*_foo/bar3256=== CONT TestGlobMatch/foo*bar_foobarbaz3257=== CONT TestGlobMatch/foo*bar_foo123bar3258=== CONT TestGlobMatch/foo*bar_foobar3259=== CONT TestGlobMatch/*bar_foo3260=== CONT TestGlobMatch/*bar_foobar3261=== CONT TestGlobMatch/*bar_bar3262=== CONT TestGlobMatch/foo*_bar3263=== CONT TestGlobMatch/foo*_foobar3264=== CONT TestGlobMatch/foo*_foo3265=== CONT TestGlobMatch/*_anything3266=== CONT TestGlobMatch/*_3267=== CONT TestGlobMatch/foo_bar3268--- PASS: TestGlobMatch (0.01s)3269 --- PASS: TestGlobMatch/foo_foo (0.00s)3270 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3271 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3272 --- PASS: TestGlobMatch/?oo_boo (0.00s)3273 --- PASS: TestGlobMatch/?oo_foo (0.00s)3274 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3275 --- PASS: TestGlobMatch/fo?_fo (0.00s)3276 --- PASS: TestGlobMatch/fo?_foo (0.00s)3277 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3278 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3279 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3280 --- PASS: TestGlobMatch/*/*_foo (0.00s)3281 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3282 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3283 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3284 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3285 --- PASS: TestGlobMatch/*bar_foo (0.00s)3286 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3287 --- PASS: TestGlobMatch/*bar_bar (0.00s)3288 --- PASS: TestGlobMatch/foo*_bar (0.00s)3289 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3290 --- PASS: TestGlobMatch/foo*_foo (0.00s)3291 --- PASS: TestGlobMatch/*_anything (0.00s)3292 --- PASS: TestGlobMatch/*_ (0.00s)3293 --- PASS: TestGlobMatch/foo_bar (0.00s)32942026/10/01 10:23:03 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233295--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)32962026/10/01 10:23:03 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:611383297--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)32982026/10/01 10:23:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61140/oidc3299--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)33002026/10/01 10:23:03 http: TLS handshake error from 127.0.0.1:61143: remote error: tls: bad certificate3301--- PASS: TestNewValidator_KubernetesRequiresCA (0.05s)33022026/10/01 10:23:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61145/oidc3303--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)33042026/10/01 10:23:03 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:61147/oidc33052026/10/01 10:23:03 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:61144/oidc3306--- PASS: TestValidateToken_MultipleProviders (0.14s)33072026/10/01 10:23:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61150/oidc3308--- PASS: TestPins_ReservedForMatchingRule (0.11s)33092026/10/01 10:23:03 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:61152/oidc3310--- PASS: TestValidateToken_NoMatchingProvider (0.20s)33112026/10/01 10:23:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61155/oidc3312--- PASS: TestValidateToken_BoundSubjectMismatch (0.21s)3313PASS3314Running hook tests...3315=== RUN TestSendPathsEmpty3316=== PAUSE TestSendPathsEmpty3317=== RUN TestQueueEnqueueAndFetch3318=== PAUSE TestQueueEnqueueAndFetch3319=== RUN TestQueueDeduplication3320=== PAUSE TestQueueDeduplication3321=== RUN TestQueueRemove3322=== PAUSE TestQueueRemove3323=== RUN TestQueueFetchBatchLimit3324=== PAUSE TestQueueFetchBatchLimit3325=== RUN TestQueueRetryMovesToBack3326=== PAUSE TestQueueRetryMovesToBack3327=== RUN TestQueueFetchRemoveLifecycle3328=== PAUSE TestQueueFetchRemoveLifecycle3329=== RUN TestQueueConcurrentWriters3330=== PAUSE TestQueueConcurrentWriters3331=== RUN TestQueueRemoveLargeClosure3332=== PAUSE TestQueueRemoveLargeClosure3333=== RUN TestServerClientIntegration3334=== PAUSE TestServerClientIntegration3335=== RUN TestServerQueueError3336=== PAUSE TestServerQueueError3337=== RUN TestGetListenerSocketActivation3338 server_test.go:210: === RUN TestGetListenerSocketActivation3339 --- PASS: TestGetListenerSocketActivation (0.00s)3340 PASS3341 3342--- PASS: TestGetListenerSocketActivation (0.01s)3343=== RUN TestDrainIsolatesPoisonPath3344=== PAUSE TestDrainIsolatesPoisonPath3345=== RUN TestRunNotBlockedByPoisonHead3346=== PAUSE TestRunNotBlockedByPoisonHead3347=== RUN TestDrainGivesUpWhenServerDown3348=== PAUSE TestDrainGivesUpWhenServerDown3349=== RUN TestFailedPathPrunedByLaterClosure3350=== PAUSE TestFailedPathPrunedByLaterClosure3351=== RUN TestWorkerUploadsAndRemoves3352=== PAUSE TestWorkerUploadsAndRemoves3353=== RUN TestWorkerSkipsGCdPaths3354=== PAUSE TestWorkerSkipsGCdPaths3355=== RUN TestWorkerPrunesClosureDeps3356=== PAUSE TestWorkerPrunesClosureDeps3357=== RUN TestDrainTimeout3358=== PAUSE TestDrainTimeout3359=== CONT TestSendPathsEmpty3360=== CONT TestServerQueueError3361--- PASS: TestSendPathsEmpty (0.00s)3362=== CONT TestQueueFetchBatchLimit3363=== CONT TestQueueRetryMovesToBack3364=== CONT TestWorkerUploadsAndRemoves3365=== CONT TestWorkerPrunesClosureDeps3366=== CONT TestQueueRemoveLargeClosure3367=== CONT TestDrainTimeout3368=== CONT TestWorkerSkipsGCdPaths3369=== CONT TestQueueConcurrentWriters3370=== CONT TestQueueDeduplication33712026/10/01 10:23:04 ERROR Failed to queue paths error="permission denied" count=13372--- PASS: TestServerQueueError (0.00s)3373=== CONT TestQueueFetchRemoveLifecycle33742026/10/01 10:23:04 INFO Upload queue status pending=233752026/10/01 10:23:04 INFO Upload queue status pending=233762026/10/01 10:23:04 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-32041-4233760698/TestWorkerSkipsGCdPaths1096449717/002/nonexistent3377--- PASS: TestQueueFetchBatchLimit (0.01s)3378=== CONT TestQueueEnqueueAndFetch33792026/10/01 10:23:04 INFO Upload queue status pending=233802026/10/01 10:23:04 INFO Uploading batch count=133812026/10/01 10:23:04 INFO Uploading batch count=23382--- PASS: TestQueueFetchRemoveLifecycle (0.01s)3383=== CONT TestDrainGivesUpWhenServerDown33842026/10/01 10:23:04 INFO Uploading batch count=133852026/10/01 10:23:04 INFO Uploading batch count=23386--- PASS: TestQueueRetryMovesToBack (0.01s)3387=== CONT TestFailedPathPrunedByLaterClosure3388--- PASS: TestQueueDeduplication (0.01s)3389=== CONT TestServerClientIntegration3390--- PASS: TestServerClientIntegration (0.00s)3391=== CONT TestQueueRemove33922026/10/01 10:23:04 INFO Uploading batch count=133932026/10/01 10:23:04 ERROR Upload failed error="upload failed" count=13394--- PASS: TestQueueEnqueueAndFetch (0.00s)3395=== CONT TestRunNotBlockedByPoisonHead33962026/10/01 10:23:04 INFO Uploading batch count=133972026/10/01 10:23:04 INFO Uploading batch count=133982026/10/01 10:23:04 INFO Uploading batch count=233992026/10/01 10:23:04 ERROR Upload failed error="upload failed" count=234002026/10/01 10:23:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-32041-4233760698/TestDrainGivesUpWhenServerDown3873731469/002/a34012026/10/01 10:23:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-32041-4233760698/TestDrainGivesUpWhenServerDown3873731469/002/b34022026/10/01 10:23:04 INFO Uploading batch count=234032026/10/01 10:23:04 ERROR Upload failed error="upload failed" count=234042026/10/01 10:23:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-32041-4233760698/TestDrainGivesUpWhenServerDown3873731469/002/c34052026/10/01 10:23:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-32041-4233760698/TestDrainGivesUpWhenServerDown3873731469/002/d34062026/10/01 10:23:04 INFO Uploading batch count=234072026/10/01 10:23:04 ERROR Upload failed error="upload failed" count=234082026/10/01 10:23:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-32041-4233760698/TestDrainGivesUpWhenServerDown3873731469/002/e34092026/10/01 10:23:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-32041-4233760698/TestDrainGivesUpWhenServerDown3873731469/002/f3410--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)3411=== CONT TestDrainIsolatesPoisonPath3412--- PASS: TestQueueRemove (0.00s)34132026/10/01 10:23:04 ERROR Drain finished with paths left in queue remaining=1034142026/10/01 10:23:04 INFO Upload queue status pending=334152026/10/01 10:23:04 INFO Uploading batch count=134162026/10/01 10:23:04 ERROR Upload failed error="upload failed" count=13417--- PASS: TestDrainGivesUpWhenServerDown (0.01s)34182026/10/01 10:23:04 INFO Uploading batch count=434192026/10/01 10:23:04 ERROR Upload failed error="upload failed" count=434202026/10/01 10:23:04 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-32041-4233760698/TestDrainIsolatesPoisonPath1609671693/002/bbb34212026/10/01 10:23:04 INFO Uploading batch count=134222026/10/01 10:23:04 ERROR Upload failed error="upload failed" count=134232026/10/01 10:23:04 INFO Uploading batch count=134242026/10/01 10:23:04 ERROR Upload failed error="upload failed" count=134252026/10/01 10:23:04 INFO Uploading batch count=134262026/10/01 10:23:04 ERROR Upload failed error="upload failed" count=134272026/10/01 10:23:04 ERROR Drain finished with paths left in queue remaining=13428--- PASS: TestDrainIsolatesPoisonPath (0.00s)3429--- PASS: TestWorkerPrunesClosureDeps (0.03s)3430--- PASS: TestWorkerUploadsAndRemoves (0.03s)3431--- PASS: TestWorkerSkipsGCdPaths (0.03s)3432--- PASS: TestQueueRemoveLargeClosure (0.05s)3433--- PASS: TestQueueConcurrentWriters (0.15s)34342026/10/01 10:23:04 ERROR Upload failed error="context deadline exceeded" count=234352026/10/01 10:23:04 ERROR Drain finished with paths left in queue remaining=43436--- PASS: TestDrainTimeout (0.21s)34372026/10/01 10:23:05 INFO Uploading batch count=134382026/10/01 10:23:05 INFO Uploading batch count=134392026/10/01 10:23:05 INFO Uploading batch count=134402026/10/01 10:23:05 ERROR Upload failed error="upload failed" count=134412026/10/01 10:23:05 INFO Uploading batch count=134422026/10/01 10:23:05 ERROR Upload failed error="upload failed" count=134432026/10/01 10:23:05 INFO Uploading batch count=134442026/10/01 10:23:05 ERROR Upload failed error="upload failed" count=134452026/10/01 10:23:05 INFO Uploading batch count=134462026/10/01 10:23:05 ERROR Upload failed error="upload failed" count=134472026/10/01 10:23:05 ERROR Drain finished with paths left in queue remaining=13448--- PASS: TestRunNotBlockedByPoisonHead (1.01s)3449PASS