nixbot

1this derivation will be built:2  /nix/store/dmify7hbzj7a61m5im43kybbdrpyp0nn-niks3-go-unit-tests.drv3building '/nix/store/dmify7hbzj7a61m5im43kybbdrpyp0nn-niks3-go-unit-tests.drv' on 'ssh-ng://customer@mac02'4building '/nix/store/dmify7hbzj7a61m5im43kybbdrpyp0nn-niks3-go-unit-tests.drv'5niks3-go-unit-tests> Running client tests...6niks3-go-unit-tests> === RUN   TestDoServerRequestAttachesToken7niks3-go-unit-tests> === PAUSE TestDoServerRequestAttachesToken8niks3-go-unit-tests> === RUN   TestCaseHackSuffix9niks3-go-unit-tests> === PAUSE TestCaseHackSuffix10niks3-go-unit-tests> === RUN   TestFilterOversizedClosures11niks3-go-unit-tests> === PAUSE TestFilterOversizedClosures12niks3-go-unit-tests> === RUN   TestPartSizeForNAR13niks3-go-unit-tests> === PAUSE TestPartSizeForNAR14niks3-go-unit-tests> === RUN   TestUploadMultipart_SupersededByPeer15niks3-go-unit-tests> === PAUSE TestUploadMultipart_SupersededByPeer16niks3-go-unit-tests> === RUN   TestDumpPathCaseHackMatchesNix17niks3-go-unit-tests> --- PASS: TestDumpPathCaseHackMatchesNix (10.53s)18niks3-go-unit-tests> === RUN   TestDumpPathCaseHackCollision19niks3-go-unit-tests> --- PASS: TestDumpPathCaseHackCollision (0.00s)20niks3-go-unit-tests> === RUN   TestDumpPathMatchesNix21niks3-go-unit-tests> === PAUSE TestDumpPathMatchesNix22niks3-go-unit-tests> === RUN   TestDumpPathSingleFile23niks3-go-unit-tests> === PAUSE TestDumpPathSingleFile24niks3-go-unit-tests> === RUN   TestDumpPathWriterError25niks3-go-unit-tests> === PAUSE TestDumpPathWriterError26niks3-go-unit-tests> === RUN   TestEncodeNixBase3227niks3-go-unit-tests> === PAUSE TestEncodeNixBase3228niks3-go-unit-tests> === RUN   TestEncodeNixBase32WithRealHash29niks3-go-unit-tests> === PAUSE TestEncodeNixBase32WithRealHash30niks3-go-unit-tests> === RUN   TestConvertHashToNix3231niks3-go-unit-tests> === PAUSE TestConvertHashToNix3232niks3-go-unit-tests> === RUN   TestGetStorePathHash33niks3-go-unit-tests> === PAUSE TestGetStorePathHash34niks3-go-unit-tests> === RUN   TestPathInfoHashCompatibility35niks3-go-unit-tests> === PAUSE TestPathInfoHashCompatibility36niks3-go-unit-tests> === RUN   TestParsePathInfoJSON37niks3-go-unit-tests> === PAUSE TestParsePathInfoJSON38niks3-go-unit-tests> === RUN   TestParsePathInfoJSONMultiplePaths39niks3-go-unit-tests> === PAUSE TestParsePathInfoJSONMultiplePaths40niks3-go-unit-tests> === RUN   TestPathInfoCACompatibility41niks3-go-unit-tests> === PAUSE TestPathInfoCACompatibility42niks3-go-unit-tests> === RUN   TestRateLimiterFeedback43niks3-go-unit-tests> === PAUSE TestRateLimiterFeedback44niks3-go-unit-tests> === RUN   TestRateLimiterFeedback_400DoesNotCountAsSuccess45niks3-go-unit-tests> === PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46niks3-go-unit-tests> === RUN   TestResolveStorePath47niks3-go-unit-tests> === PAUSE TestResolveStorePath48niks3-go-unit-tests> === RUN   TestDoWithRetry_BodyReplayedViaGetBody49niks3-go-unit-tests> === PAUSE TestDoWithRetry_BodyReplayedViaGetBody50niks3-go-unit-tests> === RUN   TestShellSplit51niks3-go-unit-tests> === PAUSE TestShellSplit52niks3-go-unit-tests> === RUN   TestShellSplitErrors53niks3-go-unit-tests> === PAUSE TestShellSplitErrors54niks3-go-unit-tests> === RUN   TestStreamPushReportsEveryPath55niks3-go-unit-tests> === PAUSE TestStreamPushReportsEveryPath56niks3-go-unit-tests> === RUN   TestStreamPushBatchesUnderLoad57niks3-go-unit-tests> === PAUSE TestStreamPushBatchesUnderLoad58niks3-go-unit-tests> === RUN   TestStreamPushIsolatesFailures59niks3-go-unit-tests> === PAUSE TestStreamPushIsolatesFailures60niks3-go-unit-tests> === RUN   TestStreamPushGivesUpOnDeadServer61niks3-go-unit-tests> === PAUSE TestStreamPushGivesUpOnDeadServer62niks3-go-unit-tests> === RUN   TestStreamPushRequestLine63niks3-go-unit-tests> === PAUSE TestStreamPushRequestLine64niks3-go-unit-tests> === RUN   TestSetClientTLS65niks3-go-unit-tests> === PAUSE TestSetClientTLS66niks3-go-unit-tests> === RUN   TestSetClientTLSDoesNotMutateDefaultTransport67niks3-go-unit-tests> === PAUSE TestSetClientTLSDoesNotMutateDefaultTransport68niks3-go-unit-tests> === RUN   TestSetClientTLSErrors69niks3-go-unit-tests> === PAUSE TestSetClientTLSErrors70niks3-go-unit-tests> === RUN   TestStaticToken71niks3-go-unit-tests> === PAUSE TestStaticToken72niks3-go-unit-tests> === RUN   TestFileTokenReadsAndCaches73niks3-go-unit-tests> === PAUSE TestFileTokenReadsAndCaches74niks3-go-unit-tests> === RUN   TestFileTokenMissing75niks3-go-unit-tests> === PAUSE TestFileTokenMissing76niks3-go-unit-tests> === RUN   TestFileTokenEmpty77niks3-go-unit-tests> === PAUSE TestFileTokenEmpty78niks3-go-unit-tests> === RUN   TestScriptTokenNoExpiryRerunsEveryCall79niks3-go-unit-tests> === PAUSE TestScriptTokenNoExpiryRerunsEveryCall80niks3-go-unit-tests> === RUN   TestScriptTokenCachesUntilRefresh81niks3-go-unit-tests> === PAUSE TestScriptTokenCachesUntilRefresh82niks3-go-unit-tests> === RUN   TestScriptTokenEmptyToken83niks3-go-unit-tests> === PAUSE TestScriptTokenEmptyToken84niks3-go-unit-tests> === RUN   TestScriptTokenBadJSON85niks3-go-unit-tests> === PAUSE TestScriptTokenBadJSON86niks3-go-unit-tests> === RUN   TestScriptTokenScriptFails87niks3-go-unit-tests> === PAUSE TestScriptTokenScriptFails88niks3-go-unit-tests> === RUN   TestScriptTokenEmptyCommand89niks3-go-unit-tests> === PAUSE TestScriptTokenEmptyCommand90niks3-go-unit-tests> === CONT  TestDoServerRequestAttachesToken91niks3-go-unit-tests> === CONT  TestConvertHashToNix3292niks3-go-unit-tests> === CONT  TestPathInfoCACompatibility93niks3-go-unit-tests> === RUN   TestConvertHashToNix32/SRI_format_to_Nix3294niks3-go-unit-tests> === PAUSE TestConvertHashToNix32/SRI_format_to_Nix3295niks3-go-unit-tests> === RUN   TestPathInfoCACompatibility/null_ca_field96niks3-go-unit-tests> === RUN   TestConvertHashToNix32/already_Nix32_format97niks3-go-unit-tests> === PAUSE TestConvertHashToNix32/already_Nix32_format98niks3-go-unit-tests> === RUN   TestConvertHashToNix32/invalid_format99niks3-go-unit-tests> === PAUSE TestConvertHashToNix32/invalid_format100niks3-go-unit-tests> === CONT  TestScriptTokenEmptyCommand101niks3-go-unit-tests> === CONT  TestFileTokenEmpty102niks3-go-unit-tests> === CONT  TestShellSplit103niks3-go-unit-tests> === CONT  TestScriptTokenBadJSON104niks3-go-unit-tests> === CONT  TestFileTokenReadsAndCaches105niks3-go-unit-tests> === CONT  TestScriptTokenEmptyToken106niks3-go-unit-tests> === CONT  TestScriptTokenCachesUntilRefresh107niks3-go-unit-tests> === CONT  TestStaticToken108niks3-go-unit-tests> === CONT  TestScriptTokenNoExpiryRerunsEveryCall109niks3-go-unit-tests> === PAUSE TestPathInfoCACompatibility/null_ca_field110niks3-go-unit-tests> === RUN   TestPathInfoCACompatibility/old_string_format_-_text111niks3-go-unit-tests> === PAUSE TestPathInfoCACompatibility/old_string_format_-_text112niks3-go-unit-tests> === RUN   TestPathInfoCACompatibility/old_string_format_-_fixed_recursive113niks3-go-unit-tests> === PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive114niks3-go-unit-tests> --- PASS: TestScriptTokenEmptyCommand (0.00s)115niks3-go-unit-tests> === CONT  TestFileTokenMissing116niks3-go-unit-tests> === CONT  TestScriptTokenScriptFails117niks3-go-unit-tests> === CONT  TestSetClientTLSErrors118niks3-go-unit-tests> === RUN   TestPathInfoCACompatibility/new_structured_format_-_text119niks3-go-unit-tests> --- PASS: TestShellSplit (0.00s)120niks3-go-unit-tests> --- PASS: TestFileTokenEmpty (0.00s)121niks3-go-unit-tests> --- PASS: TestStaticToken (0.00s)122niks3-go-unit-tests> --- PASS: TestFileTokenMissing (0.00s)123niks3-go-unit-tests> --- PASS: TestFileTokenReadsAndCaches (0.00s)124niks3-go-unit-tests> === CONT  TestSetClientTLSDoesNotMutateDefaultTransport125niks3-go-unit-tests> === CONT  TestSetClientTLS126niks3-go-unit-tests> === PAUSE TestPathInfoCACompatibility/new_structured_format_-_text127niks3-go-unit-tests> === RUN   TestPathInfoCACompatibility/new_structured_format_-_nar_method128niks3-go-unit-tests> === PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method129niks3-go-unit-tests> === CONT  TestStreamPushRequestLine130niks3-go-unit-tests> === RUN   TestSetClientTLSErrors/missing_cert_file131niks3-go-unit-tests> === PAUSE TestSetClientTLSErrors/missing_cert_file132niks3-go-unit-tests> === RUN   TestSetClientTLSErrors/missing_key_file133niks3-go-unit-tests> === PAUSE TestSetClientTLSErrors/missing_key_file134niks3-go-unit-tests> === RUN   TestSetClientTLSErrors/missing_ca_file135niks3-go-unit-tests> === PAUSE TestSetClientTLSErrors/missing_ca_file136niks3-go-unit-tests> === RUN   TestSetClientTLSErrors/invalid_ca_file137niks3-go-unit-tests> === PAUSE TestSetClientTLSErrors/invalid_ca_file138niks3-go-unit-tests> === CONT  TestStreamPushGivesUpOnDeadServer139niks3-go-unit-tests> 2026/09/18 13:10:55 ERROR Upload failed error="connection refused" count=20140niks3-go-unit-tests> 2026/09/18 13:10:55 ERROR Server seems unavailable, giving up on batch untried=17141niks3-go-unit-tests> 2026/09/18 13:10:55 ERROR Upload failed error="stale build claim" count=1142niks3-go-unit-tests> --- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)143niks3-go-unit-tests> === CONT  TestStreamPushIsolatesFailures144niks3-go-unit-tests> 2026/09/18 13:10:55 ERROR Upload failed error="bad path" count=3145niks3-go-unit-tests> --- PASS: TestStreamPushIsolatesFailures (0.00s)146niks3-go-unit-tests> === CONT  TestStreamPushBatchesUnderLoad147niks3-go-unit-tests> --- PASS: TestDoServerRequestAttachesToken (0.01s)148niks3-go-unit-tests> === CONT  TestStreamPushReportsEveryPath149niks3-go-unit-tests> --- PASS: TestStreamPushReportsEveryPath (0.00s)150niks3-go-unit-tests> === CONT  TestShellSplitErrors151niks3-go-unit-tests> --- PASS: TestShellSplitErrors (0.00s)152niks3-go-unit-tests> === CONT  TestParsePathInfoJSON153niks3-go-unit-tests> === RUN   TestParsePathInfoJSON/Nix_format154niks3-go-unit-tests> === PAUSE TestParsePathInfoJSON/Nix_format155niks3-go-unit-tests> === RUN   TestParsePathInfoJSON/Lix_format156niks3-go-unit-tests> --- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)157niks3-go-unit-tests> === PAUSE TestParsePathInfoJSON/Lix_format158niks3-go-unit-tests> === RUN   TestParsePathInfoJSON/empty_input159niks3-go-unit-tests> === CONT  TestParsePathInfoJSONMultiplePaths160niks3-go-unit-tests> === PAUSE TestParsePathInfoJSON/empty_input161niks3-go-unit-tests> === RUN   TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths162niks3-go-unit-tests> === PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths163niks3-go-unit-tests> === RUN   TestParsePathInfoJSON/whitespace_only164niks3-go-unit-tests> === RUN   TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths165niks3-go-unit-tests> === PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths166niks3-go-unit-tests> === CONT  TestPathInfoHashCompatibility167niks3-go-unit-tests> === RUN   TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)168niks3-go-unit-tests> === PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)169niks3-go-unit-tests> === RUN   TestPathInfoHashCompatibility/old_string_format_with_colon170niks3-go-unit-tests> === PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon171niks3-go-unit-tests> === RUN   TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI172niks3-go-unit-tests> === PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI173niks3-go-unit-tests> === RUN   TestPathInfoHashCompatibility/new_structured_format_with_sha512174niks3-go-unit-tests> === PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512175niks3-go-unit-tests> === PAUSE TestParsePathInfoJSON/whitespace_only176niks3-go-unit-tests> === RUN   TestParsePathInfoJSON/invalid_JSON177niks3-go-unit-tests> === PAUSE TestParsePathInfoJSON/invalid_JSON178niks3-go-unit-tests> === CONT  TestDumpPathMatchesNix179niks3-go-unit-tests> === CONT  TestEncodeNixBase32WithRealHash180niks3-go-unit-tests> --- PASS: TestEncodeNixBase32WithRealHash (0.00s)181niks3-go-unit-tests> === CONT  TestEncodeNixBase32182niks3-go-unit-tests> === RUN   TestEncodeNixBase32/test_string_hash183niks3-go-unit-tests> === PAUSE TestEncodeNixBase32/test_string_hash184niks3-go-unit-tests> === RUN   TestEncodeNixBase32/empty_input185niks3-go-unit-tests> === PAUSE TestEncodeNixBase32/empty_input186niks3-go-unit-tests> === CONT  TestDumpPathWriterError187niks3-go-unit-tests> === RUN   TestSetClientTLS/rejects_connection_without_client_cert188niks3-go-unit-tests> === PAUSE TestSetClientTLS/rejects_connection_without_client_cert189niks3-go-unit-tests> === RUN   TestSetClientTLS/succeeds_with_client_cert_and_CA190niks3-go-unit-tests> === PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA191niks3-go-unit-tests> === RUN   TestSetClientTLS/preserves_debug_logging_transport192niks3-go-unit-tests> === PAUSE TestSetClientTLS/preserves_debug_logging_transport193niks3-go-unit-tests> === CONT  TestDumpPathSingleFile194niks3-go-unit-tests> --- PASS: TestScriptTokenScriptFails (0.01s)195niks3-go-unit-tests> === CONT  TestGetStorePathHash196niks3-go-unit-tests> === RUN   TestGetStorePathHash/valid_store_path197niks3-go-unit-tests> === PAUSE TestGetStorePathHash/valid_store_path198niks3-go-unit-tests> === RUN   TestGetStorePathHash/basename_without_hyphen_should_error199niks3-go-unit-tests> === PAUSE TestGetStorePathHash/basename_without_hyphen_should_error200niks3-go-unit-tests> === RUN   TestGetStorePathHash/hash_with_invalid_characters_should_error201niks3-go-unit-tests> === PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error202niks3-go-unit-tests> === RUN   TestGetStorePathHash/hash_with_wrong_length_should_error203niks3-go-unit-tests> === PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error204niks3-go-unit-tests> === CONT  TestResolveStorePath205niks3-go-unit-tests> === CONT  TestRateLimiterFeedback_400DoesNotCountAsSuccess206niks3-go-unit-tests> --- PASS: TestResolveStorePath (0.00s)207niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Rate limiter enabled after throttle name=server-test rate=5208niks3-go-unit-tests> --- PASS: TestScriptTokenEmptyToken (0.01s)209niks3-go-unit-tests> === CONT  TestDoWithRetry_BodyReplayedViaGetBody210niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Rate limiter enabled after throttle name=server-test rate=5211niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:56992212niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Rate limiter backed off name=server-test rate=5213niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:56992214niks3-go-unit-tests> --- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)215niks3-go-unit-tests> === CONT  TestRateLimiterFeedback216niks3-go-unit-tests> === RUN   TestRateLimiterFeedback/429_enables_limiter217niks3-go-unit-tests> === PAUSE TestRateLimiterFeedback/429_enables_limiter218niks3-go-unit-tests> === RUN   TestRateLimiterFeedback/503_enables_limiter219niks3-go-unit-tests> === PAUSE TestRateLimiterFeedback/503_enables_limiter220niks3-go-unit-tests> === RUN   TestRateLimiterFeedback/200_does_not_enable_limiter221niks3-go-unit-tests> === PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter222niks3-go-unit-tests> === RUN   TestRateLimiterFeedback/400_does_not_enable_limiter223niks3-go-unit-tests> === PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter224niks3-go-unit-tests> === CONT  TestPartSizeForNAR225niks3-go-unit-tests> --- PASS: TestScriptTokenBadJSON (0.01s)226niks3-go-unit-tests> === CONT  TestFilterOversizedClosures227niks3-go-unit-tests> === RUN   TestFilterOversizedClosures/no_limit_keeps_everything228niks3-go-unit-tests> === RUN   TestPartSizeForNAR/zero_stays_at_minimum229niks3-go-unit-tests> === PAUSE TestFilterOversizedClosures/no_limit_keeps_everything230niks3-go-unit-tests> === RUN   TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231niks3-go-unit-tests> === PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped232niks3-go-unit-tests> === RUN   TestFilterOversizedClosures/all_closures_skipped233niks3-go-unit-tests> === PAUSE TestPartSizeForNAR/zero_stays_at_minimum234niks3-go-unit-tests> === RUN   TestPartSizeForNAR/small_stays_at_minimum235niks3-go-unit-tests> === PAUSE TestFilterOversizedClosures/all_closures_skipped236niks3-go-unit-tests> === PAUSE TestPartSizeForNAR/small_stays_at_minimum237niks3-go-unit-tests> === RUN   TestPartSizeForNAR/80_GiB_fits_at_minimum238niks3-go-unit-tests> === PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum239niks3-go-unit-tests> === RUN   TestPartSizeForNAR/115_GiB_needs_larger_parts240niks3-go-unit-tests> === PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts241niks3-go-unit-tests> === RUN   TestPartSizeForNAR/1_TiB242niks3-go-unit-tests> === PAUSE TestPartSizeForNAR/1_TiB243niks3-go-unit-tests> === RUN   TestPartSizeForNAR/5_TiB_S3_max_object244niks3-go-unit-tests> === PAUSE TestPartSizeForNAR/5_TiB_S3_max_object245niks3-go-unit-tests> === RUN   TestPartSizeForNAR/capped_at_5_GiB246niks3-go-unit-tests> === PAUSE TestPartSizeForNAR/capped_at_5_GiB247niks3-go-unit-tests> === CONT  TestUploadMultipart_SupersededByPeer248niks3-go-unit-tests> === RUN   TestUploadMultipart_SupersededByPeer/exists249niks3-go-unit-tests> === PAUSE TestUploadMultipart_SupersededByPeer/exists250niks3-go-unit-tests> === RUN   TestUploadMultipart_SupersededByPeer/missing251niks3-go-unit-tests> === PAUSE TestUploadMultipart_SupersededByPeer/missing252niks3-go-unit-tests> === CONT  TestCaseHackSuffix253niks3-go-unit-tests> === CONT  TestConvertHashToNix32/SRI_format_to_Nix32254niks3-go-unit-tests> === CONT  TestConvertHashToNix32/invalid_format255niks3-go-unit-tests> === CONT  TestConvertHashToNix32/already_Nix32_format256niks3-go-unit-tests> --- PASS: TestConvertHashToNix32 (0.00s)257niks3-go-unit-tests>     --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)258niks3-go-unit-tests>     --- PASS: TestConvertHashToNix32/invalid_format (0.00s)259niks3-go-unit-tests>     --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)260niks3-go-unit-tests> === CONT  TestPathInfoCACompatibility/null_ca_field261niks3-go-unit-tests> === CONT  TestPathInfoCACompatibility/new_structured_format_-_text262niks3-go-unit-tests> === CONT  TestPathInfoCACompatibility/new_structured_format_-_nar_method263niks3-go-unit-tests> === CONT  TestPathInfoCACompatibility/old_string_format_-_fixed_recursive264niks3-go-unit-tests> === CONT  TestPathInfoCACompatibility/old_string_format_-_text265niks3-go-unit-tests> --- PASS: TestPathInfoCACompatibility (0.00s)266niks3-go-unit-tests>     --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)267niks3-go-unit-tests>     --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)268niks3-go-unit-tests>     --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)269niks3-go-unit-tests>     --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)270niks3-go-unit-tests>     --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)271niks3-go-unit-tests> === CONT  TestSetClientTLSErrors/missing_cert_file272niks3-go-unit-tests> === CONT  TestSetClientTLSErrors/invalid_ca_file273niks3-go-unit-tests> === CONT  TestSetClientTLSErrors/missing_ca_file274niks3-go-unit-tests> === CONT  TestSetClientTLSErrors/missing_key_file275niks3-go-unit-tests> === CONT  TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths276niks3-go-unit-tests> === CONT  TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths277niks3-go-unit-tests> --- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)278niks3-go-unit-tests>     --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)279niks3-go-unit-tests>     --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)280niks3-go-unit-tests> === CONT  TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)281niks3-go-unit-tests> === CONT  TestParsePathInfoJSON/Nix_format282niks3-go-unit-tests> === CONT  TestEncodeNixBase32/test_string_hash283niks3-go-unit-tests> === CONT  TestPathInfoHashCompatibility/new_structured_format_with_sha512284niks3-go-unit-tests> === CONT  TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI285niks3-go-unit-tests> === CONT  TestPathInfoHashCompatibility/old_string_format_with_colon286niks3-go-unit-tests> --- PASS: TestPathInfoHashCompatibility (0.00s)287niks3-go-unit-tests>     --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)288niks3-go-unit-tests>     --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)289niks3-go-unit-tests>     --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)290niks3-go-unit-tests>     --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)291niks3-go-unit-tests> === CONT  TestParsePathInfoJSON/whitespace_only292niks3-go-unit-tests> === CONT  TestParsePathInfoJSON/invalid_JSON293niks3-go-unit-tests> === CONT  TestParsePathInfoJSON/empty_input294niks3-go-unit-tests> === CONT  TestEncodeNixBase32/empty_input295niks3-go-unit-tests> --- PASS: TestEncodeNixBase32 (0.00s)296niks3-go-unit-tests>     --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)297niks3-go-unit-tests>     --- PASS: TestEncodeNixBase32/empty_input (0.00s)298niks3-go-unit-tests> === CONT  TestParsePathInfoJSON/Lix_format299niks3-go-unit-tests> --- PASS: TestParsePathInfoJSON (0.00s)300niks3-go-unit-tests>     --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)301niks3-go-unit-tests>     --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)302niks3-go-unit-tests>     --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)303niks3-go-unit-tests>     --- PASS: TestParsePathInfoJSON/empty_input (0.00s)304niks3-go-unit-tests>     --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)305niks3-go-unit-tests> --- PASS: TestSetClientTLSErrors (0.01s)306niks3-go-unit-tests>     --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)307niks3-go-unit-tests>     --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)308niks3-go-unit-tests>     --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)309niks3-go-unit-tests>     --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)310niks3-go-unit-tests> === CONT  TestSetClientTLS/rejects_connection_without_client_cert311niks3-go-unit-tests> --- PASS: TestStreamPushRequestLine (0.01s)312niks3-go-unit-tests> === CONT  TestSetClientTLS/preserves_debug_logging_transport313niks3-go-unit-tests> === CONT  TestSetClientTLS/succeeds_with_client_cert_and_CA314niks3-go-unit-tests> === CONT  TestGetStorePathHash/valid_store_path315niks3-go-unit-tests> === CONT  TestGetStorePathHash/hash_with_invalid_characters_should_error316niks3-go-unit-tests> === CONT  TestGetStorePathHash/hash_with_wrong_length_should_error317niks3-go-unit-tests> === CONT  TestGetStorePathHash/basename_without_hyphen_should_error318niks3-go-unit-tests> --- PASS: TestGetStorePathHash (0.00s)319niks3-go-unit-tests>     --- PASS: TestGetStorePathHash/valid_store_path (0.00s)320niks3-go-unit-tests>     --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)321niks3-go-unit-tests>     --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)322niks3-go-unit-tests>     --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)323niks3-go-unit-tests> === CONT  TestRateLimiterFeedback/429_enables_limiter324niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Rate limiter enabled after throttle name=server-test rate=5325niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:56997326niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Rate limiter backed off name=server-test rate=5327niks3-go-unit-tests> === CONT  TestRateLimiterFeedback/200_does_not_enable_limiter328niks3-go-unit-tests> === CONT  TestRateLimiterFeedback/400_does_not_enable_limiter329niks3-go-unit-tests> === CONT  TestRateLimiterFeedback/503_enables_limiter330niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Rate limiter enabled after throttle name=server-test rate=5331niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:57003332niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Rate limiter backed off name=server-test rate=5333niks3-go-unit-tests> === CONT  TestFilterOversizedClosures/no_limit_keeps_everything334niks3-go-unit-tests> === CONT  TestFilterOversizedClosures/all_closures_skipped335niks3-go-unit-tests> 2026/09/18 13:10:55 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=50336niks3-go-unit-tests> --- PASS: TestRateLimiterFeedback (0.00s)337niks3-go-unit-tests>     --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)338niks3-go-unit-tests>     --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)339niks3-go-unit-tests>     --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)340niks3-go-unit-tests>     --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)341niks3-go-unit-tests> === CONT  TestPartSizeForNAR/zero_stays_at_minimum342niks3-go-unit-tests> === CONT  TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped343niks3-go-unit-tests> 2026/09/18 13:10:55 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000344niks3-go-unit-tests> --- PASS: TestFilterOversizedClosures (0.00s)345niks3-go-unit-tests>     --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)346niks3-go-unit-tests>     --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)347niks3-go-unit-tests>     --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)348niks3-go-unit-tests> === CONT  TestPartSizeForNAR/capped_at_5_GiB349niks3-go-unit-tests> === CONT  TestPartSizeForNAR/5_TiB_S3_max_object350niks3-go-unit-tests> === CONT  TestPartSizeForNAR/1_TiB351niks3-go-unit-tests> === CONT  TestPartSizeForNAR/115_GiB_needs_larger_parts352niks3-go-unit-tests> === CONT  TestPartSizeForNAR/80_GiB_fits_at_minimum353niks3-go-unit-tests> === CONT  TestPartSizeForNAR/small_stays_at_minimum354niks3-go-unit-tests> --- PASS: TestPartSizeForNAR (0.00s)355niks3-go-unit-tests>     --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)356niks3-go-unit-tests>     --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)357niks3-go-unit-tests>     --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)358niks3-go-unit-tests>     --- PASS: TestPartSizeForNAR/1_TiB (0.00s)359niks3-go-unit-tests>     --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)360niks3-go-unit-tests>     --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)361niks3-go-unit-tests>     --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)362niks3-go-unit-tests> === CONT  TestUploadMultipart_SupersededByPeer/exists363niks3-go-unit-tests> === CONT  TestUploadMultipart_SupersededByPeer/missing364niks3-go-unit-tests> --- PASS: TestUploadMultipart_SupersededByPeer (0.00s)365niks3-go-unit-tests>     --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)366niks3-go-unit-tests>     --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)367niks3-go-unit-tests> --- PASS: TestScriptTokenCachesUntilRefresh (0.03s)368niks3-go-unit-tests> --- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)369niks3-go-unit-tests> 2026/09/18 13:10:55 http: TLS handshake error from 127.0.0.1:56994: remote error: tls: bad certificate370niks3-go-unit-tests> --- PASS: TestSetClientTLS (0.01s)371niks3-go-unit-tests>     --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)372niks3-go-unit-tests>     --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)373niks3-go-unit-tests>     --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)374niks3-go-unit-tests> --- PASS: TestDumpPathWriterError (0.03s)375niks3-go-unit-tests> --- PASS: TestDumpPathSingleFile (0.05s)376niks3-go-unit-tests> --- PASS: TestCaseHackSuffix (0.04s)377niks3-go-unit-tests> --- PASS: TestDumpPathMatchesNix (0.07s)378niks3-go-unit-tests> --- PASS: TestStreamPushBatchesUnderLoad (0.10s)379niks3-go-unit-tests> --- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)380niks3-go-unit-tests> PASS381niks3-go-unit-tests> Running server tests...382niks3-go-unit-tests> The files belonging to this database system will be owned by user "_nixbld1".383niks3-go-unit-tests> This user must also own the server process.384niks3-go-unit-tests> 385niks3-go-unit-tests> The database cluster will be initialized with locale "C".386niks3-go-unit-tests> The default database encoding has accordingly been set to "SQL_ASCII".387niks3-go-unit-tests> The default text search configuration will be set to "english".388niks3-go-unit-tests> 389niks3-go-unit-tests> Data page checksums are enabled.390niks3-go-unit-tests> 391niks3-go-unit-tests> creating directory /nix/var/nix/builds/nix-80273-1366931373/postgres1601625091/data ... ok392niks3-go-unit-tests> creating subdirectories ... ok393niks3-go-unit-tests> selecting dynamic shared memory implementation ... posix394niks3-go-unit-tests> selecting default "max_connections" ... 100395niks3-go-unit-tests> selecting default "shared_buffers" ... 128MB396niks3-go-unit-tests> selecting default time zone ... UTC397niks3-go-unit-tests> creating configuration files ... ok398niks3-go-unit-tests> running bootstrap script ... ok399niks3-go-unit-tests> performing post-bootstrap initialization ... ok400niks3-go-unit-tests> syncing data to disk ... ok401niks3-go-unit-tests> 402niks3-go-unit-tests> initdb: warning: enabling "trust" authentication for local connections403niks3-go-unit-tests> initdb: 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.404niks3-go-unit-tests> 405niks3-go-unit-tests> Success. You can now start the database server using:406niks3-go-unit-tests> 407niks3-go-unit-tests>     pg_ctl -D /nix/var/nix/builds/nix-80273-1366931373/postgres1601625091/data -l logfile start408niks3-go-unit-tests> 409niks3-go-unit-tests> 2026-09-18 13:10:58.611 UTC [80421] LOG:  starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit410niks3-go-unit-tests> 2026-09-18 13:10:58.611 UTC [80421] LOG:  listening on Unix socket "/nix/var/nix/builds/nix-80273-1366931373/postgres1601625091/.s.PGSQL.5432"411niks3-go-unit-tests> 2026-09-18 13:10:58.613 UTC [80428] LOG:  database system was shut down at 2026-09-18 13:10:58 UTC412niks3-go-unit-tests> 2026-09-18 13:10:58.614 UTC [80421] LOG:  database system is ready to accept connections413niks3-go-unit-tests> /nix/var/nix/builds/nix-80273-1366931373/postgres1601625091:5432 - accepting connections414niks3-go-unit-tests> === RUN   TestService_AuthMiddleware415niks3-go-unit-tests> === PAUSE TestService_AuthMiddleware416niks3-go-unit-tests> === RUN   TestService_AuthMiddleware_MTLSProxyHeader417niks3-go-unit-tests> === PAUSE TestService_AuthMiddleware_MTLSProxyHeader418niks3-go-unit-tests> === RUN   TestService_AuthMiddleware_MTLSBoundSubjects419niks3-go-unit-tests> === PAUSE TestService_AuthMiddleware_MTLSBoundSubjects420niks3-go-unit-tests> === RUN   TestService_ReadAuthMiddleware421niks3-go-unit-tests> === PAUSE TestService_ReadAuthMiddleware422niks3-go-unit-tests> === RUN   TestService_AuthMiddleware_OIDC423niks3-go-unit-tests> === PAUSE TestService_AuthMiddleware_OIDC424niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC425niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC426niks3-go-unit-tests> === RUN   TestService_ReadScope_PublicByDefault427niks3-go-unit-tests> === PAUSE TestService_ReadScope_PublicByDefault428niks3-go-unit-tests> === RUN   TestCacheConfigHandler429niks3-go-unit-tests> === PAUSE TestCacheConfigHandler430niks3-go-unit-tests> === RUN   TestCacheStatsHandler431niks3-go-unit-tests> === PAUSE TestCacheStatsHandler432niks3-go-unit-tests> === RUN   TestClaim_BuildWaitComplete433niks3-go-unit-tests> === PAUSE TestClaim_BuildWaitComplete434niks3-go-unit-tests> === RUN   TestClaim_GCMarkedOutputCountsAsAbsent435niks3-go-unit-tests> === PAUSE TestClaim_GCMarkedOutputCountsAsAbsent436niks3-go-unit-tests> === RUN   TestClaim_TooManyStreams437niks3-go-unit-tests> === PAUSE TestClaim_TooManyStreams438niks3-go-unit-tests> === RUN   TestClaim_HolderDisconnectKeepsClaim439niks3-go-unit-tests> === PAUSE TestClaim_HolderDisconnectKeepsClaim440niks3-go-unit-tests> === RUN   TestClaim_FailWakesWaitersButIsNotRemembered441niks3-go-unit-tests> === PAUSE TestClaim_FailWakesWaitersButIsNotRemembered442niks3-go-unit-tests> === RUN   TestClaim_FailWithoutKindReleases443niks3-go-unit-tests> === PAUSE TestClaim_FailWithoutKindReleases444niks3-go-unit-tests> === RUN   TestClaim_StaleHeartbeatStolen445niks3-go-unit-tests> === PAUSE TestClaim_StaleHeartbeatStolen446niks3-go-unit-tests> === RUN   TestClaim_TwoInstances447niks3-go-unit-tests> === PAUSE TestClaim_TwoInstances448niks3-go-unit-tests> === RUN   TestClaim_InputsTouched449niks3-go-unit-tests> === PAUSE TestClaim_InputsTouched450niks3-go-unit-tests> === RUN   TestClaim_StreamsThroughServer451niks3-go-unit-tests> === PAUSE TestClaim_StreamsThroughServer452niks3-go-unit-tests> === RUN   TestPresent453niks3-go-unit-tests> === PAUSE TestPresent454niks3-go-unit-tests> === RUN   TestClientCADerivations455niks3-go-unit-tests> === PAUSE TestClientCADerivations456niks3-go-unit-tests> === RUN   TestClientErrorHandling457niks3-go-unit-tests> === PAUSE TestClientErrorHandling458niks3-go-unit-tests> === RUN   TestClientIntegration459niks3-go-unit-tests> === PAUSE TestClientIntegration460niks3-go-unit-tests> === RUN   TestClientMultipleUploads461niks3-go-unit-tests> === PAUSE TestClientMultipleUploads462niks3-go-unit-tests> === RUN   TestClientWithDependencies463niks3-go-unit-tests> === PAUSE TestClientWithDependencies464niks3-go-unit-tests> === RUN   TestPinProtectsFromGC465niks3-go-unit-tests> === PAUSE TestPinProtectsFromGC466niks3-go-unit-tests> === RUN   TestResolveDBConnectionString467niks3-go-unit-tests> === PAUSE TestResolveDBConnectionString468niks3-go-unit-tests> === RUN   TestGCAdvisoryLockBlocksConcurrentRun469niks3-go-unit-tests> 2026-09-18 13:11:00.994 UTC [80502] ERROR:  relation "goose_db_version" does not exist at character 36470niks3-go-unit-tests> 2026-09-18 13:11:00.994 UTC [80502] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC471niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (3.84ms)472niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (517.21µs)473niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (896.58µs)474niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (858.67µs)475niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (932.04µs)476niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000477niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (954.42µs)478niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (195.5µs)479niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2480niks3-go-unit-tests> --- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.36s)481niks3-go-unit-tests> === RUN   TestGCBugBareHashReferences482niks3-go-unit-tests> === PAUSE TestGCBugBareHashReferences483niks3-go-unit-tests> === RUN   TestGCMetrics484niks3-go-unit-tests> === PAUSE TestGCMetrics485niks3-go-unit-tests> === RUN   TestGCTaskStore_StartNew486niks3-go-unit-tests> === PAUSE TestGCTaskStore_StartNew487niks3-go-unit-tests> === RUN   TestGCTaskStore_DeduplicateSameParams488niks3-go-unit-tests> === PAUSE TestGCTaskStore_DeduplicateSameParams489niks3-go-unit-tests> === RUN   TestGCTaskStore_ConflictDifferentParams490niks3-go-unit-tests> === PAUSE TestGCTaskStore_ConflictDifferentParams491niks3-go-unit-tests> === RUN   TestGCTaskStore_GetEmpty492niks3-go-unit-tests> === PAUSE TestGCTaskStore_GetEmpty493niks3-go-unit-tests> === RUN   TestGCTaskStore_GetReturnsLatest494niks3-go-unit-tests> === PAUSE TestGCTaskStore_GetReturnsLatest495niks3-go-unit-tests> === RUN   TestGCTaskStore_CompletedAllowsNewTask496niks3-go-unit-tests> === PAUSE TestGCTaskStore_CompletedAllowsNewTask497niks3-go-unit-tests> === RUN   TestGCTaskStore_PhaseUpdates498niks3-go-unit-tests> === PAUSE TestGCTaskStore_PhaseUpdates499niks3-go-unit-tests> === RUN   TestGCTaskStore_Fail500niks3-go-unit-tests> === PAUSE TestGCTaskStore_Fail501niks3-go-unit-tests> === RUN   TestGracefulShutdownDrainsInflight502niks3-go-unit-tests> === PAUSE TestGracefulShutdownDrainsInflight503niks3-go-unit-tests> === RUN   TestService_healthCheckHandler504niks3-go-unit-tests> === PAUSE TestService_healthCheckHandler505niks3-go-unit-tests> === RUN   TestService_readinessHandler506niks3-go-unit-tests> === PAUSE TestService_readinessHandler507niks3-go-unit-tests> === RUN   TestGenerateLandingPage508niks3-go-unit-tests> === PAUSE TestGenerateLandingPage509niks3-go-unit-tests> === RUN   TestCacheConfigHandlerMaxNarSize510niks3-go-unit-tests> === PAUSE TestCacheConfigHandlerMaxNarSize511niks3-go-unit-tests> === RUN   TestCreatePendingClosureRejectsOversizedNAR512niks3-go-unit-tests> === PAUSE TestCreatePendingClosureRejectsOversizedNAR513niks3-go-unit-tests> === RUN   TestNARDeduplicationMetadataUploadBug514niks3-go-unit-tests> === PAUSE TestNARDeduplicationMetadataUploadBug515niks3-go-unit-tests> === RUN   TestMetricsInventory516niks3-go-unit-tests> === PAUSE TestMetricsInventory517niks3-go-unit-tests> === RUN   TestService_NativeMTLS518niks3-go-unit-tests> === PAUSE TestService_NativeMTLS519niks3-go-unit-tests> === RUN   TestServerTLSConfig520niks3-go-unit-tests> === PAUSE TestServerTLSConfig521niks3-go-unit-tests> === RUN   TestMultipartCleanup522niks3-go-unit-tests> === PAUSE TestMultipartCleanup523niks3-go-unit-tests> === RUN   TestObjectStatsTrigger524niks3-go-unit-tests> === PAUSE TestObjectStatsTrigger525niks3-go-unit-tests> === RUN   TestOrphanedObjectsGC526niks3-go-unit-tests> === PAUSE TestOrphanedObjectsGC527niks3-go-unit-tests> === RUN   TestOrphanedObjectsGCStressTest528niks3-go-unit-tests> === PAUSE TestOrphanedObjectsGCStressTest529niks3-go-unit-tests> === RUN   TestResurrectedObjectNotDeleted530niks3-go-unit-tests> === PAUSE TestResurrectedObjectNotDeleted531niks3-go-unit-tests> === RUN   TestParseSingleRange532niks3-go-unit-tests> === PAUSE TestParseSingleRange533niks3-go-unit-tests> === RUN   TestIsValidCachePath534niks3-go-unit-tests> === PAUSE TestIsValidCachePath535niks3-go-unit-tests> === RUN   TestReadProxyNarinfo536niks3-go-unit-tests> === PAUSE TestReadProxyNarinfo537niks3-go-unit-tests> === RUN   TestReadProxyNarinfoAlreadyDecompressed538niks3-go-unit-tests> === PAUSE TestReadProxyNarinfoAlreadyDecompressed539niks3-go-unit-tests> === RUN   TestReadProxyNarStreaming540niks3-go-unit-tests> === PAUSE TestReadProxyNarStreaming541niks3-go-unit-tests> === RUN   TestReadProxy404542niks3-go-unit-tests> === PAUSE TestReadProxy404543niks3-go-unit-tests> === RUN   TestReadProxyInvalidPath544niks3-go-unit-tests> === PAUSE TestReadProxyInvalidPath545niks3-go-unit-tests> === RUN   TestReadProxyHead546niks3-go-unit-tests> === PAUSE TestReadProxyHead547niks3-go-unit-tests> === RUN   TestReadProxyConditionalGet548niks3-go-unit-tests> === PAUSE TestReadProxyConditionalGet549niks3-go-unit-tests> === RUN   TestReadProxyRootRedirectsToIndexHTML550niks3-go-unit-tests> === PAUSE TestReadProxyRootRedirectsToIndexHTML551niks3-go-unit-tests> === RUN   TestReadProxyDisabled552niks3-go-unit-tests> === PAUSE TestReadProxyDisabled553niks3-go-unit-tests> === RUN   TestReadRedirectNar554niks3-go-unit-tests> === PAUSE TestReadRedirectNar555niks3-go-unit-tests> === RUN   TestReadRedirectKeepsNarinfoProxied556niks3-go-unit-tests> === PAUSE TestReadRedirectKeepsNarinfoProxied557niks3-go-unit-tests> === RUN   TestReadProxyRangeRequest558niks3-go-unit-tests> === PAUSE TestReadProxyRangeRequest559niks3-go-unit-tests> === RUN   TestReadRedirectUsesPublicS3URL560niks3-go-unit-tests> === PAUSE TestReadRedirectUsesPublicS3URL561niks3-go-unit-tests> === RUN   TestRedundantMultipartUpload562niks3-go-unit-tests> === PAUSE TestRedundantMultipartUpload563niks3-go-unit-tests> === RUN   TestCompleteMultipartUpload_ErrorButObjectExists564niks3-go-unit-tests> === PAUSE TestCompleteMultipartUpload_ErrorButObjectExists565niks3-go-unit-tests> === RUN   TestCompletedNarNotReofferedAcrossClosures566niks3-go-unit-tests> === PAUSE TestCompletedNarNotReofferedAcrossClosures567niks3-go-unit-tests> === RUN   TestPresignedUploadRegisteredBeforeCommit568niks3-go-unit-tests> === PAUSE TestPresignedUploadRegisteredBeforeCommit569niks3-go-unit-tests> === RUN   TestService_Rustfstest570niks3-go-unit-tests> === PAUSE TestService_Rustfstest571niks3-go-unit-tests> === RUN   TestParseSize572niks3-go-unit-tests> === PAUSE TestParseSize573niks3-go-unit-tests> === RUN   TestSkippedUploadsHandler574niks3-go-unit-tests> === PAUSE TestSkippedUploadsHandler575niks3-go-unit-tests> === RUN   TestSystemdListenerNotActivated576niks3-go-unit-tests> --- PASS: TestSystemdListenerNotActivated (0.00s)577niks3-go-unit-tests> === RUN   TestWatchdogBeatsWhenHealthy578niks3-go-unit-tests> --- PASS: TestWatchdogBeatsWhenHealthy (0.02s)579niks3-go-unit-tests> === RUN   TestWatchdogSkipsWhenUnhealthy580niks3-go-unit-tests> 2026/09/18 13:11:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"581niks3-go-unit-tests> 2026/09/18 13:11:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"582niks3-go-unit-tests> 2026/09/18 13:11:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"583niks3-go-unit-tests> 2026/09/18 13:11:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"584niks3-go-unit-tests> 2026/09/18 13:11:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"585niks3-go-unit-tests> 2026/09/18 13:11:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"586niks3-go-unit-tests> 2026/09/18 13:11:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"587niks3-go-unit-tests> 2026/09/18 13:11:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"588niks3-go-unit-tests> 2026/09/18 13:11:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"589niks3-go-unit-tests> 2026/09/18 13:11:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"590niks3-go-unit-tests> --- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)591niks3-go-unit-tests> === RUN   TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle592niks3-go-unit-tests> === PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle593niks3-go-unit-tests> === RUN   TestProxyWriteTimeout594niks3-go-unit-tests> === PAUSE TestProxyWriteTimeout595niks3-go-unit-tests> === RUN   TestIsValidUploadKey596niks3-go-unit-tests> === PAUSE TestIsValidUploadKey597niks3-go-unit-tests> === RUN   TestUploadHandlersRejectInvalidKeys598niks3-go-unit-tests> === PAUSE TestUploadHandlersRejectInvalidKeys599niks3-go-unit-tests> === RUN   TestUploadHandlersRejectOversizedBody600niks3-go-unit-tests> === PAUSE TestUploadHandlersRejectOversizedBody601niks3-go-unit-tests> === RUN   TestService_cleanupPendingClosuresHandler602niks3-go-unit-tests> === PAUSE TestService_cleanupPendingClosuresHandler603niks3-go-unit-tests> === RUN   TestService_createPendingClosureHandler604niks3-go-unit-tests> === PAUSE TestService_createPendingClosureHandler605niks3-go-unit-tests> === RUN   TestService_verifyS3Integrity606niks3-go-unit-tests> === PAUSE TestService_verifyS3Integrity607niks3-go-unit-tests> === RUN   TestCompleteMultipartUnregistered608niks3-go-unit-tests> === PAUSE TestCompleteMultipartUnregistered609niks3-go-unit-tests> === RUN   TestCreatePendingClosure_SmallNARUsesSimplePUT610niks3-go-unit-tests> === PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT611niks3-go-unit-tests> === CONT  TestService_Rustfstest612niks3-go-unit-tests> === CONT  TestService_AuthMiddleware613niks3-go-unit-tests> === CONT  TestGCTaskStore_Fail614niks3-go-unit-tests> --- PASS: TestGCTaskStore_Fail (0.00s)615niks3-go-unit-tests> === CONT  TestPresignedUploadRegisteredBeforeCommit616niks3-go-unit-tests> === CONT  TestClaim_StreamsThroughServer617niks3-go-unit-tests> === CONT  TestClaim_BuildWaitComplete618niks3-go-unit-tests> === CONT  TestGCTaskStore_PhaseUpdates619niks3-go-unit-tests> === CONT  TestIsValidCachePath620niks3-go-unit-tests> === RUN   TestIsValidCachePath/narinfo621niks3-go-unit-tests> === PAUSE TestIsValidCachePath/narinfo622niks3-go-unit-tests> --- PASS: TestGCTaskStore_PhaseUpdates (0.00s)623niks3-go-unit-tests> === CONT  TestGCTaskStore_CompletedAllowsNewTask624niks3-go-unit-tests> --- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)625niks3-go-unit-tests> === CONT  TestGCTaskStore_DeduplicateSameParams626niks3-go-unit-tests> --- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)627niks3-go-unit-tests> === CONT  TestGCTaskStore_StartNew628niks3-go-unit-tests> --- PASS: TestGCTaskStore_StartNew (0.00s)629niks3-go-unit-tests> === CONT  TestGCMetrics630niks3-go-unit-tests> === CONT  TestGCTaskStore_GetReturnsLatest631niks3-go-unit-tests> --- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)632niks3-go-unit-tests> === CONT  TestCreatePendingClosure_SmallNARUsesSimplePUT633niks3-go-unit-tests> === CONT  TestGCTaskStore_GetEmpty634niks3-go-unit-tests> --- PASS: TestGCTaskStore_GetEmpty (0.00s)635niks3-go-unit-tests> === CONT  TestGCBugBareHashReferences636niks3-go-unit-tests> === CONT  TestGCTaskStore_ConflictDifferentParams637niks3-go-unit-tests> === RUN   TestIsValidCachePath/narinfo_all_nix_base32_chars638niks3-go-unit-tests> === PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars639niks3-go-unit-tests> --- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)640niks3-go-unit-tests> === CONT  TestCompleteMultipartUnregistered641niks3-go-unit-tests> === RUN   TestIsValidCachePath/nar_zst642niks3-go-unit-tests> === PAUSE TestIsValidCachePath/nar_zst643niks3-go-unit-tests> === RUN   TestIsValidCachePath/nar_xz644niks3-go-unit-tests> === PAUSE TestIsValidCachePath/nar_xz645niks3-go-unit-tests> === RUN   TestIsValidCachePath/nar_bz2646niks3-go-unit-tests> === PAUSE TestIsValidCachePath/nar_bz2647niks3-go-unit-tests> === RUN   TestIsValidCachePath/nar_uncompressed648niks3-go-unit-tests> === PAUSE TestIsValidCachePath/nar_uncompressed649niks3-go-unit-tests> === RUN   TestIsValidCachePath/ls650niks3-go-unit-tests> === PAUSE TestIsValidCachePath/ls651niks3-go-unit-tests> === RUN   TestIsValidCachePath/log652niks3-go-unit-tests> === PAUSE TestIsValidCachePath/log653niks3-go-unit-tests> === RUN   TestIsValidCachePath/realisation654niks3-go-unit-tests> === PAUSE TestIsValidCachePath/realisation655niks3-go-unit-tests> === RUN   TestIsValidCachePath/nix-cache-info656niks3-go-unit-tests> === PAUSE TestIsValidCachePath/nix-cache-info657niks3-go-unit-tests> === RUN   TestIsValidCachePath/index.html658niks3-go-unit-tests> === PAUSE TestIsValidCachePath/index.html659niks3-go-unit-tests> === RUN   TestIsValidCachePath/traversal_parent660niks3-go-unit-tests> === PAUSE TestIsValidCachePath/traversal_parent661niks3-go-unit-tests> === RUN   TestIsValidCachePath/traversal_in_middle662niks3-go-unit-tests> === PAUSE TestIsValidCachePath/traversal_in_middle663niks3-go-unit-tests> === RUN   TestIsValidCachePath/invalid_char_e664niks3-go-unit-tests> === PAUSE TestIsValidCachePath/invalid_char_e665niks3-go-unit-tests> === RUN   TestIsValidCachePath/invalid_char_u666niks3-go-unit-tests> === PAUSE TestIsValidCachePath/invalid_char_u667niks3-go-unit-tests> === RUN   TestIsValidCachePath/random_path668niks3-go-unit-tests> === PAUSE TestIsValidCachePath/random_path669niks3-go-unit-tests> === RUN   TestIsValidCachePath/empty670niks3-go-unit-tests> === PAUSE TestIsValidCachePath/empty671niks3-go-unit-tests> === RUN   TestIsValidCachePath/leading_slash672niks3-go-unit-tests> === PAUSE TestIsValidCachePath/leading_slash673niks3-go-unit-tests> === RUN   TestIsValidCachePath/wrong_extension674niks3-go-unit-tests> === PAUSE TestIsValidCachePath/wrong_extension675niks3-go-unit-tests> === RUN   TestIsValidCachePath/short_hash676niks3-go-unit-tests> === PAUSE TestIsValidCachePath/short_hash677niks3-go-unit-tests> === CONT  TestService_verifyS3Integrity678niks3-go-unit-tests> 2026-09-18 13:11:01.750 UTC [80524] ERROR:  relation "goose_db_version" does not exist at character 36679niks3-go-unit-tests> 2026-09-18 13:11:01.750 UTC [80524] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC680niks3-go-unit-tests> 2026-09-18 13:11:01.752 UTC [80526] ERROR:  relation "goose_db_version" does not exist at character 36681niks3-go-unit-tests> 2026-09-18 13:11:01.752 UTC [80526] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC682niks3-go-unit-tests> 2026-09-18 13:11:01.753 UTC [80525] ERROR:  relation "goose_db_version" does not exist at character 36683niks3-go-unit-tests> 2026-09-18 13:11:01.753 UTC [80525] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC684niks3-go-unit-tests> 2026-09-18 13:11:01.754 UTC [80527] ERROR:  relation "goose_db_version" does not exist at character 36685niks3-go-unit-tests> 2026-09-18 13:11:01.754 UTC [80527] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC686niks3-go-unit-tests> 2026-09-18 13:11:01.754 UTC [80530] ERROR:  relation "goose_db_version" does not exist at character 36687niks3-go-unit-tests> 2026-09-18 13:11:01.754 UTC [80530] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC688niks3-go-unit-tests> 2026-09-18 13:11:01.756 UTC [80528] ERROR:  relation "goose_db_version" does not exist at character 36689niks3-go-unit-tests> 2026-09-18 13:11:01.756 UTC [80528] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC690niks3-go-unit-tests> 2026-09-18 13:11:01.757 UTC [80529] ERROR:  relation "goose_db_version" does not exist at character 36691niks3-go-unit-tests> 2026-09-18 13:11:01.757 UTC [80529] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC692niks3-go-unit-tests> 2026-09-18 13:11:01.758 UTC [80531] ERROR:  relation "goose_db_version" does not exist at character 36693niks3-go-unit-tests> 2026-09-18 13:11:01.758 UTC [80531] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC694niks3-go-unit-tests> 2026-09-18 13:11:01.758 UTC [80533] ERROR:  relation "goose_db_version" does not exist at character 36695niks3-go-unit-tests> 2026-09-18 13:11:01.758 UTC [80533] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC696niks3-go-unit-tests> 2026-09-18 13:11:01.758 UTC [80532] ERROR:  relation "goose_db_version" does not exist at character 36697niks3-go-unit-tests> 2026-09-18 13:11:01.758 UTC [80532] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC698niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (8.37ms)699niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (1.43ms)700niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (8.46ms)701niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (7.68ms)702niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (8.41ms)703niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (1.78ms)704niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (873.75µs)705niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (7.39ms)706niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (819.21µs)707niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (8.61ms)708niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (1.05ms)709niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (801.54µs)710niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (7.87ms)711niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (1.6ms)712niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (796.38µs)713niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (1.42ms)714niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (1.04ms)715niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (8.91ms)716niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (2.75ms)717niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (1.86ms)718niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (2.04ms)719niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (7.83ms)720niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (1.73ms)721niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (748.42µs)722niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (1.63ms)723niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (1.9ms)724niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (1.59ms)725niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (833.92µs)726niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20241026095416_initial_model.sql (8.01ms)727niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (1.47ms)728niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (1.84ms)729niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (2.19ms)730niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000731niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251210153512_drop_unused_gin_index.sql (771.79µs)732niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (1.3ms)733niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (1.89ms)734niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (2.05ms)735niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (2.49ms)736niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000737niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (2.67ms)738niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000739niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (2.42ms)740niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (1.96ms)741niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (1.56ms)742niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000743niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20251218171726_add_pins.sql (2.07ms)744niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (2.58ms)745niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000746niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (1.59ms)747niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (2.28ms)748niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000749niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (1.98ms)750niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (497.46µs)751niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2752niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (1.85ms)753niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (1.84ms)754niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (1.52ms)755niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260628120000_add_object_size_and_stats.sql (1.66ms)756niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (1.48ms)757niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (2.51ms)758niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000759niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (2.24ms)760niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (1.12ms)761niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2762niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (649.38µs)763niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2764niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (1.84ms)765niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000766niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (1.03ms)767niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2768niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (588.75µs)769niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2770niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (486.67µs)771niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2772niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (2.74ms)773niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000774niks3-go-unit-tests> 2026/09/18 13:11:01 OK   20260905000000_add_claims.sql (1.38ms)775niks3-go-unit-tests> 2026/09/18 13:11:01 goose: successfully migrated database to version: 20260905000000776niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (1.29ms)777niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (817.25µs)778niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (756.29µs)779niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (311.38µs)780niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2781niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (251.29µs)782niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2783niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (239.79µs)784niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2785niks3-go-unit-tests> 2026/09/18 13:11:01 OK   1_commit_pending_closure.sql (749.5µs)786niks3-go-unit-tests> 2026/09/18 13:11:01 OK   2_object_stats_trigger.sql (196.38µs)787niks3-go-unit-tests> 2026/09/18 13:11:01 goose: up to current file version: 2788niks3-go-unit-tests> 2026/09/18 13:11:01 INFO Received uploads request method=POST path=/api/pending_closures789niks3-go-unit-tests> 2026/09/18 13:11:01 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst790niks3-go-unit-tests> 2026/09/18 13:11:01 INFO Received uploads request method=POST path=/api/pending_closures791niks3-go-unit-tests> --- PASS: TestPresignedUploadRegisteredBeforeCommit (0.57s)792niks3-go-unit-tests> === CONT  TestService_createPendingClosureHandler793niks3-go-unit-tests> 2026/09/18 13:11:01 WARN claim: cannot clear write deadline error="feature not supported"794niks3-go-unit-tests> 2026/09/18 13:11:01 WARN claim: cannot clear write deadline error="feature not supported"795niks3-go-unit-tests> 2026/09/18 13:11:01 WARN claim: cannot clear write deadline error="feature not supported"796niks3-go-unit-tests> 2026/09/18 13:11:01 INFO Received uploads request method=POST path=/api/pending_closures797niks3-go-unit-tests> 2026/09/18 13:11:02 INFO Received uploads request method=POST path=/api/pending_closures798niks3-go-unit-tests> --- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.86s)799niks3-go-unit-tests> === CONT  TestService_cleanupPendingClosuresHandler800niks3-go-unit-tests> 2026/09/18 13:11:02 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"801niks3-go-unit-tests> --- PASS: TestService_AuthMiddleware (0.99s)802niks3-go-unit-tests> === CONT  TestResolveDBConnectionString803niks3-go-unit-tests> === RUN   TestResolveDBConnectionString/flag_wins804niks3-go-unit-tests> === PAUSE TestResolveDBConnectionString/flag_wins805niks3-go-unit-tests> === RUN   TestResolveDBConnectionString/file_when_flag_empty806niks3-go-unit-tests> === PAUSE TestResolveDBConnectionString/file_when_flag_empty807niks3-go-unit-tests> === RUN   TestResolveDBConnectionString/missing_file_is_an_error808niks3-go-unit-tests> === PAUSE TestResolveDBConnectionString/missing_file_is_an_error809niks3-go-unit-tests> === RUN   TestResolveDBConnectionString/PGHOST_allows_empty810niks3-go-unit-tests> === PAUSE TestResolveDBConnectionString/PGHOST_allows_empty811niks3-go-unit-tests> === RUN   TestResolveDBConnectionString/nothing_configured812niks3-go-unit-tests> === PAUSE TestResolveDBConnectionString/nothing_configured813niks3-go-unit-tests> === CONT  TestUploadHandlersRejectOversizedBody814niks3-go-unit-tests> === RUN   TestUploadHandlersRejectOversizedBody/create_pending_closure815niks3-go-unit-tests> === PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure816niks3-go-unit-tests> === RUN   TestUploadHandlersRejectOversizedBody/complete_multipart817niks3-go-unit-tests> === PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart818niks3-go-unit-tests> === RUN   TestUploadHandlersRejectOversizedBody/request_more_parts819niks3-go-unit-tests> === PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts820niks3-go-unit-tests> === CONT  TestUploadHandlersRejectInvalidKeys821niks3-go-unit-tests> === RUN   TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info822niks3-go-unit-tests> === PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info823niks3-go-unit-tests> === RUN   TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal824niks3-go-unit-tests> === PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal825niks3-go-unit-tests> === RUN   TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key826niks3-go-unit-tests> === PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key827niks3-go-unit-tests> === RUN   TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key828niks3-go-unit-tests> === PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key829niks3-go-unit-tests> === CONT  TestIsValidUploadKey830niks3-go-unit-tests> === RUN   TestIsValidUploadKey/narinfo831niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/narinfo832niks3-go-unit-tests> === RUN   TestIsValidUploadKey/nar_zst833niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/nar_zst834niks3-go-unit-tests> === RUN   TestIsValidUploadKey/nar_xz835niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/nar_xz836niks3-go-unit-tests> === RUN   TestIsValidUploadKey/nar_plain837niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/nar_plain838niks3-go-unit-tests> === RUN   TestIsValidUploadKey/listing839niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/listing840niks3-go-unit-tests> === RUN   TestIsValidUploadKey/build_log841niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/build_log842niks3-go-unit-tests> === RUN   TestIsValidUploadKey/build_log_home-manager_file843niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/build_log_home-manager_file844niks3-go-unit-tests> === RUN   TestIsValidUploadKey/build_log_plus_in_name845niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/build_log_plus_in_name846niks3-go-unit-tests> === RUN   TestIsValidUploadKey/build_log_question_mark847niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/build_log_question_mark848niks3-go-unit-tests> === RUN   TestIsValidUploadKey/build_log_equals849niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/build_log_equals850niks3-go-unit-tests> === RUN   TestIsValidUploadKey/realisation851niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/realisation852niks3-go-unit-tests> === RUN   TestIsValidUploadKey/realisation_plus_in_output853niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/realisation_plus_in_output854niks3-go-unit-tests> === RUN   TestIsValidUploadKey/nix-cache-info855niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/nix-cache-info856niks3-go-unit-tests> === RUN   TestIsValidUploadKey/index.html857niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/index.html858niks3-go-unit-tests> === RUN   TestIsValidUploadKey/narinfo_key,_nar_type859niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/narinfo_key,_nar_type860niks3-go-unit-tests> === RUN   TestIsValidUploadKey/nar_key,_narinfo_type861niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/nar_key,_narinfo_type862niks3-go-unit-tests> === RUN   TestIsValidUploadKey/listing_key,_narinfo_type863niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/listing_key,_narinfo_type864niks3-go-unit-tests> === RUN   TestIsValidUploadKey/traversal865niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/traversal866niks3-go-unit-tests> === RUN   TestIsValidUploadKey/traversal_nar867niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/traversal_nar868niks3-go-unit-tests> === RUN   TestIsValidUploadKey/absolute869niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/absolute870niks3-go-unit-tests> === RUN   TestIsValidUploadKey/empty_key871niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/empty_key872niks3-go-unit-tests> === RUN   TestIsValidUploadKey/unknown_type873niks3-go-unit-tests> === PAUSE TestIsValidUploadKey/unknown_type874niks3-go-unit-tests> === CONT  TestProxyWriteTimeout875niks3-go-unit-tests> === RUN   TestProxyWriteTimeout/narinfo876niks3-go-unit-tests> === PAUSE TestProxyWriteTimeout/narinfo877niks3-go-unit-tests> === RUN   TestProxyWriteTimeout/1_GiB_nar878niks3-go-unit-tests> === PAUSE TestProxyWriteTimeout/1_GiB_nar879niks3-go-unit-tests> === RUN   TestProxyWriteTimeout/10_GiB_nar880niks3-go-unit-tests> === PAUSE TestProxyWriteTimeout/10_GiB_nar881niks3-go-unit-tests> === RUN   TestProxyWriteTimeout/unknown_size882niks3-go-unit-tests> === PAUSE TestProxyWriteTimeout/unknown_size883niks3-go-unit-tests> === CONT  TestPinProtectsFromGC884niks3-go-unit-tests> 2026/09/18 13:11:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete885niks3-go-unit-tests> 2026/09/18 13:11:02 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst886niks3-go-unit-tests> --- PASS: TestCompleteMultipartUnregistered (1.33s)887niks3-go-unit-tests> === CONT  TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle888niks3-go-unit-tests> 2026-09-18 13:11:02.671 UTC [80550] ERROR:  relation "goose_db_version" does not exist at character 36889niks3-go-unit-tests> 2026-09-18 13:11:02.671 UTC [80550] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC890niks3-go-unit-tests> 2026/09/18 13:11:02 OK   20241026095416_initial_model.sql (103.22ms)891niks3-go-unit-tests> 2026/09/18 13:11:02 OK   20251210153512_drop_unused_gin_index.sql (12.36ms)892niks3-go-unit-tests> 2026/09/18 13:11:02 INFO Received uploads request method=POST path=/api/pending_closures893niks3-go-unit-tests> 2026-09-18 13:11:02.822 UTC [80552] ERROR:  relation "goose_db_version" does not exist at character 36894niks3-go-unit-tests> 2026-09-18 13:11:02.822 UTC [80552] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC895niks3-go-unit-tests> 2026/09/18 13:11:02 OK   20251218171726_add_pins.sql (10.16ms)896niks3-go-unit-tests> 2026/09/18 13:11:02 OK   20260628120000_add_object_size_and_stats.sql (23.46ms)897niks3-go-unit-tests> 2026/09/18 13:11:02 OK   20260905000000_add_claims.sql (28.54ms)898niks3-go-unit-tests> 2026/09/18 13:11:02 goose: successfully migrated database to version: 20260905000000899niks3-go-unit-tests> 2026/09/18 13:11:02 OK   1_commit_pending_closure.sql (6.29ms)900niks3-go-unit-tests> 2026/09/18 13:11:02 OK   2_object_stats_trigger.sql (1.16ms)901niks3-go-unit-tests> 2026/09/18 13:11:02 goose: up to current file version: 2902niks3-go-unit-tests> 2026/09/18 13:11:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete903niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20241026095416_initial_model.sql (138.24ms)904niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLmUxMjhmZjI2LWQ0OTgtNDE5YS1hMTM2LTNjMTk5Zjg5NzJmZHgxNzg5NzM3MDYxOTgyNjYyMDAw parts=10905niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign906niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Signed narinfos id=1 count=1907niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete908niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received uploads request method=POST path=/api/pending_closures909niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign910niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Signed narinfos id=2 count=1911niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete912niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Completed upload id=2913niks3-go-unit-tests> 2026/09/18 13:11:03 WARN claim: cannot clear write deadline error="feature not supported"914niks3-go-unit-tests> --- PASS: TestClaim_BuildWaitComplete (1.73s)915niks3-go-unit-tests> === CONT  TestClaim_InputsTouched916niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20251210153512_drop_unused_gin_index.sql (11.26ms)917niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20251218171726_add_pins.sql (14.84ms)918niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20260628120000_add_object_size_and_stats.sql (23.97ms)919niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20260905000000_add_claims.sql (40.07ms)920niks3-go-unit-tests> 2026/09/18 13:11:03 goose: successfully migrated database to version: 20260905000000921niks3-go-unit-tests> 2026-09-18 13:11:03.105 UTC [80555] ERROR:  relation "goose_db_version" does not exist at character 36922niks3-go-unit-tests> 2026-09-18 13:11:03.105 UTC [80555] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC923niks3-go-unit-tests> 2026/09/18 13:11:03 OK   1_commit_pending_closure.sql (3.23ms)924niks3-go-unit-tests> 2026/09/18 13:11:03 OK   2_object_stats_trigger.sql (650.79µs)925niks3-go-unit-tests> 2026/09/18 13:11:03 goose: up to current file version: 2926niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20241026095416_initial_model.sql (103.59ms)927niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20251210153512_drop_unused_gin_index.sql (11.7ms)928niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Aborted multipart uploads count=0929niks3-go-unit-tests> 2026/09/18 13:11:03 WARN Force mode enabled - objects will be deleted immediately without grace period930niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=0931niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Vacuumed table table=pending_closures932niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Vacuumed table table=pending_objects933niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Vacuumed table table=multipart_uploads934niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Vacuumed table table=closures935niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Vacuumed table table=objects936niks3-go-unit-tests> --- PASS: TestGCMetrics (1.96s)937niks3-go-unit-tests> === CONT  TestClientWithDependencies938niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20251218171726_add_pins.sql (22.99ms)939niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20260628120000_add_object_size_and_stats.sql (18.55ms)940niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20260905000000_add_claims.sql (3.53ms)941niks3-go-unit-tests> 2026/09/18 13:11:03 goose: successfully migrated database to version: 20260905000000942niks3-go-unit-tests> --- PASS: TestGCBugBareHashReferences (2.00s)943niks3-go-unit-tests> === CONT  TestSkippedUploadsHandler944niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000945niks3-go-unit-tests> 2026/09/18 13:11:03 OK   1_commit_pending_closure.sql (2.57ms)946niks3-go-unit-tests> --- PASS: TestSkippedUploadsHandler (0.00s)947niks3-go-unit-tests> === CONT  TestClaim_TwoInstances948niks3-go-unit-tests> 2026/09/18 13:11:03 OK   2_object_stats_trigger.sql (558.67µs)949niks3-go-unit-tests> 2026/09/18 13:11:03 goose: up to current file version: 2950niks3-go-unit-tests> 2026-09-18 13:11:03.385 UTC [80561] ERROR:  relation "goose_db_version" does not exist at character 36951niks3-go-unit-tests> 2026-09-18 13:11:03.385 UTC [80561] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC952niks3-go-unit-tests> --- PASS: TestService_Rustfstest (2.12s)953niks3-go-unit-tests> === CONT  TestClientMultipleUploads954niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20241026095416_initial_model.sql (109.78ms)955niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received uploads request method=POST path=/api/pending_closures956niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received uploads request method=POST path=/api/pending_closures957niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received uploads request method=POST path=/api/pending_closures958niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20251210153512_drop_unused_gin_index.sql (14.92ms)959niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20251218171726_add_pins.sql (3.28ms)960niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20260628120000_add_object_size_and_stats.sql (32.71ms)961niks3-go-unit-tests> 2026/09/18 13:11:03 OK   20260905000000_add_claims.sql (36.64ms)962niks3-go-unit-tests> 2026/09/18 13:11:03 goose: successfully migrated database to version: 20260905000000963niks3-go-unit-tests> 2026/09/18 13:11:03 OK   1_commit_pending_closure.sql (9.23ms)964niks3-go-unit-tests> 2026/09/18 13:11:03 OK   2_object_stats_trigger.sql (626.04µs)965niks3-go-unit-tests> 2026/09/18 13:11:03 goose: up to current file version: 2966niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received cleanup request method=DELETE path=/api/pending_closures967niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Aborted multipart uploads count=0968niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received uploads request method=POST path=/api/pending_closures969niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received cleanup request method=DELETE path=/api/pending_closures970niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Aborted multipart uploads count=1971niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete972niks3-go-unit-tests> 2026-09-18 13:11:03.890 UTC [80552] ERROR:  Closure does not exist: id=1973niks3-go-unit-tests> 2026-09-18 13:11:03.890 UTC [80552] CONTEXT:  PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE974niks3-go-unit-tests> 2026-09-18 13:11:03.890 UTC [80552] STATEMENT:  -- name: CommitPendingClosure :exec975niks3-go-unit-tests> 	SELECT commit_pending_closure($1::bigint)976niks3-go-unit-tests> 	977niks3-go-unit-tests> --- PASS: TestService_cleanupPendingClosuresHandler (1.74s)978niks3-go-unit-tests> === CONT  TestParseSize979niks3-go-unit-tests> --- PASS: TestParseSize (0.00s)980niks3-go-unit-tests> === CONT  TestClientIntegration981niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete982niks3-go-unit-tests> --- PASS: TestClaim_StreamsThroughServer (2.66s)983niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC984niks3-go-unit-tests> 2026/09/18 13:11:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57087/oidc985niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLjJjNGJkZWFiLTQzYTItNDExYS05NjA0LTY5YTI2M2FmYzNjZHgxNzg5NzM3MDYyODMyNTU0MDAw parts=10986niks3-go-unit-tests> 2026/09/18 13:11:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete987niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Completed upload id=1988niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received uploads request method=POST path=/api/pending_closures989niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received uploads request method=POST path=/api/pending_closures990niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo991niks3-go-unit-tests> 2026/09/18 13:11:04 WARN Found objects in DB but missing from S3, will re-upload count=1992niks3-go-unit-tests> --- PASS: TestService_verifyS3Integrity (2.71s)993niks3-go-unit-tests> === CONT  TestClientErrorHandling994niks3-go-unit-tests> === RUN   TestClientErrorHandling/InvalidStorePath995niks3-go-unit-tests> === PAUSE TestClientErrorHandling/InvalidStorePath996niks3-go-unit-tests> === RUN   TestClientErrorHandling/InvalidAuthToken997niks3-go-unit-tests> === PAUSE TestClientErrorHandling/InvalidAuthToken998niks3-go-unit-tests> === RUN   TestClientErrorHandling/ServerNotAvailable999niks3-go-unit-tests> === PAUSE TestClientErrorHandling/ServerNotAvailable1000niks3-go-unit-tests> === CONT  TestCacheStatsHandler1001niks3-go-unit-tests> 2026-09-18 13:11:04.122 UTC [80571] ERROR:  relation "goose_db_version" does not exist at character 361002niks3-go-unit-tests> 2026-09-18 13:11:04.122 UTC [80571] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1003niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received uploads request method=POST path=/api/pending_closures1004niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20241026095416_initial_model.sql (109.53ms)1005niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20251210153512_drop_unused_gin_index.sql (6.86ms)1006niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20251218171726_add_pins.sql (3.78ms)1007niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20260628120000_add_object_size_and_stats.sql (13.92ms)1008niks3-go-unit-tests> 2026-09-18 13:11:04.377 UTC [80574] ERROR:  relation "goose_db_version" does not exist at character 361009niks3-go-unit-tests> 2026-09-18 13:11:04.377 UTC [80574] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1010niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20260905000000_add_claims.sql (70.41ms)1011niks3-go-unit-tests> 2026/09/18 13:11:04 goose: successfully migrated database to version: 202609050000001012niks3-go-unit-tests> 2026/09/18 13:11:04 OK   1_commit_pending_closure.sql (7.31ms)1013niks3-go-unit-tests> 2026/09/18 13:11:04 OK   2_object_stats_trigger.sql (281.79µs)1014niks3-go-unit-tests> 2026/09/18 13:11:04 goose: up to current file version: 21015niks3-go-unit-tests> === NAME  TestPinProtectsFromGC1016niks3-go-unit-tests>     client_integration_test.go:667: Pinned store path: /nix/var/nix/builds/nix-80273-1366931373/TestPinProtectsFromGC2048025934/001/store/8z885gj76sifa268vflal9qs0ycxqnay-pinned-file.txt1017niks3-go-unit-tests>     client_integration_test.go:668: Unpinned store path: /nix/var/nix/builds/nix-80273-1366931373/TestPinProtectsFromGC2048025934/001/store/nrl5wmj2941z9l7qz6h8ral2bqh0gg2s-unpinned-file.txt1018niks3-go-unit-tests> 2026/09/18 13:11:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1019niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1020niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received uploads request method=POST path=/api/pending_closures1021niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20241026095416_initial_model.sql (162.43ms)1022niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20251210153512_drop_unused_gin_index.sql (12.75ms)1023niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1024niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Uploading 8z885gj76sifa268vflal9qs0ycxqnay-pinned-file.txt (128B)1025niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20251218171726_add_pins.sql (23.44ms)1026niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received uploads request method=POST path=/api/pending_closures1027niks3-go-unit-tests> 2026/09/18 13:11:04 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1028niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1029niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Signed narinfos id=1 count=11030niks3-go-unit-tests> 2026/09/18 13:11:04 WARN Failed to register uploaded object key=8z885gj76sifa268vflal9qs0ycxqnay.ls error="server returned 404: 404 page not found\n"1031niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Uploading 1 narinfos1032niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1033niks3-go-unit-tests> 2026/09/18 13:11:04 WARN Failed to register uploaded object key=8z885gj76sifa268vflal9qs0ycxqnay.narinfo error="server returned 404: 404 page not found\n"1034niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20260628120000_add_object_size_and_stats.sql (22.03ms)1035niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Completed upload id=11036niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Upload complete. (213ms)1037niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20260905000000_add_claims.sql (27.76ms)1038niks3-go-unit-tests> 2026/09/18 13:11:04 goose: successfully migrated database to version: 202609050000001039niks3-go-unit-tests> 2026/09/18 13:11:04 OK   1_commit_pending_closure.sql (5.79ms)1040niks3-go-unit-tests> 2026/09/18 13:11:04 OK   2_object_stats_trigger.sql (238.08µs)1041niks3-go-unit-tests> 2026/09/18 13:11:04 goose: up to current file version: 21042niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1043niks3-go-unit-tests> 2026/09/18 13:11:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1044niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLmVlYTdmMDgyLTRiYTAtNDJkZC04N2VmLTAyMDMzZmJjZjExYXgxNzg5NzM3MDYzNjIxODc5MDAw parts=101045niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1046niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Completed upload id=11047niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001048niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received uploads request method=POST path=/api/pending_closures1049niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures1050niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Aborted multipart uploads count=01051niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=01052niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Vacuumed table table=pending_closures1053niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Vacuumed table table=pending_objects1054niks3-go-unit-tests> 2026-09-18 13:11:04.795 UTC [80587] ERROR:  relation "goose_db_version" does not exist at character 361055niks3-go-unit-tests> 2026-09-18 13:11:04.795 UTC [80587] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1056niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received uploads request method=POST path=/api/pending_closures1057niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1058niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Uploading nrl5wmj2941z9l7qz6h8ral2bqh0gg2s-unpinned-file.txt (128B)1059niks3-go-unit-tests> 2026-09-18 13:11:04.811 UTC [80589] ERROR:  relation "goose_db_version" does not exist at character 361060niks3-go-unit-tests> 2026-09-18 13:11:04.811 UTC [80589] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1061niks3-go-unit-tests> 2026/09/18 13:11:04 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1062niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Vacuumed table table=multipart_uploads1063niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1064niks3-go-unit-tests> 2026/09/18 13:11:04 WARN Failed to register uploaded object key=nrl5wmj2941z9l7qz6h8ral2bqh0gg2s.ls error="server returned 404: 404 page not found\n"1065niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Signed narinfos id=2 count=11066niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Uploading 1 narinfos1067niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Vacuumed table table=closures1068niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1069niks3-go-unit-tests> 2026/09/18 13:11:04 WARN Failed to register uploaded object key=nrl5wmj2941z9l7qz6h8ral2bqh0gg2s.narinfo error="server returned 404: 404 page not found\n"1070niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Completed upload id=21071niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Upload complete. (144ms)1072niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Vacuumed table table=objects1073niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001074niks3-go-unit-tests> --- PASS: TestService_createPendingClosureHandler (3.00s)1075niks3-go-unit-tests> === CONT  TestClientCADerivations1076niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Received create pin request method=POST path=/api/pins/myapp1077niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-80273-1366931373/TestPinProtectsFromGC2048025934/001/store/8z885gj76sifa268vflal9qs0ycxqnay-pinned-file.txt narinfo_key=8z885gj76sifa268vflal9qs0ycxqnay.narinfo1078niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures1079niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Garbage collection started1080niks3-go-unit-tests> 2026/09/18 13:11:04 INFO Aborted multipart uploads count=01081niks3-go-unit-tests> 2026/09/18 13:11:04 WARN Force mode enabled - objects will be deleted immediately without grace period1082niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20241026095416_initial_model.sql (85.3ms)1083niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20241026095416_initial_model.sql (91.65ms)1084niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20251210153512_drop_unused_gin_index.sql (1.23ms)1085niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20251210153512_drop_unused_gin_index.sql (1.84ms)1086niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20251218171726_add_pins.sql (1.95ms)1087niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20251218171726_add_pins.sql (2.44ms)1088niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20260628120000_add_object_size_and_stats.sql (3.7ms)1089niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20260628120000_add_object_size_and_stats.sql (3.24ms)1090niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20260905000000_add_claims.sql (2.67ms)1091niks3-go-unit-tests> 2026/09/18 13:11:04 goose: successfully migrated database to version: 202609050000001092niks3-go-unit-tests> 2026/09/18 13:11:04 OK   20260905000000_add_claims.sql (2.83ms)1093niks3-go-unit-tests> 2026/09/18 13:11:04 goose: successfully migrated database to version: 202609050000001094niks3-go-unit-tests> 2026/09/18 13:11:04 OK   1_commit_pending_closure.sql (1.47ms)1095niks3-go-unit-tests> 2026/09/18 13:11:04 OK   1_commit_pending_closure.sql (2.51ms)1096niks3-go-unit-tests> 2026/09/18 13:11:04 OK   2_object_stats_trigger.sql (859µs)1097niks3-go-unit-tests> 2026/09/18 13:11:04 goose: up to current file version: 21098niks3-go-unit-tests> 2026/09/18 13:11:04 OK   2_object_stats_trigger.sql (746.04µs)1099niks3-go-unit-tests> 2026/09/18 13:11:04 goose: up to current file version: 21100niks3-go-unit-tests> 2026-09-18 13:11:05.144 UTC [80603] ERROR:  relation "goose_db_version" does not exist at character 361101niks3-go-unit-tests> 2026-09-18 13:11:05.144 UTC [80603] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1102niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=01103niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Vacuumed table table=pending_closures1104niks3-go-unit-tests> 2026/09/18 13:11:05 WARN claim: cannot clear write deadline error="feature not supported"1105niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Vacuumed table table=pending_objects1106niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Vacuumed table table=multipart_uploads1107niks3-go-unit-tests> 2026/09/18 13:11:05 WARN claim: cannot clear write deadline error="feature not supported"1108niks3-go-unit-tests> 2026/09/18 13:11:05 WARN claim: cannot clear write deadline error="feature not supported"1109niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received uploads request method=POST path=/api/pending_closures1110niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Vacuumed table table=closures1111niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Vacuumed table table=objects1112niks3-go-unit-tests> 2026-09-18 13:11:05.235 UTC [80611] ERROR:  relation "goose_db_version" does not exist at character 361113niks3-go-unit-tests> 2026-09-18 13:11:05.235 UTC [80611] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1114niks3-go-unit-tests> 2026-09-18 13:11:05.245 UTC [80612] ERROR:  relation "goose_db_version" does not exist at character 361115niks3-go-unit-tests> 2026-09-18 13:11:05.245 UTC [80612] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1116niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20241026095416_initial_model.sql (106.35ms)1117niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20251210153512_drop_unused_gin_index.sql (15.26ms)1118niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20251218171726_add_pins.sql (13.2ms)1119niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20260628120000_add_object_size_and_stats.sql (23.16ms)1120niks3-go-unit-tests> === NAME  TestClientWithDependencies1121niks3-go-unit-tests>     client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-80273-1366931373/TestClientWithDependencies3963078825/001/store/4wwp78m8q22yh37wvlyj6nmgd64qggak-test-script1122niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20260905000000_add_claims.sql (38.59ms)1123niks3-go-unit-tests> 2026/09/18 13:11:05 goose: successfully migrated database to version: 202609050000001124niks3-go-unit-tests> 2026/09/18 13:11:05 OK   1_commit_pending_closure.sql (10.3ms)1125niks3-go-unit-tests> 2026/09/18 13:11:05 OK   2_object_stats_trigger.sql (240.04µs)1126niks3-go-unit-tests> 2026/09/18 13:11:05 goose: up to current file version: 21127niks3-go-unit-tests>     client_integration_test.go:615: Found 1 dependencies (including self)1128niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20241026095416_initial_model.sql (105.75ms)1129niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20241026095416_initial_model.sql (99.6ms)1130niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20251210153512_drop_unused_gin_index.sql (1.64ms)1131niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20251210153512_drop_unused_gin_index.sql (10.46ms)1132niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20251218171726_add_pins.sql (22.33ms)1133niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20251218171726_add_pins.sql (40.71ms)1134niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20260628120000_add_object_size_and_stats.sql (50.08ms)1135niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1136niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received uploads request method=POST path=/api/pending_closures1137niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20260628120000_add_object_size_and_stats.sql (40.18ms)1138niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20260905000000_add_claims.sql (28.26ms)1139niks3-go-unit-tests> 2026/09/18 13:11:05 goose: successfully migrated database to version: 202609050000001140niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1141niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading 4wwp78m8q22yh37wvlyj6nmgd64qggak-test-script (136B)1142niks3-go-unit-tests> 2026/09/18 13:11:05 OK   1_commit_pending_closure.sql (1.79ms)1143niks3-go-unit-tests> 2026/09/18 13:11:05 OK   2_object_stats_trigger.sql (257.67µs)1144niks3-go-unit-tests> 2026/09/18 13:11:05 goose: up to current file version: 21145niks3-go-unit-tests> 2026/09/18 13:11:05 OK   20260905000000_add_claims.sql (16.89ms)1146niks3-go-unit-tests> 2026/09/18 13:11:05 goose: successfully migrated database to version: 202609050000001147niks3-go-unit-tests> 2026/09/18 13:11:05 OK   1_commit_pending_closure.sql (1.32ms)1148niks3-go-unit-tests> === NAME  TestClientMultipleUploads1149niks3-go-unit-tests>     client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-80273-1366931373/TestClientMultipleUploads2436518977/001/store/pnz23gzvrw3x2hyq4nkd148g2slqsy5q-test-file-0.txt1150niks3-go-unit-tests> 2026/09/18 13:11:05 OK   2_object_stats_trigger.sql (250.88µs)1151niks3-go-unit-tests> 2026/09/18 13:11:05 goose: up to current file version: 21152niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1153niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=4wwp78m8q22yh37wvlyj6nmgd64qggak.ls error="server returned 404: 404 page not found\n"1154niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=log/424hq28xn3lqpg1chjzad53z7c7j09nq-test-script.drv error="server returned 404: 404 page not found\n"1155niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1156niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Signed narinfos id=1 count=11157niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading 1 narinfos1158niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1159niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=4wwp78m8q22yh37wvlyj6nmgd64qggak.narinfo error="server returned 404: 404 page not found\n"1160niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Completed upload id=11161niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Upload complete. (152ms)1162niks3-go-unit-tests> === NAME  TestClientWithDependencies1163niks3-go-unit-tests>     client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-80273-1366931373/TestClientWithDependencies3963078825/001/store) requires matching store prefix1164niks3-go-unit-tests> === NAME  TestClientMultipleUploads1165niks3-go-unit-tests>     client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-80273-1366931373/TestClientMultipleUploads2436518977/001/store/yrl1qb7g251bri9sjs5fcx9rraqaqlkb-test-file-1.txt1166niks3-go-unit-tests> --- PASS: TestClientWithDependencies (2.44s)1167niks3-go-unit-tests> === CONT  TestCacheConfigHandler1168niks3-go-unit-tests> === RUN   TestCacheConfigHandler/full_config,_no_issuer1169niks3-go-unit-tests> === PAUSE TestCacheConfigHandler/full_config,_no_issuer1170niks3-go-unit-tests> === RUN   TestCacheConfigHandler/no_cache_url_configured1171niks3-go-unit-tests> === PAUSE TestCacheConfigHandler/no_cache_url_configured1172niks3-go-unit-tests> === RUN   TestCacheConfigHandler/no_signing_keys1173niks3-go-unit-tests> === PAUSE TestCacheConfigHandler/no_signing_keys1174niks3-go-unit-tests> === RUN   TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1175niks3-go-unit-tests> === PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1176niks3-go-unit-tests> === CONT  TestPresent1177niks3-go-unit-tests> === NAME  TestClientMultipleUploads1178niks3-go-unit-tests>     client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-80273-1366931373/TestClientMultipleUploads2436518977/001/store/4xychv2m473f0kyab5ac6c2gim1n5byc-test-file-2.txt1179niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1180niks3-go-unit-tests> === NAME  TestClientIntegration1181niks3-go-unit-tests>     client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-80273-1366931373/TestClientIntegration3751658200/002/store/vrrr65qzigdyzki449pzzbqnj9i5svww-test-file.txt1182niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLmMxNzc1MGJiLThlOTYtNGMzZC1hZjM1LWZkMmUyZThhMzVjYXgxNzg5NzM3MDY0NjUyNjQ4MDAw parts=101183niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1184niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1185niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Completed upload id=11186niks3-go-unit-tests> 2026/09/18 13:11:05 WARN claim: cannot clear write deadline error="feature not supported"1187niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Aborted multipart uploads count=01188niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Force mode enabled - objects will be deleted immediately without grace period1189niks3-go-unit-tests> 2026/09/18 13:11:05 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=01190niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1191niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received uploads request method=POST path=/api/pending_closures1192niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Vacuumed table table=pending_closures1193niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC/builder_may_write1194niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC/builder_may_write1195niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC/builder_may_not_admin1196niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1197niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC/ops_may_admin1198niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC/ops_may_admin1199niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC/ops_may_not_write1200niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC/ops_may_not_write1201niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC/reader_may_not_write1202niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC/reader_may_not_write1203niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC/static_token_may_admin1204niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC/static_token_may_admin1205niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC/static_token_may_write1206niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC/static_token_may_write1207niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC/reader_may_read1208niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC/reader_may_read1209niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC/writer_implies_read1210niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC/writer_implies_read1211niks3-go-unit-tests> === RUN   TestService_RequireScope_OIDC/anonymous_may_not_read1212niks3-go-unit-tests> === PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1213niks3-go-unit-tests> === CONT  TestClaim_StaleHeartbeatStolen1214niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received uploads request method=POST path=/api/pending_closures1215niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received uploads request method=POST path=/api/pending_closures1216niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1217niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading 4xychv2m473f0kyab5ac6c2gim1n5byc-test-file-2.txt (160B)1218niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading pnz23gzvrw3x2hyq4nkd148g2slqsy5q-test-file-0.txt (160B)1219niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading yrl1qb7g251bri9sjs5fcx9rraqaqlkb-test-file-1.txt (160B)1220niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Vacuumed table table=pending_objects1221niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1222niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1223niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1224niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Vacuumed table table=multipart_uploads1225niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=pnz23gzvrw3x2hyq4nkd148g2slqsy5q.ls error="server returned 404: 404 page not found\n"1226niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=4xychv2m473f0kyab5ac6c2gim1n5byc.ls error="server returned 404: 404 page not found\n"1227niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=yrl1qb7g251bri9sjs5fcx9rraqaqlkb.ls error="server returned 404: 404 page not found\n"1228niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1229niks3-go-unit-tests> 2026-09-18 13:11:05.931 UTC [80644] ERROR:  relation "goose_db_version" does not exist at character 361230niks3-go-unit-tests> 2026-09-18 13:11:05.931 UTC [80644] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1231niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Vacuumed table table=closures1232niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received uploads request method=POST path=/api/pending_closures1233niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Signed narinfos id=1 count=11234niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1235niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Signed narinfos id=2 count=11236niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign1237niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Signed narinfos id=3 count=11238niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading 3 narinfos1239niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Vacuumed table table=objects1240niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=pnz23gzvrw3x2hyq4nkd148g2slqsy5q.narinfo error="server returned 404: 404 page not found\n"1241niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=yrl1qb7g251bri9sjs5fcx9rraqaqlkb.narinfo error="server returned 404: 404 page not found\n"1242niks3-go-unit-tests> --- PASS: TestClaim_InputsTouched (2.92s)1243niks3-go-unit-tests> === CONT  TestService_ReadScope_PublicByDefault1244niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1245niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading vrrr65qzigdyzki449pzzbqnj9i5svww-test-file.txt (152B)1246niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1247niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=4xychv2m473f0kyab5ac6c2gim1n5byc.narinfo error="server returned 404: 404 page not found\n"1248niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1249niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Completed upload id=11250niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1251niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Completed upload id=21252niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete1253niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Completed upload id=31254niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Upload complete. (208ms)1255niks3-go-unit-tests> === NAME  TestClientMultipleUploads1256niks3-go-unit-tests>     client_integration_test.go:369: Uploaded 3 paths in 243.1235ms1257niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=vrrr65qzigdyzki449pzzbqnj9i5svww.ls error="server returned 404: 404 page not found\n"1258niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1259niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Signed narinfos id=1 count=11260niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Uploading 1 narinfos1261niks3-go-unit-tests> 2026/09/18 13:11:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1262niks3-go-unit-tests> 2026/09/18 13:11:05 WARN Failed to register uploaded object key=vrrr65qzigdyzki449pzzbqnj9i5svww.narinfo error="server returned 404: 404 page not found\n"1263niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Completed upload id=11264niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Upload complete. (195ms)1265niks3-go-unit-tests> === CONT  TestService_NativeMTLS1266niks3-go-unit-tests> --- PASS: TestClientMultipleUploads (2.61s)1267niks3-go-unit-tests> 2026/09/18 13:11:06 INFO All 1 paths already cached1268niks3-go-unit-tests> === NAME  TestClientIntegration1269niks3-go-unit-tests>     client_integration_test.go:312: Retrieved narinfo from S3:1270niks3-go-unit-tests>         StorePath: /nix/var/nix/builds/nix-80273-1366931373/TestClientIntegration3751658200/002/store/vrrr65qzigdyzki449pzzbqnj9i5svww-test-file.txt1271niks3-go-unit-tests>         URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1272niks3-go-unit-tests>         Compression: zstd1273niks3-go-unit-tests>         NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11274niks3-go-unit-tests>         NarSize: 1521275niks3-go-unit-tests>         References: 1276niks3-go-unit-tests>         CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11277niks3-go-unit-tests>     client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1278niks3-go-unit-tests>     client_integration_test.go:313: Decompressed .ls content (64 bytes):1279niks3-go-unit-tests>         {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1280niks3-go-unit-tests>     client_integration_test.go:316: Testing garbage collection...1281niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20241026095416_initial_model.sql (106.48ms)1282niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251210153512_drop_unused_gin_index.sql (6.74ms)1283niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures1284niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Garbage collection started1285niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Aborted multipart uploads count=01286niks3-go-unit-tests> 2026/09/18 13:11:06 WARN Force mode enabled - objects will be deleted immediately without grace period1287niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251218171726_add_pins.sql (10.99ms)1288niks3-go-unit-tests> --- PASS: TestCacheStatsHandler (2.08s)1289niks3-go-unit-tests> === CONT  TestClaim_FailWithoutKindReleases1290niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260628120000_add_object_size_and_stats.sql (4.8ms)1291niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260905000000_add_claims.sql (3.18ms)1292niks3-go-unit-tests> 2026/09/18 13:11:06 goose: successfully migrated database to version: 202609050000001293niks3-go-unit-tests> 2026/09/18 13:11:06 OK   1_commit_pending_closure.sql (1.26ms)1294niks3-go-unit-tests> 2026/09/18 13:11:06 OK   2_object_stats_trigger.sql (275.25µs)1295niks3-go-unit-tests> 2026/09/18 13:11:06 goose: up to current file version: 21296niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1297niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLjU0NWEyMTdjLWIyY2MtNDJjMC1iYzk4LTY0NDM4NmJiN2M4N3gxNzg5NzM3MDY1MjE5NzYxMDAw parts=101298niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1299niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Signed narinfos id=1 count=11300niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1301niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Completed upload id=11302niks3-go-unit-tests> --- PASS: TestClaim_TwoInstances (3.00s)1303niks3-go-unit-tests> === CONT  TestObjectStatsTrigger1304niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=01305niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Vacuumed table table=pending_closures1306niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Vacuumed table table=pending_objects1307niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Vacuumed table table=multipart_uploads1308niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Vacuumed table table=closures1309niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Vacuumed table table=objects1310niks3-go-unit-tests> 2026-09-18 13:11:06.341 UTC [80661] ERROR:  relation "goose_db_version" does not exist at character 361311niks3-go-unit-tests> 2026-09-18 13:11:06.341 UTC [80661] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1312niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20241026095416_initial_model.sql (17.47ms)1313niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251210153512_drop_unused_gin_index.sql (657.38µs)1314niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251218171726_add_pins.sql (5.52ms)1315niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260628120000_add_object_size_and_stats.sql (3.51ms)1316niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260905000000_add_claims.sql (1.29ms)1317niks3-go-unit-tests> 2026/09/18 13:11:06 goose: successfully migrated database to version: 202609050000001318niks3-go-unit-tests> 2026/09/18 13:11:06 OK   1_commit_pending_closure.sql (819.92µs)1319niks3-go-unit-tests> 2026/09/18 13:11:06 OK   2_object_stats_trigger.sql (224.25µs)1320niks3-go-unit-tests> 2026/09/18 13:11:06 goose: up to current file version: 21321niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Received uploads request method=POST path=/api/pending_closures1322niks3-go-unit-tests> === NAME  TestClientCADerivations1323niks3-go-unit-tests>     client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-80273-1366931373/TestClientCADerivations3523790260/001/store/ih75yar6vw1vf9ncrxzghz508cv25wjq-ca-test1324niks3-go-unit-tests> 2026-09-18 13:11:06.544 UTC [80667] ERROR:  relation "goose_db_version" does not exist at character 361325niks3-go-unit-tests> 2026-09-18 13:11:06.544 UTC [80667] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1326niks3-go-unit-tests>     client_ca_test.go:139: Found 1 dependencies (including self)1327niks3-go-unit-tests> 2026-09-18 13:11:06.567 UTC [80669] ERROR:  relation "goose_db_version" does not exist at character 361328niks3-go-unit-tests> 2026-09-18 13:11:06.567 UTC [80669] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1329niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20241026095416_initial_model.sql (39.34ms)1330niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20241026095416_initial_model.sql (25.66ms)1331niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251210153512_drop_unused_gin_index.sql (835.79µs)1332niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251210153512_drop_unused_gin_index.sql (957.88µs)1333niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251218171726_add_pins.sql (1.53ms)1334niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251218171726_add_pins.sql (1.86ms)1335niks3-go-unit-tests> 2026-09-18 13:11:06.618 UTC [80673] ERROR:  relation "goose_db_version" does not exist at character 361336niks3-go-unit-tests> 2026-09-18 13:11:06.618 UTC [80673] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1337niks3-go-unit-tests> 2026-09-18 13:11:06.637 UTC [80674] ERROR:  relation "goose_db_version" does not exist at character 361338niks3-go-unit-tests> 2026-09-18 13:11:06.637 UTC [80674] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1339niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260628120000_add_object_size_and_stats.sql (27.53ms)1340niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260628120000_add_object_size_and_stats.sql (27.27ms)1341niks3-go-unit-tests> 2026/09/18 13:11:06 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1342niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260905000000_add_claims.sql (12.85ms)1343niks3-go-unit-tests> 2026/09/18 13:11:06 goose: successfully migrated database to version: 202609050000001344niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260905000000_add_claims.sql (19.84ms)1345niks3-go-unit-tests> 2026/09/18 13:11:06 goose: successfully migrated database to version: 202609050000001346niks3-go-unit-tests> 2026/09/18 13:11:06 OK   1_commit_pending_closure.sql (7.6ms)1347niks3-go-unit-tests> 2026/09/18 13:11:06 OK   2_object_stats_trigger.sql (312.88µs)1348niks3-go-unit-tests> 2026/09/18 13:11:06 goose: up to current file version: 21349niks3-go-unit-tests> 2026/09/18 13:11:06 OK   1_commit_pending_closure.sql (1.19ms)1350niks3-go-unit-tests> 2026/09/18 13:11:06 OK   2_object_stats_trigger.sql (242.54µs)1351niks3-go-unit-tests> 2026/09/18 13:11:06 goose: up to current file version: 21352niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Received uploads request method=POST path=/api/pending_closures1353niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1354niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Uploading ih75yar6vw1vf9ncrxzghz508cv25wjq-ca-test (144B)1355niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20241026095416_initial_model.sql (48.78ms)1356niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20241026095416_initial_model.sql (34.96ms)1357niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251210153512_drop_unused_gin_index.sql (1.02ms)1358niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251210153512_drop_unused_gin_index.sql (8.49ms)1359niks3-go-unit-tests> 2026/09/18 13:11:06 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1360niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251218171726_add_pins.sql (17.86ms)1361niks3-go-unit-tests> 2026/09/18 13:11:06 WARN Failed to register uploaded object key=ih75yar6vw1vf9ncrxzghz508cv25wjq.ls error="server returned 404: 404 page not found\n"1362niks3-go-unit-tests> 2026/09/18 13:11:06 WARN Failed to register uploaded object key=log/fyax02zx19r1npxvlfb0gmwbilpf4cbx-ca-test.drv error="server returned 404: 404 page not found\n"1363niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1364niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Signed narinfos id=1 count=11365niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Uploading 1 narinfos1366niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251218171726_add_pins.sql (31.18ms)1367niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1368niks3-go-unit-tests> 2026/09/18 13:11:06 WARN Failed to register uploaded object key=ih75yar6vw1vf9ncrxzghz508cv25wjq.narinfo error="server returned 404: 404 page not found\n"1369niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260628120000_add_object_size_and_stats.sql (27.12ms)1370niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Completed upload id=11371niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Upload complete. (162ms)1372niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260628120000_add_object_size_and_stats.sql (15.82ms)1373niks3-go-unit-tests>     client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-80273-1366931373/TestClientCADerivations3523790260/001/store/ih75yar6vw1vf9ncrxzghz508cv25wjq-ca-test1374niks3-go-unit-tests>         URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1375niks3-go-unit-tests>         Compression: zstd1376niks3-go-unit-tests>         NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1377niks3-go-unit-tests>         NarSize: 1441378niks3-go-unit-tests>         References: 1379niks3-go-unit-tests>         Deriver: /nix/var/nix/builds/nix-80273-1366931373/TestClientCADerivations3523790260/001/store/fyax02zx19r1npxvlfb0gmwbilpf4cbx-ca-test.drv1380niks3-go-unit-tests>         CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1381niks3-go-unit-tests>     client_ca_test.go:185: Checking for realisation files in S3...1382niks3-go-unit-tests>     client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1383niks3-go-unit-tests>     client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1384niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260905000000_add_claims.sql (20.49ms)1385niks3-go-unit-tests> 2026/09/18 13:11:06 goose: successfully migrated database to version: 202609050000001386niks3-go-unit-tests> 2026/09/18 13:11:06 OK   1_commit_pending_closure.sql (957.92µs)1387niks3-go-unit-tests> 2026/09/18 13:11:06 OK   2_object_stats_trigger.sql (250.29µs)1388niks3-go-unit-tests> 2026/09/18 13:11:06 goose: up to current file version: 21389niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20260905000000_add_claims.sql (11.57ms)1390niks3-go-unit-tests> 2026/09/18 13:11:06 goose: successfully migrated database to version: 202609050000001391niks3-go-unit-tests> 2026/09/18 13:11:06 OK   1_commit_pending_closure.sql (804.71µs)1392niks3-go-unit-tests> 2026/09/18 13:11:06 OK   2_object_stats_trigger.sql (196.83µs)1393niks3-go-unit-tests> 2026/09/18 13:11:06 goose: up to current file version: 21394niks3-go-unit-tests> --- PASS: TestService_ReadScope_PublicByDefault (0.89s)1395niks3-go-unit-tests> === CONT  TestOrphanedObjectsGC1396niks3-go-unit-tests> === NAME  TestClientCADerivations1397niks3-go-unit-tests>     client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket23?endpoint=http://localhost:57009&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-80273-1366931373/TestClientCADerivations3523790260/001/store'1398niks3-go-unit-tests>     client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11399niks3-go-unit-tests> --- PASS: TestClientCADerivations (1.98s)1400niks3-go-unit-tests> === CONT  TestParseSingleRange1401niks3-go-unit-tests> === RUN   TestParseSingleRange/none1402niks3-go-unit-tests> === PAUSE TestParseSingleRange/none1403niks3-go-unit-tests> === RUN   TestParseSingleRange/unknown_unit1404niks3-go-unit-tests> === PAUSE TestParseSingleRange/unknown_unit1405niks3-go-unit-tests> === RUN   TestParseSingleRange/multi-range_ignored1406niks3-go-unit-tests> === PAUSE TestParseSingleRange/multi-range_ignored1407niks3-go-unit-tests> === RUN   TestParseSingleRange/malformed_no_dash1408niks3-go-unit-tests> === PAUSE TestParseSingleRange/malformed_no_dash1409niks3-go-unit-tests> === RUN   TestParseSingleRange/malformed_both_empty1410niks3-go-unit-tests> === PAUSE TestParseSingleRange/malformed_both_empty1411niks3-go-unit-tests> === RUN   TestParseSingleRange/malformed_end_before_start1412niks3-go-unit-tests> === PAUSE TestParseSingleRange/malformed_end_before_start1413niks3-go-unit-tests> === RUN   TestParseSingleRange/closed1414niks3-go-unit-tests> === PAUSE TestParseSingleRange/closed1415niks3-go-unit-tests> === RUN   TestParseSingleRange/open-ended1416niks3-go-unit-tests> === PAUSE TestParseSingleRange/open-ended1417niks3-go-unit-tests> === RUN   TestParseSingleRange/end_clamped_to_size1418niks3-go-unit-tests> === PAUSE TestParseSingleRange/end_clamped_to_size1419niks3-go-unit-tests> === RUN   TestParseSingleRange/suffix1420niks3-go-unit-tests> === PAUSE TestParseSingleRange/suffix1421niks3-go-unit-tests> === RUN   TestParseSingleRange/suffix_exceeds_size1422niks3-go-unit-tests> === PAUSE TestParseSingleRange/suffix_exceeds_size1423niks3-go-unit-tests> === RUN   TestParseSingleRange/single_byte1424niks3-go-unit-tests> === PAUSE TestParseSingleRange/single_byte1425niks3-go-unit-tests> === RUN   TestParseSingleRange/start_past_EOF1426niks3-go-unit-tests> === PAUSE TestParseSingleRange/start_past_EOF1427niks3-go-unit-tests> === RUN   TestParseSingleRange/start_far_past_EOF1428niks3-go-unit-tests> === PAUSE TestParseSingleRange/start_far_past_EOF1429niks3-go-unit-tests> === CONT  TestClaim_FailWakesWaitersButIsNotRemembered1430niks3-go-unit-tests> 2026-09-18 13:11:06.880 UTC [80684] ERROR:  relation "goose_db_version" does not exist at character 361431niks3-go-unit-tests> 2026-09-18 13:11:06.880 UTC [80684] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1432niks3-go-unit-tests> 2026/09/18 13:11:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01433niks3-go-unit-tests> === NAME  TestPinProtectsFromGC1434niks3-go-unit-tests>     client_integration_test.go:730: Pin successfully protected closure from garbage collection1435niks3-go-unit-tests> --- PASS: TestPinProtectsFromGC (4.58s)1436niks3-go-unit-tests> === CONT  TestMultipartCleanup1437niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20241026095416_initial_model.sql (75.25ms)1438niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251210153512_drop_unused_gin_index.sql (11.2ms)1439niks3-go-unit-tests> 2026/09/18 13:11:06 OK   20251218171726_add_pins.sql (5.07ms)1440niks3-go-unit-tests> 2026/09/18 13:11:07 OK   20260628120000_add_object_size_and_stats.sql (25.91ms)1441niks3-go-unit-tests> 2026/09/18 13:11:07 WARN claim: cannot clear write deadline error="feature not supported"1442niks3-go-unit-tests> 2026/09/18 13:11:07 WARN claim: cannot clear write deadline error="feature not supported"1443niks3-go-unit-tests> --- PASS: TestClaim_StaleHeartbeatStolen (1.16s)1444niks3-go-unit-tests> === CONT  TestResurrectedObjectNotDeleted1445niks3-go-unit-tests> 2026/09/18 13:11:07 OK   20260905000000_add_claims.sql (34.4ms)1446niks3-go-unit-tests> 2026/09/18 13:11:07 goose: successfully migrated database to version: 202609050000001447niks3-go-unit-tests> 2026/09/18 13:11:07 OK   1_commit_pending_closure.sql (6.44ms)1448niks3-go-unit-tests> 2026/09/18 13:11:07 OK   2_object_stats_trigger.sql (256.08µs)1449niks3-go-unit-tests> 2026/09/18 13:11:07 goose: up to current file version: 21450niks3-go-unit-tests> 2026/09/18 13:11:07 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1451niks3-go-unit-tests> 2026/09/18 13:11:07 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1452niks3-go-unit-tests> --- PASS: TestService_NativeMTLS (1.20s)1453niks3-go-unit-tests> === CONT  TestServerTLSConfig1454niks3-go-unit-tests> === RUN   TestServerTLSConfig/no_client_CA1455niks3-go-unit-tests> === PAUSE TestServerTLSConfig/no_client_CA1456niks3-go-unit-tests> === RUN   TestServerTLSConfig/missing_CA_file1457niks3-go-unit-tests> === PAUSE TestServerTLSConfig/missing_CA_file1458niks3-go-unit-tests> === RUN   TestServerTLSConfig/not_a_PEM_file1459niks3-go-unit-tests> === PAUSE TestServerTLSConfig/not_a_PEM_file1460niks3-go-unit-tests> === CONT  TestClaim_HolderDisconnectKeepsClaim1461niks3-go-unit-tests> 2026/09/18 13:11:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1462niks3-go-unit-tests> 2026/09/18 13:11:07 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002000000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLmZjNTkwZjM5LTg2NjItNDExMi1hNTQ5LTE1OWJjMjRhYjgzMHgxNzg5NzM3MDY2NTE2NjI4MDAw parts=101463niks3-go-unit-tests> 2026/09/18 13:11:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1464niks3-go-unit-tests> 2026/09/18 13:11:07 INFO Completed upload id=11465niks3-go-unit-tests> 2026/09/18 13:11:07 INFO Received uploads request method=POST path=/api/pending_closures1466niks3-go-unit-tests> 2026/09/18 13:11:07 WARN claim: cannot clear write deadline error="feature not supported"1467niks3-go-unit-tests> 2026/09/18 13:11:07 WARN claim: cannot clear write deadline error="feature not supported"1468niks3-go-unit-tests> --- PASS: TestClaim_FailWithoutKindReleases (1.36s)1469niks3-go-unit-tests> === CONT  TestOrphanedObjectsGCStressTest1470niks3-go-unit-tests> --- PASS: TestObjectStatsTrigger (1.42s)1471niks3-go-unit-tests> === CONT  TestReadProxyDisabled1472niks3-go-unit-tests> 2026-09-18 13:11:07.988 UTC [80700] ERROR:  relation "goose_db_version" does not exist at character 361473niks3-go-unit-tests> 2026-09-18 13:11:07.988 UTC [80700] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1474niks3-go-unit-tests> 2026-09-18 13:11:08.062 UTC [80701] ERROR:  relation "goose_db_version" does not exist at character 361475niks3-go-unit-tests> 2026-09-18 13:11:08.062 UTC [80701] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1476niks3-go-unit-tests> 2026/09/18 13:11:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01477niks3-go-unit-tests> === NAME  TestClientIntegration1478niks3-go-unit-tests>     client_integration_test.go:323: Objects in database after GC:1479niks3-go-unit-tests>     client_integration_test.go:323: Successfully deleted all objects with GC --force1480niks3-go-unit-tests> --- PASS: TestClientIntegration (4.23s)1481niks3-go-unit-tests> === CONT  TestReadProxyInvalidPath1482niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20241026095416_initial_model.sql (99.17ms)1483niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20251210153512_drop_unused_gin_index.sql (9.42ms)1484niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20251218171726_add_pins.sql (12.29ms)1485niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20241026095416_initial_model.sql (109.86ms)1486niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20251210153512_drop_unused_gin_index.sql (9.44ms)1487niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20260628120000_add_object_size_and_stats.sql (38.79ms)1488niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20251218171726_add_pins.sql (28.67ms)1489niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20260628120000_add_object_size_and_stats.sql (40.97ms)1490niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20260905000000_add_claims.sql (61.44ms)1491niks3-go-unit-tests> 2026/09/18 13:11:08 goose: successfully migrated database to version: 202609050000001492niks3-go-unit-tests> 2026/09/18 13:11:08 OK   1_commit_pending_closure.sql (3.56ms)1493niks3-go-unit-tests> 2026/09/18 13:11:08 OK   2_object_stats_trigger.sql (590.75µs)1494niks3-go-unit-tests> 2026/09/18 13:11:08 goose: up to current file version: 21495niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20260905000000_add_claims.sql (60.63ms)1496niks3-go-unit-tests> 2026/09/18 13:11:08 goose: successfully migrated database to version: 202609050000001497niks3-go-unit-tests> 2026/09/18 13:11:08 OK   1_commit_pending_closure.sql (9.7ms)1498niks3-go-unit-tests> 2026/09/18 13:11:08 OK   2_object_stats_trigger.sql (707.92µs)1499niks3-go-unit-tests> 2026/09/18 13:11:08 goose: up to current file version: 21500niks3-go-unit-tests> 2026-09-18 13:11:08.417 UTC [80704] ERROR:  relation "goose_db_version" does not exist at character 361501niks3-go-unit-tests> 2026-09-18 13:11:08.417 UTC [80704] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1502niks3-go-unit-tests> 2026-09-18 13:11:08.417 UTC [80705] ERROR:  relation "goose_db_version" does not exist at character 361503niks3-go-unit-tests> 2026-09-18 13:11:08.417 UTC [80705] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1504niks3-go-unit-tests> 2026/09/18 13:11:08 WARN Rate limiter enabled after throttle name=s3-test rate=51505niks3-go-unit-tests> 2026/09/18 13:11:08 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1506niks3-go-unit-tests> === NAME  TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1507niks3-go-unit-tests>     throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101508niks3-go-unit-tests>     throttle_test.go:215: Rate limiter: enabled=true, rate=5.001509niks3-go-unit-tests> --- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.86s)1510niks3-go-unit-tests> === CONT  TestClaim_TooManyStreams1511niks3-go-unit-tests> 2026/09/18 13:11:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1512niks3-go-unit-tests> 2026/09/18 13:11:08 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002100000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLmIwOGY4YWZlLTE4YzctNGJiMy05ODg0LTczZWJjZjEyNGEyMHgxNzg5NzM3MDY3NDE2NTc4MDAw parts=101513niks3-go-unit-tests> 2026/09/18 13:11:08 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1514niks3-go-unit-tests> 2026/09/18 13:11:08 INFO Completed upload id=21515niks3-go-unit-tests> --- PASS: TestPresent (2.96s)1516niks3-go-unit-tests> === CONT  TestCompletedNarNotReofferedAcrossClosures1517niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20241026095416_initial_model.sql (213.2ms)1518niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20241026095416_initial_model.sql (213.15ms)1519niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20251210153512_drop_unused_gin_index.sql (7.14ms)1520niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20251210153512_drop_unused_gin_index.sql (8.11ms)1521niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20251218171726_add_pins.sql (31.47ms)1522niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20251218171726_add_pins.sql (36.18ms)1523niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20260628120000_add_object_size_and_stats.sql (15.12ms)1524niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20260905000000_add_claims.sql (8.46ms)1525niks3-go-unit-tests> 2026/09/18 13:11:08 goose: successfully migrated database to version: 202609050000001526niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20260628120000_add_object_size_and_stats.sql (19.46ms)1527niks3-go-unit-tests> 2026/09/18 13:11:08 OK   1_commit_pending_closure.sql (3.44ms)1528niks3-go-unit-tests> 2026/09/18 13:11:08 OK   2_object_stats_trigger.sql (610µs)1529niks3-go-unit-tests> 2026/09/18 13:11:08 goose: up to current file version: 21530niks3-go-unit-tests> 2026-09-18 13:11:08.779 UTC [80710] ERROR:  relation "goose_db_version" does not exist at character 361531niks3-go-unit-tests> 2026-09-18 13:11:08.779 UTC [80710] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1532niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20260905000000_add_claims.sql (34.04ms)1533niks3-go-unit-tests> 2026/09/18 13:11:08 goose: successfully migrated database to version: 202609050000001534niks3-go-unit-tests> 2026/09/18 13:11:08 OK   1_commit_pending_closure.sql (4.06ms)1535niks3-go-unit-tests> 2026/09/18 13:11:08 OK   2_object_stats_trigger.sql (697.63µs)1536niks3-go-unit-tests> 2026/09/18 13:11:08 goose: up to current file version: 21537niks3-go-unit-tests> 2026/09/18 13:11:08 WARN claim: cannot clear write deadline error="feature not supported"1538niks3-go-unit-tests> 2026/09/18 13:11:08 WARN claim: cannot clear write deadline error="feature not supported"1539niks3-go-unit-tests> 2026/09/18 13:11:08 WARN claim: cannot clear write deadline error="feature not supported"1540niks3-go-unit-tests> --- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (2.05s)1541niks3-go-unit-tests> === CONT  TestReadProxyRootRedirectsToIndexHTML1542niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20241026095416_initial_model.sql (164.4ms)1543niks3-go-unit-tests> 2026/09/18 13:11:08 OK   20251210153512_drop_unused_gin_index.sql (19.69ms)1544niks3-go-unit-tests> 2026-09-18 13:11:09.011 UTC [80714] ERROR:  relation "goose_db_version" does not exist at character 361545niks3-go-unit-tests> 2026-09-18 13:11:09.011 UTC [80714] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1546niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20251218171726_add_pins.sql (26.33ms)1547niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20260628120000_add_object_size_and_stats.sql (33.71ms)1548niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20260905000000_add_claims.sql (72.79ms)1549niks3-go-unit-tests> 2026/09/18 13:11:09 goose: successfully migrated database to version: 202609050000001550niks3-go-unit-tests> 2026/09/18 13:11:09 OK   1_commit_pending_closure.sql (4.47ms)1551niks3-go-unit-tests> 2026/09/18 13:11:09 OK   2_object_stats_trigger.sql (916.5µs)1552niks3-go-unit-tests> 2026/09/18 13:11:09 goose: up to current file version: 21553niks3-go-unit-tests> --- PASS: TestResurrectedObjectNotDeleted (2.20s)1554niks3-go-unit-tests> === CONT  TestClaim_GCMarkedOutputCountsAsAbsent1555niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20241026095416_initial_model.sql (177.93ms)1556niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20251210153512_drop_unused_gin_index.sql (12.29ms)1557niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20251218171726_add_pins.sql (22.18ms)1558niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20260628120000_add_object_size_and_stats.sql (14.08ms)1559niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20260905000000_add_claims.sql (29.21ms)1560niks3-go-unit-tests> 2026/09/18 13:11:09 goose: successfully migrated database to version: 202609050000001561niks3-go-unit-tests> 2026/09/18 13:11:09 OK   1_commit_pending_closure.sql (2.97ms)1562niks3-go-unit-tests> 2026/09/18 13:11:09 OK   2_object_stats_trigger.sql (789.21µs)1563niks3-go-unit-tests> 2026/09/18 13:11:09 goose: up to current file version: 21564niks3-go-unit-tests> === NAME  TestOrphanedObjectsGC1565niks3-go-unit-tests>     orphaned_objects_gc_test.go:290: GC Test Summary:1566niks3-go-unit-tests>     orphaned_objects_gc_test.go:291:   - Kept:    2 objects from closure A1567niks3-go-unit-tests>     orphaned_objects_gc_test.go:292:   - Deleted: 2 objects from closure B1568niks3-go-unit-tests>     orphaned_objects_gc_test.go:293:   - Deleted: 6 orphaned chain objects (X1->X2->X3)1569niks3-go-unit-tests>     orphaned_objects_gc_test.go:294:   - Deleted: 2 orphaned single objects (Y)1570niks3-go-unit-tests>     orphaned_objects_gc_test.go:295:   - Total deleted: 10 objects1571niks3-go-unit-tests> --- PASS: TestOrphanedObjectsGC (2.50s)1572niks3-go-unit-tests> === CONT  TestCompleteMultipartUpload_ErrorButObjectExists1573niks3-go-unit-tests> 2026/09/18 13:11:09 INFO Received uploads request method=POST path=/api/pending_closures1574niks3-go-unit-tests> 2026-09-18 13:11:09.365 UTC [80717] ERROR:  relation "goose_db_version" does not exist at character 361575niks3-go-unit-tests> 2026-09-18 13:11:09.365 UTC [80717] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1576niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20241026095416_initial_model.sql (79.49ms)1577niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20251210153512_drop_unused_gin_index.sql (14.02ms)1578niks3-go-unit-tests> 2026/09/18 13:11:09 INFO Received cleanup request method=DELETE path=/api/pending_closures1579niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20251218171726_add_pins.sql (26.16ms)1580niks3-go-unit-tests> 2026/09/18 13:11:09 INFO Aborted multipart uploads count=11581niks3-go-unit-tests> --- PASS: TestMultipartCleanup (2.65s)1582niks3-go-unit-tests> === CONT  TestReadProxyConditionalGet1583niks3-go-unit-tests> 2026/09/18 13:11:09 WARN claim: cannot clear write deadline error="feature not supported"1584niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20260628120000_add_object_size_and_stats.sql (47.85ms)1585niks3-go-unit-tests> 2026-09-18 13:11:09.602 UTC [80721] ERROR:  relation "goose_db_version" does not exist at character 361586niks3-go-unit-tests> 2026-09-18 13:11:09.602 UTC [80721] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1587niks3-go-unit-tests> 2026/09/18 13:11:09 WARN claim: cannot clear write deadline error="feature not supported"1588niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20260905000000_add_claims.sql (43.75ms)1589niks3-go-unit-tests> 2026/09/18 13:11:09 goose: successfully migrated database to version: 202609050000001590niks3-go-unit-tests> 2026/09/18 13:11:09 OK   1_commit_pending_closure.sql (3.84ms)1591niks3-go-unit-tests> 2026/09/18 13:11:09 OK   2_object_stats_trigger.sql (560.04µs)1592niks3-go-unit-tests> 2026/09/18 13:11:09 goose: up to current file version: 21593niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20241026095416_initial_model.sql (64.78ms)1594niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20251210153512_drop_unused_gin_index.sql (9.09ms)1595niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20251218171726_add_pins.sql (22.93ms)1596niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20260628120000_add_object_size_and_stats.sql (87.99ms)1597niks3-go-unit-tests> 2026/09/18 13:11:09 OK   20260905000000_add_claims.sql (6.61ms)1598niks3-go-unit-tests> 2026/09/18 13:11:09 goose: successfully migrated database to version: 202609050000001599niks3-go-unit-tests> 2026/09/18 13:11:09 OK   1_commit_pending_closure.sql (3.46ms)1600niks3-go-unit-tests> 2026/09/18 13:11:09 OK   2_object_stats_trigger.sql (1.04ms)1601niks3-go-unit-tests> 2026/09/18 13:11:09 goose: up to current file version: 21602niks3-go-unit-tests> 2026-09-18 13:11:09.893 UTC [80724] ERROR:  relation "goose_db_version" does not exist at character 361603niks3-go-unit-tests> 2026-09-18 13:11:09.893 UTC [80724] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1604niks3-go-unit-tests> 2026-09-18 13:11:09.988 UTC [80725] ERROR:  relation "goose_db_version" does not exist at character 361605niks3-go-unit-tests> 2026-09-18 13:11:09.988 UTC [80725] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1606niks3-go-unit-tests> --- PASS: TestReadProxyDisabled (2.39s)1607niks3-go-unit-tests> === CONT  TestReadProxyHead1608niks3-go-unit-tests> 2026/09/18 13:11:10 WARN claim: cannot clear write deadline error="feature not supported"1609niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20241026095416_initial_model.sql (168.25ms)1610niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20251210153512_drop_unused_gin_index.sql (11.88ms)1611niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20251218171726_add_pins.sql (38.25ms)1612niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20260628120000_add_object_size_and_stats.sql (28.96ms)1613niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20241026095416_initial_model.sql (180.53ms)1614niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20251210153512_drop_unused_gin_index.sql (12.84ms)1615niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20260905000000_add_claims.sql (70.44ms)1616niks3-go-unit-tests> 2026/09/18 13:11:10 goose: successfully migrated database to version: 202609050000001617niks3-go-unit-tests> 2026/09/18 13:11:10 OK   1_commit_pending_closure.sql (8.37ms)1618niks3-go-unit-tests> 2026/09/18 13:11:10 OK   2_object_stats_trigger.sql (618.58µs)1619niks3-go-unit-tests> 2026/09/18 13:11:10 goose: up to current file version: 21620niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20251218171726_add_pins.sql (31.83ms)1621niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20260628120000_add_object_size_and_stats.sql (36.27ms)1622niks3-go-unit-tests> --- PASS: TestReadProxyInvalidPath (2.23s)1623niks3-go-unit-tests> === CONT  TestRedundantMultipartUpload1624niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20260905000000_add_claims.sql (52.97ms)1625niks3-go-unit-tests> 2026/09/18 13:11:10 goose: successfully migrated database to version: 202609050000001626niks3-go-unit-tests> 2026/09/18 13:11:10 OK   1_commit_pending_closure.sql (4.9ms)1627niks3-go-unit-tests> 2026/09/18 13:11:10 OK   2_object_stats_trigger.sql (752.92µs)1628niks3-go-unit-tests> 2026/09/18 13:11:10 goose: up to current file version: 21629niks3-go-unit-tests> 2026-09-18 13:11:10.471 UTC [80731] ERROR:  relation "goose_db_version" does not exist at character 361630niks3-go-unit-tests> 2026-09-18 13:11:10.471 UTC [80731] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1631niks3-go-unit-tests> 2026/09/18 13:11:10 WARN claim: cannot clear write deadline error="feature not supported"1632niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20241026095416_initial_model.sql (91.51ms)1633niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20251210153512_drop_unused_gin_index.sql (10.26ms)1634niks3-go-unit-tests> --- PASS: TestClaim_TooManyStreams (2.13s)1635niks3-go-unit-tests> === CONT  TestCacheConfigHandlerMaxNarSize1636niks3-go-unit-tests> --- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1637niks3-go-unit-tests> === CONT  TestMetricsInventory1638niks3-go-unit-tests> 2026-09-18 13:11:10.634 UTC [80733] ERROR:  relation "goose_db_version" does not exist at character 361639niks3-go-unit-tests> 2026-09-18 13:11:10.634 UTC [80733] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1640niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20251218171726_add_pins.sql (27.13ms)1641niks3-go-unit-tests> 2026-09-18 13:11:10.645 UTC [80735] ERROR:  relation "goose_db_version" does not exist at character 361642niks3-go-unit-tests> 2026-09-18 13:11:10.645 UTC [80735] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1643niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20260628120000_add_object_size_and_stats.sql (11.65ms)1644niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20260905000000_add_claims.sql (21.84ms)1645niks3-go-unit-tests> 2026/09/18 13:11:10 goose: successfully migrated database to version: 202609050000001646niks3-go-unit-tests> 2026/09/18 13:11:10 OK   1_commit_pending_closure.sql (2.66ms)1647niks3-go-unit-tests> 2026/09/18 13:11:10 OK   2_object_stats_trigger.sql (430.38µs)1648niks3-go-unit-tests> 2026/09/18 13:11:10 goose: up to current file version: 21649niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20241026095416_initial_model.sql (87.5ms)1650niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20241026095416_initial_model.sql (92.79ms)1651niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20251210153512_drop_unused_gin_index.sql (14.91ms)1652niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20251210153512_drop_unused_gin_index.sql (8.12ms)1653niks3-go-unit-tests> 2026/09/18 13:11:10 INFO Received uploads request method=POST path=/api/pending_closures1654niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20251218171726_add_pins.sql (34.03ms)1655niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20251218171726_add_pins.sql (34.64ms)1656niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20260628120000_add_object_size_and_stats.sql (39.54ms)1657niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20260628120000_add_object_size_and_stats.sql (40.05ms)1658niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20260905000000_add_claims.sql (10.3ms)1659niks3-go-unit-tests> 2026/09/18 13:11:10 goose: successfully migrated database to version: 202609050000001660niks3-go-unit-tests> 2026/09/18 13:11:10 OK   20260905000000_add_claims.sql (11.71ms)1661niks3-go-unit-tests> 2026/09/18 13:11:10 goose: successfully migrated database to version: 202609050000001662niks3-go-unit-tests> 2026/09/18 13:11:10 OK   1_commit_pending_closure.sql (6.03ms)1663niks3-go-unit-tests> 2026/09/18 13:11:10 OK   1_commit_pending_closure.sql (5.66ms)1664niks3-go-unit-tests> 2026/09/18 13:11:10 OK   2_object_stats_trigger.sql (2.55ms)1665niks3-go-unit-tests> 2026/09/18 13:11:10 goose: up to current file version: 21666niks3-go-unit-tests> 2026/09/18 13:11:10 OK   2_object_stats_trigger.sql (1.32ms)1667niks3-go-unit-tests> 2026/09/18 13:11:10 goose: up to current file version: 21668niks3-go-unit-tests> 2026-09-18 13:11:10.894 UTC [80737] ERROR:  relation "goose_db_version" does not exist at character 361669niks3-go-unit-tests> 2026-09-18 13:11:10.894 UTC [80737] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1670niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20241026095416_initial_model.sql (92.09ms)1671niks3-go-unit-tests> --- PASS: TestReadProxyRootRedirectsToIndexHTML (2.15s)1672niks3-go-unit-tests> === CONT  TestReadProxyNarStreaming1673niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20251210153512_drop_unused_gin_index.sql (13.36ms)1674niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20251218171726_add_pins.sql (27.95ms)1675niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20260628120000_add_object_size_and_stats.sql (34.01ms)1676niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20260905000000_add_claims.sql (22.81ms)1677niks3-go-unit-tests> 2026/09/18 13:11:11 goose: successfully migrated database to version: 202609050000001678niks3-go-unit-tests> 2026/09/18 13:11:11 OK   1_commit_pending_closure.sql (3.31ms)1679niks3-go-unit-tests> 2026/09/18 13:11:11 OK   2_object_stats_trigger.sql (563.54µs)1680niks3-go-unit-tests> 2026/09/18 13:11:11 goose: up to current file version: 21681niks3-go-unit-tests> 2026/09/18 13:11:11 INFO Received uploads request method=POST path=/api/pending_closures1682niks3-go-unit-tests> 2026-09-18 13:11:11.353 UTC [80740] ERROR:  relation "goose_db_version" does not exist at character 361683niks3-go-unit-tests> 2026-09-18 13:11:11.353 UTC [80740] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1684niks3-go-unit-tests> 2026/09/18 13:11:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1685niks3-go-unit-tests> 2026/09/18 13:11:11 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLjg3ODg4MTUwLTUzMDctNGZmNi04ZDE2LTlhMGQ0YjIzMDg2Y3gxNzg5NzM3MDcxMzExMjQ2MDAw1686niks3-go-unit-tests> 2026/09/18 13:11:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLjg3ODg4MTUwLTUzMDctNGZmNi04ZDE2LTlhMGQ0YjIzMDg2Y3gxNzg5NzM3MDcxMzExMjQ2MDAw parts=11687niks3-go-unit-tests> --- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.19s)1688niks3-go-unit-tests> === CONT  TestReadRedirectUsesPublicS3URL1689niks3-go-unit-tests> 2026/09/18 13:11:11 INFO Received uploads request method=POST path=/api/pending_closures1690niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20241026095416_initial_model.sql (142.76ms)1691niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20251210153512_drop_unused_gin_index.sql (18.42ms)1692niks3-go-unit-tests> 2026-09-18 13:11:11.597 UTC [80742] ERROR:  relation "goose_db_version" does not exist at character 361693niks3-go-unit-tests> 2026-09-18 13:11:11.597 UTC [80742] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1694niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20251218171726_add_pins.sql (32.27ms)1695niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20260628120000_add_object_size_and_stats.sql (47.48ms)1696niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20260905000000_add_claims.sql (17.49ms)1697niks3-go-unit-tests> 2026/09/18 13:11:11 goose: successfully migrated database to version: 202609050000001698niks3-go-unit-tests> 2026/09/18 13:11:11 OK   1_commit_pending_closure.sql (3.32ms)1699niks3-go-unit-tests> 2026/09/18 13:11:11 OK   2_object_stats_trigger.sql (504.79µs)1700niks3-go-unit-tests> 2026/09/18 13:11:11 goose: up to current file version: 21701niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20241026095416_initial_model.sql (149.86ms)1702niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20251210153512_drop_unused_gin_index.sql (15.48ms)1703niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20251218171726_add_pins.sql (26.8ms)1704niks3-go-unit-tests> --- PASS: TestReadProxyConditionalGet (2.30s)1705niks3-go-unit-tests> === CONT  TestNARDeduplicationMetadataUploadBug1706niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20260628120000_add_object_size_and_stats.sql (16.78ms)1707niks3-go-unit-tests> 2026/09/18 13:11:11 OK   20260905000000_add_claims.sql (76.85ms)1708niks3-go-unit-tests> 2026/09/18 13:11:11 goose: successfully migrated database to version: 202609050000001709niks3-go-unit-tests> 2026/09/18 13:11:11 OK   1_commit_pending_closure.sql (3.1ms)1710niks3-go-unit-tests> 2026/09/18 13:11:11 OK   2_object_stats_trigger.sql (579.42µs)1711niks3-go-unit-tests> 2026/09/18 13:11:11 goose: up to current file version: 21712niks3-go-unit-tests> 2026-09-18 13:11:12.040 UTC [80747] ERROR:  relation "goose_db_version" does not exist at character 361713niks3-go-unit-tests> 2026-09-18 13:11:12.040 UTC [80747] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1714niks3-go-unit-tests> --- PASS: TestClaim_HolderDisconnectKeepsClaim (4.90s)1715niks3-go-unit-tests> === CONT  TestReadProxy4041716niks3-go-unit-tests> --- PASS: TestReadProxyHead (2.05s)1717niks3-go-unit-tests> === CONT  TestReadProxyRangeRequest1718niks3-go-unit-tests> 2026/09/18 13:11:12 OK   20241026095416_initial_model.sql (241.13ms)1719niks3-go-unit-tests> 2026/09/18 13:11:12 OK   20251210153512_drop_unused_gin_index.sql (10.39ms)1720niks3-go-unit-tests> 2026/09/18 13:11:12 OK   20251218171726_add_pins.sql (40.96ms)1721niks3-go-unit-tests> 2026/09/18 13:11:12 INFO Received uploads request method=POST path=/api/pending_closures1722niks3-go-unit-tests> 2026/09/18 13:11:12 OK   20260628120000_add_object_size_and_stats.sql (41.75ms)1723niks3-go-unit-tests> 2026/09/18 13:11:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1724niks3-go-unit-tests> 2026/09/18 13:11:12 OK   20260905000000_add_claims.sql (32.99ms)1725niks3-go-unit-tests> 2026/09/18 13:11:12 goose: successfully migrated database to version: 202609050000001726niks3-go-unit-tests> 2026/09/18 13:11:12 OK   1_commit_pending_closure.sql (22.18ms)1727niks3-go-unit-tests> 2026/09/18 13:11:12 OK   2_object_stats_trigger.sql (489.25µs)1728niks3-go-unit-tests> 2026/09/18 13:11:12 goose: up to current file version: 21729niks3-go-unit-tests> 2026/09/18 13:11:12 INFO Received uploads request method=POST path=/api/pending_closures1730niks3-go-unit-tests> 2026/09/18 13:11:12 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLmIzMzUxNTI5LTJjZjMtNDkxYi05N2RiLWJhM2RjZDg2MjkyMngxNzg5NzM3MDcwODIzODU3MDAw parts=121731niks3-go-unit-tests> 2026/09/18 13:11:12 INFO Received uploads request method=POST path=/api/pending_closures1732niks3-go-unit-tests> --- PASS: TestCompletedNarNotReofferedAcrossClosures (3.86s)1733niks3-go-unit-tests> === CONT  TestCreatePendingClosureRejectsOversizedNAR1734niks3-go-unit-tests> 2026/09/18 13:11:12 INFO Received uploads request method=POST path=/api/pending_closures1735niks3-go-unit-tests> --- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1736niks3-go-unit-tests> === CONT  TestReadRedirectKeepsNarinfoProxied1737niks3-go-unit-tests> --- PASS: TestMetricsInventory (2.19s)1738niks3-go-unit-tests> === CONT  TestReadProxyNarinfoAlreadyDecompressed1739niks3-go-unit-tests> 2026-09-18 13:11:12.853 UTC [80756] ERROR:  relation "goose_db_version" does not exist at character 361740niks3-go-unit-tests> 2026-09-18 13:11:12.853 UTC [80756] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1741niks3-go-unit-tests> 2026/09/18 13:11:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1742niks3-go-unit-tests> 2026/09/18 13:11:12 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLjYxYzNmNjg2LWM5ZWUtNDY5ZS05N2RlLTE5YmZjNDc1ODIwN3gxNzg5NzM3MDcxNTk4OTI4MDAw parts=101743niks3-go-unit-tests> 2026/09/18 13:11:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1744niks3-go-unit-tests> 2026/09/18 13:11:12 INFO Completed upload id=11745niks3-go-unit-tests> 2026/09/18 13:11:12 WARN claim: cannot clear write deadline error="feature not supported"1746niks3-go-unit-tests> 2026/09/18 13:11:12 WARN claim: cannot clear write deadline error="feature not supported"1747niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20241026095416_initial_model.sql (87.1ms)1748niks3-go-unit-tests> --- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (3.76s)1749niks3-go-unit-tests> === CONT  TestReadProxyNarinfo1750niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20251210153512_drop_unused_gin_index.sql (6.97ms)1751niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20251218171726_add_pins.sql (8.72ms)1752niks3-go-unit-tests> 2026-09-18 13:11:13.036 UTC [80759] ERROR:  relation "goose_db_version" does not exist at character 361753niks3-go-unit-tests> 2026-09-18 13:11:13.036 UTC [80759] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1754niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20260628120000_add_object_size_and_stats.sql (28.26ms)1755niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20260905000000_add_claims.sql (31.07ms)1756niks3-go-unit-tests> 2026/09/18 13:11:13 goose: successfully migrated database to version: 202609050000001757niks3-go-unit-tests> 2026/09/18 13:11:13 OK   1_commit_pending_closure.sql (9.8ms)1758niks3-go-unit-tests> 2026/09/18 13:11:13 OK   2_object_stats_trigger.sql (381.75µs)1759niks3-go-unit-tests> 2026/09/18 13:11:13 goose: up to current file version: 21760niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20241026095416_initial_model.sql (149.24ms)1761niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20251210153512_drop_unused_gin_index.sql (9.79ms)1762niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20251218171726_add_pins.sql (12.1ms)1763niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20260628120000_add_object_size_and_stats.sql (49.26ms)1764niks3-go-unit-tests> --- PASS: TestReadProxyNarStreaming (2.29s)1765niks3-go-unit-tests> === CONT  TestReadRedirectNar1766niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20260905000000_add_claims.sql (48.29ms)1767niks3-go-unit-tests> 2026/09/18 13:11:13 goose: successfully migrated database to version: 202609050000001768niks3-go-unit-tests> 2026/09/18 13:11:13 OK   1_commit_pending_closure.sql (3.03ms)1769niks3-go-unit-tests> 2026/09/18 13:11:13 OK   2_object_stats_trigger.sql (1.51ms)1770niks3-go-unit-tests> 2026/09/18 13:11:13 goose: up to current file version: 21771niks3-go-unit-tests> 2026-09-18 13:11:13.428 UTC [80765] ERROR:  relation "goose_db_version" does not exist at character 361772niks3-go-unit-tests> 2026-09-18 13:11:13.428 UTC [80765] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1773niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20241026095416_initial_model.sql (152.24ms)1774niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20251210153512_drop_unused_gin_index.sql (1.93ms)1775niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20251218171726_add_pins.sql (12.73ms)1776niks3-go-unit-tests> --- PASS: TestReadRedirectUsesPublicS3URL (2.12s)1777niks3-go-unit-tests> === CONT  TestService_healthCheckHandler1778niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20260628120000_add_object_size_and_stats.sql (25.93ms)1779niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20260905000000_add_claims.sql (23.25ms)1780niks3-go-unit-tests> 2026/09/18 13:11:13 goose: successfully migrated database to version: 202609050000001781niks3-go-unit-tests> 2026/09/18 13:11:13 OK   1_commit_pending_closure.sql (2.77ms)1782niks3-go-unit-tests> 2026/09/18 13:11:13 OK   2_object_stats_trigger.sql (1.13ms)1783niks3-go-unit-tests> 2026/09/18 13:11:13 goose: up to current file version: 21784niks3-go-unit-tests> 2026-09-18 13:11:13.703 UTC [80768] ERROR:  relation "goose_db_version" does not exist at character 361785niks3-go-unit-tests> 2026-09-18 13:11:13.703 UTC [80768] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1786niks3-go-unit-tests> 2026-09-18 13:11:13.714 UTC [80769] ERROR:  relation "goose_db_version" does not exist at character 361787niks3-go-unit-tests> 2026-09-18 13:11:13.714 UTC [80769] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1788niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20241026095416_initial_model.sql (156.5ms)1789niks3-go-unit-tests> 2026/09/18 13:11:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1790niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20241026095416_initial_model.sql (143ms)1791niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20251210153512_drop_unused_gin_index.sql (10.18ms)1792niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20251210153512_drop_unused_gin_index.sql (31.32ms)1793niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20251218171726_add_pins.sql (38.07ms)1794niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20251218171726_add_pins.sql (8.77ms)1795niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20260628120000_add_object_size_and_stats.sql (15.8ms)1796niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20260628120000_add_object_size_and_stats.sql (17.3ms)1797niks3-go-unit-tests> 2026/09/18 13:11:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTRlYThlYWMtZTA1MC00YzM2LWFhZDgtZjE3OGRiNTA1Y2YzLjA0YjA4MDExLTdhYjAtNDcyNy05MTlmLTk5M2Y2Y2MxMmFjNXgxNzg5NzM3MDcyNDM1OTQyMDAw parts=121798niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20260905000000_add_claims.sql (7.75ms)1799niks3-go-unit-tests> 2026/09/18 13:11:13 goose: successfully migrated database to version: 202609050000001800niks3-go-unit-tests> 2026/09/18 13:11:13 OK   20260905000000_add_claims.sql (8.08ms)1801niks3-go-unit-tests> 2026/09/18 13:11:13 goose: successfully migrated database to version: 202609050000001802niks3-go-unit-tests> --- PASS: TestRedundantMultipartUpload (3.63s)1803niks3-go-unit-tests> === CONT  TestGenerateLandingPage1804niks3-go-unit-tests> 2026/09/18 13:11:13 OK   1_commit_pending_closure.sql (2.71ms)1805niks3-go-unit-tests> 2026/09/18 13:11:13 OK   1_commit_pending_closure.sql (2.6ms)1806niks3-go-unit-tests> 2026/09/18 13:11:13 OK   2_object_stats_trigger.sql (1.1ms)1807niks3-go-unit-tests> 2026/09/18 13:11:13 goose: up to current file version: 21808niks3-go-unit-tests> 2026/09/18 13:11:13 OK   2_object_stats_trigger.sql (1.15ms)1809niks3-go-unit-tests> 2026/09/18 13:11:13 goose: up to current file version: 21810niks3-go-unit-tests> --- PASS: TestGenerateLandingPage (0.00s)1811niks3-go-unit-tests> === CONT  TestService_readinessHandler1812niks3-go-unit-tests> 2026-09-18 13:11:13.993 UTC [80771] ERROR:  relation "goose_db_version" does not exist at character 361813niks3-go-unit-tests> 2026-09-18 13:11:13.993 UTC [80771] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1814niks3-go-unit-tests> 2026-09-18 13:11:14.018 UTC [80773] ERROR:  relation "goose_db_version" does not exist at character 361815niks3-go-unit-tests> 2026-09-18 13:11:14.018 UTC [80773] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1816niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20241026095416_initial_model.sql (89.32ms)1817niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251210153512_drop_unused_gin_index.sql (8.12ms)1818niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20241026095416_initial_model.sql (109.97ms)1819niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251210153512_drop_unused_gin_index.sql (1.9ms)1820niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251218171726_add_pins.sql (16.4ms)1821niks3-go-unit-tests> === NAME  TestNARDeduplicationMetadataUploadBug1822niks3-go-unit-tests>     metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-80273-1366931373/TestNARDeduplicationMetadataUploadBug3828797917/001/store/gkqh41p3wm6n2ri6gm0fh3mkj3kb5dyb-file1.txt1823niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251218171726_add_pins.sql (24.93ms)1824niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260628120000_add_object_size_and_stats.sql (37.27ms)1825niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260628120000_add_object_size_and_stats.sql (16.39ms)1826niks3-go-unit-tests> --- PASS: TestReadProxy404 (2.09s)1827niks3-go-unit-tests> === CONT  TestService_ReadAuthMiddleware1828niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260905000000_add_claims.sql (7.42ms)1829niks3-go-unit-tests> 2026/09/18 13:11:14 goose: successfully migrated database to version: 202609050000001830niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260905000000_add_claims.sql (5.78ms)1831niks3-go-unit-tests> 2026/09/18 13:11:14 goose: successfully migrated database to version: 202609050000001832niks3-go-unit-tests> 2026/09/18 13:11:14 OK   1_commit_pending_closure.sql (1.58ms)1833niks3-go-unit-tests> 2026/09/18 13:11:14 OK   2_object_stats_trigger.sql (319.04µs)1834niks3-go-unit-tests> 2026/09/18 13:11:14 goose: up to current file version: 21835niks3-go-unit-tests> 2026/09/18 13:11:14 OK   1_commit_pending_closure.sql (8.62ms)1836niks3-go-unit-tests> 2026/09/18 13:11:14 OK   2_object_stats_trigger.sql (411.79µs)1837niks3-go-unit-tests> 2026/09/18 13:11:14 goose: up to current file version: 21838niks3-go-unit-tests> === NAME  TestOrphanedObjectsGCStressTest1839niks3-go-unit-tests>     orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1840niks3-go-unit-tests> 2026-09-18 13:11:14.262 UTC [80781] ERROR:  relation "goose_db_version" does not exist at character 361841niks3-go-unit-tests> 2026-09-18 13:11:14.262 UTC [80781] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1842niks3-go-unit-tests> 2026/09/18 13:11:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1843niks3-go-unit-tests>     orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1844niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Received uploads request method=POST path=/api/pending_closures1845niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20241026095416_initial_model.sql (88.02ms)1846niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1847niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Uploading gkqh41p3wm6n2ri6gm0fh3mkj3kb5dyb-file1.txt (160B)1848niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251210153512_drop_unused_gin_index.sql (8.25ms)1849niks3-go-unit-tests> 2026/09/18 13:11:14 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"1850niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251218171726_add_pins.sql (7.2ms)1851niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1852niks3-go-unit-tests> 2026/09/18 13:11:14 WARN Failed to register uploaded object key=gkqh41p3wm6n2ri6gm0fh3mkj3kb5dyb.ls error="server returned 404: 404 page not found\n"1853niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Signed narinfos id=1 count=11854niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Uploading 1 narinfos1855niks3-go-unit-tests> --- PASS: TestReadProxyRangeRequest (2.24s)1856niks3-go-unit-tests> === CONT  TestGracefulShutdownDrainsInflight1857niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Starting HTTP server address=127.0.0.1:572521858niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Shutdown signal received, draining in-flight requests timeout=10s1859niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1860niks3-go-unit-tests> 2026/09/18 13:11:14 WARN Failed to register uploaded object key=gkqh41p3wm6n2ri6gm0fh3mkj3kb5dyb.narinfo error="server returned 404: 404 page not found\n"1861niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260628120000_add_object_size_and_stats.sql (20.14ms)1862niks3-go-unit-tests> 2026-09-18 13:11:14.412 UTC [80785] ERROR:  relation "goose_db_version" does not exist at character 361863niks3-go-unit-tests> 2026-09-18 13:11:14.412 UTC [80785] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1864niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Completed upload id=11865niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Upload complete. (193ms)1866niks3-go-unit-tests> === NAME  TestNARDeduplicationMetadataUploadBug1867niks3-go-unit-tests>     metadata_upload_test.go:54: Retrieved narinfo from S3:1868niks3-go-unit-tests>         StorePath: /nix/var/nix/builds/nix-80273-1366931373/TestNARDeduplicationMetadataUploadBug3828797917/001/store/gkqh41p3wm6n2ri6gm0fh3mkj3kb5dyb-file1.txt1869niks3-go-unit-tests>         URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1870niks3-go-unit-tests>         Compression: zstd1871niks3-go-unit-tests>         NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1872niks3-go-unit-tests>         NarSize: 1601873niks3-go-unit-tests>         References: 1874niks3-go-unit-tests>         CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1875niks3-go-unit-tests>     metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1876niks3-go-unit-tests>     metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1877niks3-go-unit-tests>         {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1878niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260905000000_add_claims.sql (15.06ms)1879niks3-go-unit-tests> 2026/09/18 13:11:14 goose: successfully migrated database to version: 202609050000001880niks3-go-unit-tests> 2026/09/18 13:11:14 OK   1_commit_pending_closure.sql (2.06ms)1881niks3-go-unit-tests> 2026/09/18 13:11:14 OK   2_object_stats_trigger.sql (309.5µs)1882niks3-go-unit-tests> 2026/09/18 13:11:14 goose: up to current file version: 21883niks3-go-unit-tests> === CONT  TestService_AuthMiddleware_MTLSBoundSubjects1884niks3-go-unit-tests> --- PASS: TestGracefulShutdownDrainsInflight (0.07s)1885niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20241026095416_initial_model.sql (44.91ms)1886niks3-go-unit-tests> === NAME  TestNARDeduplicationMetadataUploadBug1887niks3-go-unit-tests>     metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-80273-1366931373/TestNARDeduplicationMetadataUploadBug3828797917/001/store/gwl9kbyd3aw3af9cc3dmfhhvqb6qg1qs-file2.txt1888niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251210153512_drop_unused_gin_index.sql (7.61ms)1889niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251218171726_add_pins.sql (8.19ms)1890niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260628120000_add_object_size_and_stats.sql (14.78ms)1891niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260905000000_add_claims.sql (24.75ms)1892niks3-go-unit-tests> 2026/09/18 13:11:14 goose: successfully migrated database to version: 202609050000001893niks3-go-unit-tests> 2026/09/18 13:11:14 OK   1_commit_pending_closure.sql (1.54ms)1894niks3-go-unit-tests> 2026/09/18 13:11:14 OK   2_object_stats_trigger.sql (254.46µs)1895niks3-go-unit-tests> 2026/09/18 13:11:14 goose: up to current file version: 21896niks3-go-unit-tests> 2026/09/18 13:11:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1897niks3-go-unit-tests> --- PASS: TestReadRedirectKeepsNarinfoProxied (2.05s)1898niks3-go-unit-tests> === CONT  TestService_AuthMiddleware_OIDC1899niks3-go-unit-tests> 2026/09/18 13:11:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57260/oidc1900niks3-go-unit-tests> 2026-09-18 13:11:14.577 UTC [80794] ERROR:  relation "goose_db_version" does not exist at character 361901niks3-go-unit-tests> 2026-09-18 13:11:14.577 UTC [80794] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1902niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Received uploads request method=POST path=/api/pending_closures1903niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1904niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1905niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Signed narinfos id=2 count=11906niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Uploading 1 narinfos1907niks3-go-unit-tests> 2026/09/18 13:11:14 WARN Failed to register uploaded object key=gwl9kbyd3aw3af9cc3dmfhhvqb6qg1qs.ls error="server returned 404: 404 page not found\n"1908niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1909niks3-go-unit-tests> 2026/09/18 13:11:14 WARN Failed to register uploaded object key=gwl9kbyd3aw3af9cc3dmfhhvqb6qg1qs.narinfo error="server returned 404: 404 page not found\n"1910niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Completed upload id=21911niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Upload complete. (107ms)1912niks3-go-unit-tests> === NAME  TestNARDeduplicationMetadataUploadBug1913niks3-go-unit-tests>     metadata_upload_test.go:76: Retrieved narinfo from S3:1914niks3-go-unit-tests>         StorePath: /nix/var/nix/builds/nix-80273-1366931373/TestNARDeduplicationMetadataUploadBug3828797917/001/store/gwl9kbyd3aw3af9cc3dmfhhvqb6qg1qs-file2.txt1915niks3-go-unit-tests>         URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1916niks3-go-unit-tests>         Compression: zstd1917niks3-go-unit-tests>         NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1918niks3-go-unit-tests>         NarSize: 1601919niks3-go-unit-tests>         References: 1920niks3-go-unit-tests>         CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1921niks3-go-unit-tests>     metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1922niks3-go-unit-tests>     metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1923niks3-go-unit-tests>         {"version":1,"root":{"type":"regular","size":44}}1924niks3-go-unit-tests> --- PASS: TestNARDeduplicationMetadataUploadBug (2.78s)1925niks3-go-unit-tests> === CONT  TestService_AuthMiddleware_MTLSProxyHeader1926niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20241026095416_initial_model.sql (54.46ms)1927niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251210153512_drop_unused_gin_index.sql (6.07ms)1928niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251218171726_add_pins.sql (17.43ms)1929niks3-go-unit-tests> --- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.91s)1930niks3-go-unit-tests> === CONT  TestIsValidCachePath/narinfo1931niks3-go-unit-tests> === CONT  TestIsValidCachePath/nix-cache-info1932niks3-go-unit-tests> === CONT  TestIsValidCachePath/realisation1933niks3-go-unit-tests> === CONT  TestIsValidCachePath/log1934niks3-go-unit-tests> === CONT  TestIsValidCachePath/ls1935niks3-go-unit-tests> === CONT  TestIsValidCachePath/nar_uncompressed1936niks3-go-unit-tests> === CONT  TestIsValidCachePath/nar_bz21937niks3-go-unit-tests> === CONT  TestIsValidCachePath/nar_xz1938niks3-go-unit-tests> === CONT  TestIsValidCachePath/nar_zst1939niks3-go-unit-tests> === CONT  TestIsValidCachePath/narinfo_all_nix_base32_chars1940niks3-go-unit-tests> === CONT  TestIsValidCachePath/wrong_extension1941niks3-go-unit-tests> === CONT  TestIsValidCachePath/short_hash1942niks3-go-unit-tests> === CONT  TestIsValidCachePath/invalid_char_e1943niks3-go-unit-tests> === CONT  TestIsValidCachePath/invalid_char_u1944niks3-go-unit-tests> === CONT  TestIsValidCachePath/leading_slash1945niks3-go-unit-tests> === CONT  TestIsValidCachePath/traversal_in_middle1946niks3-go-unit-tests> === CONT  TestIsValidCachePath/empty1947niks3-go-unit-tests> === CONT  TestIsValidCachePath/traversal_parent1948niks3-go-unit-tests> === CONT  TestIsValidCachePath/random_path1949niks3-go-unit-tests> === CONT  TestIsValidCachePath/index.html1950niks3-go-unit-tests> --- PASS: TestIsValidCachePath (0.00s)1951niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/narinfo (0.00s)1952niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1953niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/realisation (0.00s)1954niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/log (0.00s)1955niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/ls (0.00s)1956niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1957niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1958niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/nar_xz (0.00s)1959niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/nar_zst (0.00s)1960niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1961niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1962niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/short_hash (0.00s)1963niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1964niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1965niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/leading_slash (0.00s)1966niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1967niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/empty (0.00s)1968niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1969niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/random_path (0.00s)1970niks3-go-unit-tests>     --- PASS: TestIsValidCachePath/index.html (0.00s)1971niks3-go-unit-tests> === CONT  TestResolveDBConnectionString/flag_wins1972niks3-go-unit-tests> === CONT  TestResolveDBConnectionString/file_when_flag_empty1973niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260628120000_add_object_size_and_stats.sql (34.41ms)1974niks3-go-unit-tests> === CONT  TestResolveDBConnectionString/missing_file_is_an_error1975niks3-go-unit-tests> === CONT  TestResolveDBConnectionString/nothing_configured1976niks3-go-unit-tests> === CONT  TestResolveDBConnectionString/PGHOST_allows_empty1977niks3-go-unit-tests> === CONT  TestUploadHandlersRejectOversizedBody/create_pending_closure1978niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Received uploads request method=POST path=/1979niks3-go-unit-tests> --- PASS: TestResolveDBConnectionString (0.02s)1980niks3-go-unit-tests>     --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1981niks3-go-unit-tests>     --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1982niks3-go-unit-tests>     --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1983niks3-go-unit-tests>     --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1984niks3-go-unit-tests>     --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1985niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260905000000_add_claims.sql (42.7ms)1986niks3-go-unit-tests> 2026/09/18 13:11:14 goose: successfully migrated database to version: 202609050000001987niks3-go-unit-tests> 2026/09/18 13:11:14 OK   1_commit_pending_closure.sql (7.75ms)1988niks3-go-unit-tests> 2026/09/18 13:11:14 OK   2_object_stats_trigger.sql (495.38µs)1989niks3-go-unit-tests> 2026/09/18 13:11:14 goose: up to current file version: 21990niks3-go-unit-tests> 2026-09-18 13:11:14.819 UTC [80801] ERROR:  relation "goose_db_version" does not exist at character 361991niks3-go-unit-tests> 2026-09-18 13:11:14.819 UTC [80801] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1992niks3-go-unit-tests> --- PASS: TestReadProxyNarinfo (1.95s)1993niks3-go-unit-tests> === CONT  TestUploadHandlersRejectOversizedBody/request_more_parts1994niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Received request for more parts method=POST path=/1995niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20241026095416_initial_model.sql (63.76ms)1996niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251210153512_drop_unused_gin_index.sql (8.4ms)1997niks3-go-unit-tests> 2026-09-18 13:11:14.985 UTC [80802] ERROR:  relation "goose_db_version" does not exist at character 361998niks3-go-unit-tests> 2026-09-18 13:11:14.985 UTC [80802] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1999niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20251218171726_add_pins.sql (6.45ms)2000niks3-go-unit-tests> === CONT  TestUploadHandlersRejectOversizedBody/complete_multipart2001niks3-go-unit-tests> 2026/09/18 13:11:14 INFO Received complete multipart upload request method=POST path=/2002niks3-go-unit-tests> 2026/09/18 13:11:14 OK   20260628120000_add_object_size_and_stats.sql (13.47ms)2003niks3-go-unit-tests> === CONT  TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2004niks3-go-unit-tests> 2026/09/18 13:11:15 INFO Received uploads request method=POST path=/2005niks3-go-unit-tests> === CONT  TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2006niks3-go-unit-tests> 2026/09/18 13:11:15 INFO Received complete multipart upload request method=POST path=/2007niks3-go-unit-tests> === CONT  TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2008niks3-go-unit-tests> 2026/09/18 13:11:15 INFO Received request for more parts method=POST path=/2009niks3-go-unit-tests> === CONT  TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2010niks3-go-unit-tests> 2026/09/18 13:11:15 INFO Received uploads request method=POST path=/2011niks3-go-unit-tests> --- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2012niks3-go-unit-tests>     --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2013niks3-go-unit-tests>     --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2014niks3-go-unit-tests>     --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2015niks3-go-unit-tests>     --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2016niks3-go-unit-tests> === CONT  TestIsValidUploadKey/narinfo2017niks3-go-unit-tests> === CONT  TestIsValidUploadKey/realisation_plus_in_output2018niks3-go-unit-tests> === CONT  TestIsValidUploadKey/unknown_type2019niks3-go-unit-tests> === CONT  TestIsValidUploadKey/empty_key2020niks3-go-unit-tests> === CONT  TestIsValidUploadKey/absolute2021niks3-go-unit-tests> === CONT  TestIsValidUploadKey/traversal_nar2022niks3-go-unit-tests> === CONT  TestIsValidUploadKey/traversal2023niks3-go-unit-tests> === CONT  TestIsValidUploadKey/listing_key,_narinfo_type2024niks3-go-unit-tests> === CONT  TestIsValidUploadKey/nar_key,_narinfo_type2025niks3-go-unit-tests> === CONT  TestIsValidUploadKey/narinfo_key,_nar_type2026niks3-go-unit-tests> === CONT  TestIsValidUploadKey/index.html2027niks3-go-unit-tests> === CONT  TestIsValidUploadKey/nix-cache-info2028niks3-go-unit-tests> === CONT  TestIsValidUploadKey/build_log_home-manager_file2029niks3-go-unit-tests> === CONT  TestIsValidUploadKey/realisation2030niks3-go-unit-tests> === CONT  TestIsValidUploadKey/build_log_equals2031niks3-go-unit-tests> === CONT  TestIsValidUploadKey/build_log_question_mark2032niks3-go-unit-tests> === CONT  TestIsValidUploadKey/build_log_plus_in_name2033niks3-go-unit-tests> === CONT  TestIsValidUploadKey/nar_plain2034niks3-go-unit-tests> === CONT  TestIsValidUploadKey/build_log2035niks3-go-unit-tests> === CONT  TestIsValidUploadKey/listing2036niks3-go-unit-tests> === CONT  TestIsValidUploadKey/nar_xz2037niks3-go-unit-tests> === CONT  TestIsValidUploadKey/nar_zst2038niks3-go-unit-tests> --- PASS: TestIsValidUploadKey (0.00s)2039niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/narinfo (0.00s)2040niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2041niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2042niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/empty_key (0.00s)2043niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/absolute (0.00s)2044niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2045niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/traversal (0.00s)2046niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2047niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2048niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2049niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/index.html (0.00s)2050niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2051niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2052niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/realisation (0.00s)2053niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2054niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2055niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2056niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2057niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/build_log (0.00s)2058niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/listing (0.00s)2059niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2060niks3-go-unit-tests>     --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2061niks3-go-unit-tests> === CONT  TestProxyWriteTimeout/narinfo2062niks3-go-unit-tests> === CONT  TestProxyWriteTimeout/10_GiB_nar2063niks3-go-unit-tests> === CONT  TestProxyWriteTimeout/unknown_size2064niks3-go-unit-tests> === CONT  TestProxyWriteTimeout/1_GiB_nar2065niks3-go-unit-tests> --- PASS: TestProxyWriteTimeout (0.00s)2066niks3-go-unit-tests>     --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2067niks3-go-unit-tests>     --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2068niks3-go-unit-tests>     --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2069niks3-go-unit-tests>     --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2070niks3-go-unit-tests> === CONT  TestClientErrorHandling/InvalidStorePath2071niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260905000000_add_claims.sql (14.98ms)2072niks3-go-unit-tests> 2026/09/18 13:11:15 goose: successfully migrated database to version: 202609050000002073niks3-go-unit-tests> 2026/09/18 13:11:15 OK   1_commit_pending_closure.sql (5.32ms)2074niks3-go-unit-tests> 2026/09/18 13:11:15 OK   2_object_stats_trigger.sql (309.25µs)2075niks3-go-unit-tests> 2026/09/18 13:11:15 goose: up to current file version: 22076niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20241026095416_initial_model.sql (60.4ms)2077niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251210153512_drop_unused_gin_index.sql (921.29µs)2078niks3-go-unit-tests> --- PASS: TestReadRedirectNar (1.74s)2079niks3-go-unit-tests> === CONT  TestClientErrorHandling/ServerNotAvailable2080niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251218171726_add_pins.sql (9.49ms)2081niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260628120000_add_object_size_and_stats.sql (19.84ms)2082niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260905000000_add_claims.sql (13.49ms)2083niks3-go-unit-tests> 2026/09/18 13:11:15 goose: successfully migrated database to version: 202609050000002084niks3-go-unit-tests> 2026/09/18 13:11:15 OK   1_commit_pending_closure.sql (15.92ms)2085niks3-go-unit-tests> 2026/09/18 13:11:15 OK   2_object_stats_trigger.sql (286.83µs)2086niks3-go-unit-tests> 2026/09/18 13:11:15 goose: up to current file version: 22087niks3-go-unit-tests> --- PASS: TestService_healthCheckHandler (1.57s)2088niks3-go-unit-tests> === CONT  TestClientErrorHandling/InvalidAuthToken2089niks3-go-unit-tests> 2026-09-18 13:11:15.277 UTC [80810] ERROR:  relation "goose_db_version" does not exist at character 362090niks3-go-unit-tests> 2026-09-18 13:11:15.277 UTC [80810] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2091niks3-go-unit-tests> 2026/09/18 13:11:15 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/present2092niks3-go-unit-tests> --- PASS: TestUploadHandlersRejectOversizedBody (0.05s)2093niks3-go-unit-tests>     --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2094niks3-go-unit-tests>     --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2095niks3-go-unit-tests>     --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.62s)2096niks3-go-unit-tests> === CONT  TestCacheConfigHandler/full_config,_no_issuer2097niks3-go-unit-tests> === CONT  TestCacheConfigHandler/no_signing_keys2098niks3-go-unit-tests> === CONT  TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2099niks3-go-unit-tests> === CONT  TestCacheConfigHandler/no_cache_url_configured2100niks3-go-unit-tests> --- PASS: TestCacheConfigHandler (0.00s)2101niks3-go-unit-tests>     --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2102niks3-go-unit-tests>     --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2103niks3-go-unit-tests>     --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2104niks3-go-unit-tests>     --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2105niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC/builder_may_write2106niks3-go-unit-tests> 2026/09/18 13:11:15 INFO OIDC auth successful provider=test scopes=[write]2107niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC/static_token_may_admin2108niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC/anonymous_may_not_read2109niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC/writer_implies_read2110niks3-go-unit-tests> 2026/09/18 13:11:15 INFO OIDC auth successful provider=test scopes=[write]2111niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC/reader_may_read2112niks3-go-unit-tests> 2026/09/18 13:11:15 INFO OIDC auth successful provider=test scopes=[read]2113niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC/static_token_may_write2114niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC/ops_may_not_write2115niks3-go-unit-tests> 2026/09/18 13:11:15 INFO OIDC auth successful provider=test scopes=[admin]2116niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC/reader_may_not_write2117niks3-go-unit-tests> 2026/09/18 13:11:15 INFO OIDC auth successful provider=test scopes=[read]2118niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC/ops_may_admin2119niks3-go-unit-tests> 2026/09/18 13:11:15 INFO OIDC auth successful provider=test scopes=[admin]2120niks3-go-unit-tests> === CONT  TestService_RequireScope_OIDC/builder_may_not_admin2121niks3-go-unit-tests> 2026/09/18 13:11:15 INFO OIDC auth successful provider=test scopes=[write]2122niks3-go-unit-tests> === CONT  TestParseSingleRange/none2123niks3-go-unit-tests> === CONT  TestParseSingleRange/open-ended2124niks3-go-unit-tests> === CONT  TestParseSingleRange/start_far_past_EOF2125niks3-go-unit-tests> === CONT  TestParseSingleRange/start_past_EOF2126niks3-go-unit-tests> === CONT  TestParseSingleRange/single_byte2127niks3-go-unit-tests> === CONT  TestParseSingleRange/suffix_exceeds_size2128niks3-go-unit-tests> === CONT  TestParseSingleRange/suffix2129niks3-go-unit-tests> === CONT  TestParseSingleRange/end_clamped_to_size2130niks3-go-unit-tests> === CONT  TestParseSingleRange/malformed_both_empty2131niks3-go-unit-tests> === CONT  TestParseSingleRange/closed2132niks3-go-unit-tests> === CONT  TestParseSingleRange/malformed_end_before_start2133niks3-go-unit-tests> === CONT  TestParseSingleRange/multi-range_ignored2134niks3-go-unit-tests> === CONT  TestParseSingleRange/malformed_no_dash2135niks3-go-unit-tests> === CONT  TestParseSingleRange/unknown_unit2136niks3-go-unit-tests> --- PASS: TestParseSingleRange (0.00s)2137niks3-go-unit-tests>     --- PASS: TestParseSingleRange/none (0.00s)2138niks3-go-unit-tests>     --- PASS: TestParseSingleRange/open-ended (0.00s)2139niks3-go-unit-tests>     --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2140niks3-go-unit-tests>     --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2141niks3-go-unit-tests>     --- PASS: TestParseSingleRange/single_byte (0.00s)2142niks3-go-unit-tests>     --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2143niks3-go-unit-tests>     --- PASS: TestParseSingleRange/suffix (0.00s)2144niks3-go-unit-tests>     --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2145niks3-go-unit-tests>     --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2146niks3-go-unit-tests>     --- PASS: TestParseSingleRange/closed (0.00s)2147niks3-go-unit-tests>     --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2148niks3-go-unit-tests>     --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2149niks3-go-unit-tests>     --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2150niks3-go-unit-tests>     --- PASS: TestParseSingleRange/unknown_unit (0.00s)2151niks3-go-unit-tests> === CONT  TestServerTLSConfig/no_client_CA2152niks3-go-unit-tests> === CONT  TestServerTLSConfig/not_a_PEM_file2153niks3-go-unit-tests> --- PASS: TestService_RequireScope_OIDC (1.93s)2154niks3-go-unit-tests>     --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2155niks3-go-unit-tests>     --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2156niks3-go-unit-tests>     --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2157niks3-go-unit-tests>     --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2158niks3-go-unit-tests>     --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2159niks3-go-unit-tests>     --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2160niks3-go-unit-tests>     --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2161niks3-go-unit-tests>     --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2162niks3-go-unit-tests>     --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2163niks3-go-unit-tests>     --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2164niks3-go-unit-tests> === CONT  TestServerTLSConfig/missing_CA_file2165niks3-go-unit-tests> --- PASS: TestServerTLSConfig (0.00s)2166niks3-go-unit-tests>     --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2167niks3-go-unit-tests>     --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2168niks3-go-unit-tests>     --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2169niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20241026095416_initial_model.sql (56.97ms)2170niks3-go-unit-tests> 2026-09-18 13:11:15.363 UTC [80812] ERROR:  relation "goose_db_version" does not exist at character 362171niks3-go-unit-tests> 2026-09-18 13:11:15.363 UTC [80812] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2172niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251210153512_drop_unused_gin_index.sql (8.4ms)2173niks3-go-unit-tests> 2026/09/18 13:11:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.58689ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2174niks3-go-unit-tests> 2026/09/18 13:11:15 WARN readiness check failed error="closed pool"2175niks3-go-unit-tests> --- PASS: TestService_readinessHandler (1.40s)2176niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251218171726_add_pins.sql (34.6ms)2177niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260628120000_add_object_size_and_stats.sql (20.26ms)2178niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260905000000_add_claims.sql (16.67ms)2179niks3-go-unit-tests> 2026/09/18 13:11:15 goose: successfully migrated database to version: 202609050000002180niks3-go-unit-tests> 2026/09/18 13:11:15 OK   1_commit_pending_closure.sql (4.46ms)2181niks3-go-unit-tests> 2026/09/18 13:11:15 OK   2_object_stats_trigger.sql (1.48ms)2182niks3-go-unit-tests> 2026/09/18 13:11:15 goose: up to current file version: 22183niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20241026095416_initial_model.sql (43.57ms)2184niks3-go-unit-tests> 2026-09-18 13:11:15.458 UTC [80813] ERROR:  relation "goose_db_version" does not exist at character 362185niks3-go-unit-tests> 2026-09-18 13:11:15.458 UTC [80813] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2186niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251210153512_drop_unused_gin_index.sql (3.81ms)2187niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251218171726_add_pins.sql (8.38ms)2188niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260628120000_add_object_size_and_stats.sql (17.41ms)2189niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260905000000_add_claims.sql (22.11ms)2190niks3-go-unit-tests> 2026/09/18 13:11:15 goose: successfully migrated database to version: 202609050000002191niks3-go-unit-tests> 2026/09/18 13:11:15 OK   1_commit_pending_closure.sql (1.96ms)2192niks3-go-unit-tests> 2026/09/18 13:11:15 OK   2_object_stats_trigger.sql (244.42µs)2193niks3-go-unit-tests> 2026/09/18 13:11:15 goose: up to current file version: 22194niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20241026095416_initial_model.sql (70.64ms)2195niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251210153512_drop_unused_gin_index.sql (7.64ms)2196niks3-go-unit-tests> 2026/09/18 13:11:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.298293ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2197niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251218171726_add_pins.sql (10.95ms)2198niks3-go-unit-tests> === NAME  TestOrphanedObjectsGCStressTest2199niks3-go-unit-tests>     orphaned_objects_gc_test.go:509: Stress test completed successfully:2200niks3-go-unit-tests>     orphaned_objects_gc_test.go:510:   - Active objects preserved: 202201niks3-go-unit-tests>     orphaned_objects_gc_test.go:511:   - Objects deleted: 2102202niks3-go-unit-tests>     orphaned_objects_gc_test.go:512:   - Total GC'd: 2102203niks3-go-unit-tests> --- PASS: TestOrphanedObjectsGCStressTest (8.13s)2204niks3-go-unit-tests> --- PASS: TestService_ReadAuthMiddleware (1.38s)2205niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260628120000_add_object_size_and_stats.sql (13.81ms)2206niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260905000000_add_claims.sql (13.07ms)2207niks3-go-unit-tests> 2026/09/18 13:11:15 goose: successfully migrated database to version: 202609050000002208niks3-go-unit-tests> 2026/09/18 13:11:15 OK   1_commit_pending_closure.sql (1.9ms)2209niks3-go-unit-tests> 2026/09/18 13:11:15 OK   2_object_stats_trigger.sql (388.58µs)2210niks3-go-unit-tests> 2026/09/18 13:11:15 goose: up to current file version: 22211niks3-go-unit-tests> 2026/09/18 13:11:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"2212niks3-go-unit-tests> 2026/09/18 13:11:15 WARN mTLS auth: bound subjects configured but subject DN unavailable2213niks3-go-unit-tests> 2026/09/18 13:11:15 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2214niks3-go-unit-tests> --- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.26s)2215niks3-go-unit-tests> 2026-09-18 13:11:15.772 UTC [80814] ERROR:  relation "goose_db_version" does not exist at character 362216niks3-go-unit-tests> 2026-09-18 13:11:15.772 UTC [80814] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2217niks3-go-unit-tests> === RUN   TestService_AuthMiddleware_OIDC/valid_OIDC_token2218niks3-go-unit-tests> === PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2219niks3-go-unit-tests> === RUN   TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2220niks3-go-unit-tests> === PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2221niks3-go-unit-tests> === RUN   TestService_AuthMiddleware_OIDC/malformed_token_rejected2222niks3-go-unit-tests> === PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2223niks3-go-unit-tests> === RUN   TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2224niks3-go-unit-tests> === PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2225niks3-go-unit-tests> === CONT  TestService_AuthMiddleware_OIDC/valid_OIDC_token2226niks3-go-unit-tests> === CONT  TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2227niks3-go-unit-tests> === CONT  TestService_AuthMiddleware_OIDC/malformed_token_rejected2228niks3-go-unit-tests> 2026/09/18 13:11:15 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]2229niks3-go-unit-tests> === CONT  TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2230niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20241026095416_initial_model.sql (77.65ms)2231niks3-go-unit-tests> 2026/09/18 13:11:15 INFO OIDC auth successful provider=test scopes=[write]2232niks3-go-unit-tests> 2026/09/18 13:11:15 WARN Authentication failed token_preview=eyJhbGciOi...SSPeM3ZF-A token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2233niks3-go-unit-tests> --- PASS: TestService_AuthMiddleware_OIDC (1.30s)2234niks3-go-unit-tests>     --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2235niks3-go-unit-tests>     --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2236niks3-go-unit-tests>     --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2237niks3-go-unit-tests>     --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2238niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251210153512_drop_unused_gin_index.sql (2.52ms)2239niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251218171726_add_pins.sql (4.97ms)2240niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260628120000_add_object_size_and_stats.sql (11.86ms)2241niks3-go-unit-tests> 2026-09-18 13:11:15.893 UTC [80815] ERROR:  relation "goose_db_version" does not exist at character 362242niks3-go-unit-tests> 2026-09-18 13:11:15.893 UTC [80815] STATEMENT:  SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2243niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260905000000_add_claims.sql (13.57ms)2244niks3-go-unit-tests> 2026/09/18 13:11:15 goose: successfully migrated database to version: 202609050000002245niks3-go-unit-tests> 2026/09/18 13:11:15 OK   1_commit_pending_closure.sql (2.76ms)2246niks3-go-unit-tests> 2026/09/18 13:11:15 OK   2_object_stats_trigger.sql (548.75µs)2247niks3-go-unit-tests> 2026/09/18 13:11:15 goose: up to current file version: 22248niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20241026095416_initial_model.sql (43.48ms)2249niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251210153512_drop_unused_gin_index.sql (1.31ms)2250niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20251218171726_add_pins.sql (12.53ms)2251niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260628120000_add_object_size_and_stats.sql (9.84ms)2252niks3-go-unit-tests> 2026/09/18 13:11:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=852.999432ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2253niks3-go-unit-tests> --- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.35s)2254niks3-go-unit-tests> 2026/09/18 13:11:15 OK   20260905000000_add_claims.sql (22.78ms)2255niks3-go-unit-tests> 2026/09/18 13:11:15 goose: successfully migrated database to version: 202609050000002256niks3-go-unit-tests> 2026/09/18 13:11:16 OK   1_commit_pending_closure.sql (2.8ms)2257niks3-go-unit-tests> 2026/09/18 13:11:16 OK   2_object_stats_trigger.sql (654.33µs)2258niks3-go-unit-tests> 2026/09/18 13:11:16 goose: up to current file version: 22259niks3-go-unit-tests> 2026/09/18 13:11:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2260niks3-go-unit-tests> 2026/09/18 13:11:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2261niks3-go-unit-tests> 2026/09/18 13:11:16 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2262niks3-go-unit-tests> 2026/09/18 13:11:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.621506071s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2263niks3-go-unit-tests> 2026/09/18 13:11:18 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-config2264niks3-go-unit-tests> 2026/09/18 13:11:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.353848ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2265niks3-go-unit-tests> 2026/09/18 13:11:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=371.401744ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2266niks3-go-unit-tests> 2026/09/18 13:11:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=824.817021ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2267niks3-go-unit-tests> 2026/09/18 13:11:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.4539882s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2268niks3-go-unit-tests> 2026/09/18 13:11:21 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"2269niks3-go-unit-tests> 2026/09/18 13:11:21 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_closures2270niks3-go-unit-tests> 2026/09/18 13:11:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.517862ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2271niks3-go-unit-tests> 2026/09/18 13:11:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=410.403028ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2272niks3-go-unit-tests> 2026/09/18 13:11:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=827.912158ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2273niks3-go-unit-tests> 2026/09/18 13:11:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.670345572s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2274niks3-go-unit-tests> --- PASS: TestClientErrorHandling (0.00s)2275niks3-go-unit-tests>     --- PASS: TestClientErrorHandling/InvalidStorePath (1.14s)2276niks3-go-unit-tests>     --- PASS: TestClientErrorHandling/InvalidAuthToken (1.09s)2277niks3-go-unit-tests>     --- PASS: TestClientErrorHandling/ServerNotAvailable (9.75s)2278niks3-go-unit-tests> PASS2279niks3-go-unit-tests> {"timestamp":"2026-09-18T13:11:24.81899Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57090","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1880,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}2280niks3-go-unit-tests> 2026-09-18 13:11:24.932 UTC [80421] LOG:  received smart shutdown request2281niks3-go-unit-tests> 2026-09-18 13:11:24.933 UTC [80421] LOG:  background worker "logical replication launcher" (PID 80431) exited with exit code 12282niks3-go-unit-tests> 2026-09-18 13:11:24.937 UTC [80426] LOG:  shutting down2283niks3-go-unit-tests> 2026-09-18 13:11:24.937 UTC [80426] LOG:  checkpoint starting: shutdown immediate2284niks3-go-unit-tests> 2026-09-18 13:11:25.996 UTC [80426] LOG:  checkpoint complete: wrote 12818 buffers (78.2%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.699 s, sync=0.358 s, total=1.060 s; sync files=21338, longest=0.001 s, average=0.001 s; distance=292395 kB, estimate=292395 kB; lsn=0/13517F38, redo lsn=0/13517F382285niks3-go-unit-tests> 2026-09-18 13:11:26.002 UTC [80421] LOG:  database system is shut down2286niks3-go-unit-tests> Running OIDC tests...