niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #277
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestDoWithRetry_BodyReplayedViaGetBody96=== CONT TestScriptTokenScriptFails97=== CONT TestSetClientTLSDoesNotMutateDefaultTransport98=== CONT TestScriptTokenBadJSON99=== CONT TestScriptTokenEmptyCommand100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestScriptTokenNoExpiryRerunsEveryCall102=== CONT TestScriptTokenEmptyToken103=== CONT TestScriptTokenCachesUntilRefresh104=== CONT TestFileTokenMissing105=== CONT TestFileTokenReadsAndCaches106--- PASS: TestFileTokenMissing (0.00s)107=== CONT TestStaticToken108--- PASS: TestStaticToken (0.00s)109=== CONT TestFileTokenEmpty1102026/09/29 08:16:25 WARN Rate limiter enabled after throttle name=server-test rate=51112026/09/29 08:16:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:56074112--- PASS: TestScriptTokenScriptFails (0.00s)113=== CONT TestSetClientTLSErrors1142026/09/29 08:16:25 WARN Rate limiter backed off name=server-test rate=5115--- PASS: TestFileTokenReadsAndCaches (0.00s)116=== CONT TestStreamPushGivesUpOnDeadServer117--- PASS: TestFileTokenEmpty (0.00s)1182026/09/29 08:16:25 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:56074119=== CONT TestStreamPushReportsEveryPath120--- PASS: TestDoServerRequestAttachesToken (0.01s)121=== CONT TestSetClientTLS1222026/09/29 08:16:25 ERROR Upload failed error="connection refused" count=201232026/09/29 08:16:25 ERROR Server seems unavailable, giving up on batch untried=17124--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)125--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)126=== CONT TestClientSignaturesByStorePath127=== CONT TestStreamPushIsolatesFailures128=== CONT TestStreamPushReportsSignatures129--- PASS: TestClientSignaturesByStorePath (0.00s)130--- PASS: TestStreamPushReportsEveryPath (0.00s)131--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)132=== CONT TestStreamPushRequestLine1332026/09/29 08:16:25 ERROR Upload failed error="bad path" count=31342026/09/29 08:16:25 ERROR Upload failed error=boom count=1135--- PASS: TestStreamPushReportsSignatures (0.00s)136=== CONT TestShellSplitErrors137--- PASS: TestShellSplitErrors (0.00s)138=== CONT TestStreamPushBatchesUnderLoad139--- PASS: TestStreamPushIsolatesFailures (0.00s)140=== CONT TestEncodeNixBase32WithRealHash141=== CONT TestResolveStorePath1422026/09/29 08:16:25 ERROR Upload failed error=boom count=1143--- PASS: TestEncodeNixBase32WithRealHash (0.00s)144=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1452026/09/29 08:16:25 WARN Rate limiter enabled after throttle name=server-test rate=5146--- PASS: TestResolveStorePath (0.00s)147=== CONT TestRateLimiterFeedback148=== RUN TestRateLimiterFeedback/429_enables_limiter149=== PAUSE TestRateLimiterFeedback/429_enables_limiter150=== RUN TestRateLimiterFeedback/503_enables_limiter151=== PAUSE TestRateLimiterFeedback/503_enables_limiter152=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter153=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter154=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter155=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter156=== CONT TestPathInfoCACompatibility157=== RUN TestPathInfoCACompatibility/null_ca_field158=== PAUSE TestPathInfoCACompatibility/null_ca_field159=== RUN TestPathInfoCACompatibility/old_string_format_-_text160=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text161=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive162=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive163=== RUN TestPathInfoCACompatibility/new_structured_format_-_text164=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text165=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method166=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method167=== CONT TestParsePathInfoJSONMultiplePaths168=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths169=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths170=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths171=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths172=== RUN TestSetClientTLSErrors/missing_cert_file173=== CONT TestParsePathInfoJSON174=== RUN TestParsePathInfoJSON/Nix_format175=== PAUSE TestSetClientTLSErrors/missing_cert_file176=== RUN TestSetClientTLSErrors/missing_key_file177=== PAUSE TestParsePathInfoJSON/Nix_format178=== RUN TestParsePathInfoJSON/Lix_format179=== PAUSE TestSetClientTLSErrors/missing_key_file180=== RUN TestSetClientTLSErrors/missing_ca_file181=== PAUSE TestSetClientTLSErrors/missing_ca_file182=== RUN TestSetClientTLSErrors/invalid_ca_file183=== PAUSE TestSetClientTLSErrors/invalid_ca_file184=== PAUSE TestParsePathInfoJSON/Lix_format185=== RUN TestParsePathInfoJSON/empty_input186=== PAUSE TestParsePathInfoJSON/empty_input187=== RUN TestParsePathInfoJSON/whitespace_only188=== PAUSE TestParsePathInfoJSON/whitespace_only189=== RUN TestParsePathInfoJSON/invalid_JSON190=== PAUSE TestParsePathInfoJSON/invalid_JSON191=== CONT TestPathInfoHashCompatibility192=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)193=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)194=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon195=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon196=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI197=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI198=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512199=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512200=== CONT TestGetStorePathHash201=== RUN TestGetStorePathHash/valid_store_path202=== PAUSE TestGetStorePathHash/valid_store_path203=== CONT TestConvertHashToNix32204=== RUN TestConvertHashToNix32/SRI_format_to_Nix32205=== RUN TestGetStorePathHash/basename_without_hyphen_should_error206=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32207=== RUN TestConvertHashToNix32/already_Nix32_format208=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error209=== PAUSE TestConvertHashToNix32/already_Nix32_format210=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error211=== RUN TestConvertHashToNix32/invalid_format212=== PAUSE TestConvertHashToNix32/invalid_format213=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error214=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error215=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error216=== CONT TestShellSplit217=== CONT TestDumpPathWriterError218--- PASS: TestShellSplit (0.00s)219=== CONT TestEncodeNixBase32220=== RUN TestEncodeNixBase32/test_string_hash221=== PAUSE TestEncodeNixBase32/test_string_hash222=== RUN TestEncodeNixBase32/empty_input223=== PAUSE TestEncodeNixBase32/empty_input224=== CONT TestDumpPathSingleFile225=== RUN TestSetClientTLS/rejects_connection_without_client_cert226=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert227=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA228=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA229=== RUN TestSetClientTLS/preserves_debug_logging_transport230=== PAUSE TestSetClientTLS/preserves_debug_logging_transport231=== CONT TestUploadMultipart_SupersededByPeer232=== RUN TestUploadMultipart_SupersededByPeer/exists233=== PAUSE TestUploadMultipart_SupersededByPeer/exists234=== RUN TestUploadMultipart_SupersededByPeer/missing235=== PAUSE TestUploadMultipart_SupersededByPeer/missing236=== CONT TestDumpPathMatchesNix237--- PASS: TestScriptTokenEmptyToken (0.01s)238--- PASS: TestScriptTokenBadJSON (0.01s)239=== CONT TestFilterOversizedClosures240=== RUN TestFilterOversizedClosures/no_limit_keeps_everything241=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything242=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped243=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped244=== RUN TestFilterOversizedClosures/all_closures_skipped245=== PAUSE TestFilterOversizedClosures/all_closures_skipped246=== CONT TestPartSizeForNAR247=== RUN TestPartSizeForNAR/zero_stays_at_minimum248=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum249=== RUN TestPartSizeForNAR/small_stays_at_minimum250=== PAUSE TestPartSizeForNAR/small_stays_at_minimum251=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum252=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum253=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts254=== CONT TestCaseHackSuffix255=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts256=== RUN TestPartSizeForNAR/1_TiB257=== PAUSE TestPartSizeForNAR/1_TiB258=== RUN TestPartSizeForNAR/5_TiB_S3_max_object259=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object260=== RUN TestPartSizeForNAR/capped_at_5_GiB261=== PAUSE TestPartSizeForNAR/capped_at_5_GiB262=== CONT TestUploadMultipart_PartsInParallel263--- PASS: TestStreamPushRequestLine (0.01s)264=== CONT TestRegisterUploadedObjectReusesConnections265--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)266=== CONT TestRateLimiterFeedback/429_enables_limiter2672026/09/29 08:16:25 WARN Rate limiter enabled after throttle name=server-test rate=52682026/09/29 08:16:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:561502692026/09/29 08:16:25 WARN Rate limiter backed off name=server-test rate=5270=== CONT TestPathInfoCACompatibility/null_ca_field271=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter272--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)273=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter274--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)275=== CONT TestRateLimiterFeedback/503_enables_limiter276=== CONT TestPathInfoCACompatibility/new_structured_format_-_text277=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2782026/09/29 08:16:25 WARN Rate limiter enabled after throttle name=server-test rate=5279=== CONT TestPathInfoCACompatibility/old_string_format_-_text280=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive2812026/09/29 08:16:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:56156282--- PASS: TestPathInfoCACompatibility (0.00s)283 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)284 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)285 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)286 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)287 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)288=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths289=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths290=== CONT TestSetClientTLSErrors/missing_cert_file2912026/09/29 08:16:25 WARN Rate limiter backed off name=server-test rate=5292--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)293 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)294 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)295=== CONT TestParsePathInfoJSON/Nix_format296--- PASS: TestRateLimiterFeedback (0.00s)297 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)298 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)299 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)300 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)301=== CONT TestSetClientTLSErrors/invalid_ca_file302=== CONT TestSetClientTLSErrors/missing_ca_file303=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)304=== CONT TestParsePathInfoJSON/Lix_format305=== CONT TestParsePathInfoJSON/invalid_JSON306=== CONT TestSetClientTLSErrors/missing_key_file307=== CONT TestParsePathInfoJSON/empty_input308=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512309=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI310=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon311--- PASS: TestPathInfoHashCompatibility (0.00s)312 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)313 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)314 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)315 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)316=== CONT TestGetStorePathHash/valid_store_path317=== CONT TestParsePathInfoJSON/whitespace_only318=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error319=== CONT TestGetStorePathHash/basename_without_hyphen_should_error320--- PASS: TestParsePathInfoJSON (0.00s)321 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)322 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)323 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)324 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)325 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)326=== CONT TestConvertHashToNix32/invalid_format327=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error328--- PASS: TestGetStorePathHash (0.00s)329 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)330 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)331 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)332 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)333=== CONT TestConvertHashToNix32/already_Nix32_format334=== CONT TestEncodeNixBase32/empty_input335=== CONT TestSetClientTLS/rejects_connection_without_client_cert336=== CONT TestEncodeNixBase32/test_string_hash337=== CONT TestConvertHashToNix32/SRI_format_to_Nix32338=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA339--- PASS: TestEncodeNixBase32 (0.00s)340 --- PASS: TestEncodeNixBase32/empty_input (0.00s)341 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)342--- PASS: TestConvertHashToNix32 (0.00s)343 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)344 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)345 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)346=== CONT TestSetClientTLS/preserves_debug_logging_transport347--- PASS: TestSetClientTLSErrors (0.00s)348 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)349 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)350 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)351 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)352=== CONT TestUploadMultipart_SupersededByPeer/exists353=== CONT TestUploadMultipart_SupersededByPeer/missing354=== CONT TestFilterOversizedClosures/no_limit_keeps_everything355=== CONT TestFilterOversizedClosures/all_closures_skipped3562026/09/29 08:16:25 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=50357=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3582026/09/29 08:16:25 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=2000359--- PASS: TestFilterOversizedClosures (0.00s)360 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)361 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)362 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)363=== CONT TestPartSizeForNAR/zero_stays_at_minimum364=== CONT TestPartSizeForNAR/1_TiB365=== CONT TestPartSizeForNAR/capped_at_5_GiB366=== CONT TestPartSizeForNAR/5_TiB_S3_max_object367=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum368=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts369=== CONT TestPartSizeForNAR/small_stays_at_minimum370--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)371 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)372 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)373--- PASS: TestPartSizeForNAR (0.00s)374 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)376 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)377 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)378 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)379 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)380 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)381--- PASS: TestDumpPathWriterError (0.05s)3822026/09/29 08:16:25 http: TLS handshake error from 127.0.0.1:56158: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestCaseHackSuffix (0.05s)388--- PASS: TestDumpPathSingleFile (0.05s)389--- PASS: TestDumpPathMatchesNix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld1".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-9113-1245729578/postgres3866469551/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-9113-1245729578/postgres3866469551/data -l logfile start421422/nix/var/nix/builds/nix-9113-1245729578/postgres3866469551:5432 - no response4232026-09-29 08:16:26.800 UTC [9169] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-09-29 08:16:26.800 UTC [9169] LOG: listening on Unix socket "/nix/var/nix/builds/nix-9113-1245729578/postgres3866469551/.s.PGSQL.5432"4252026-09-29 08:16:26.802 UTC [9176] LOG: database system was shut down at 2026-09-29 08:16:26 UTC4262026-09-29 08:16:26.803 UTC [9169] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-9113-1245729578/postgres3866469551:5432 - accepting connections428{"timestamp":"2026-09-29T08:16:28.851114Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"83597f22-dcfb-41f2-886f-b5b5c33426e7","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}429{"timestamp":"2026-09-29T08:16:28.95276Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1f498f64-42e4-4942-bb15-fb1f8fdc0eeb","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-09-29 08:16:29.102 UTC [9232] ERROR: relation "goose_db_version" does not exist at character 364722026-09-29 08:16:29.102 UTC [9232] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/09/29 08:16:29 OK 20241026095416_initial_model.sql (2.95ms)4742026/09/29 08:16:29 OK 20251210153512_drop_unused_gin_index.sql (564.79µs)4752026/09/29 08:16:29 OK 20251218171726_add_pins.sql (789.96µs)4762026/09/29 08:16:29 OK 20260628120000_add_object_size_and_stats.sql (767.67µs)4772026/09/29 08:16:29 OK 20260905000000_add_claims.sql (894.92µs)4782026/09/29 08:16:29 OK 20260920000000_drop_claims.sql (536.67µs)4792026/09/29 08:16:29 OK 20260923120000_add_pushes.sql (358.71µs)4802026/09/29 08:16:29 goose: successfully migrated database to version: 202609231200004812026/09/29 08:16:29 OK 1_commit_pending_closure.sql (785.38µs)4822026/09/29 08:16:29 OK 2_object_stats_trigger.sql (193.63µs)4832026/09/29 08:16:29 OK 3_commit_push.sql (193.21µs)4842026/09/29 08:16:29 goose: up to current file version: 34852026/09/29 08:16:29 INFO lead: acquired remote=192.0.2.1:12344862026/09/29 08:16:29 INFO lead: released remote=192.0.2.1:12344872026/09/29 08:16:29 INFO lead: acquired remote=192.0.2.1:12344882026/09/29 08:16:29 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.76s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-09-29 08:16:29.902 UTC [9242] ERROR: relation "goose_db_version" does not exist at character 364942026-09-29 08:16:29.902 UTC [9242] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/09/29 08:16:29 OK 20241026095416_initial_model.sql (3.48ms)4962026/09/29 08:16:29 OK 20251210153512_drop_unused_gin_index.sql (564.96µs)4972026/09/29 08:16:29 OK 20251218171726_add_pins.sql (908.13µs)4982026/09/29 08:16:29 OK 20260628120000_add_object_size_and_stats.sql (938.92µs)4992026/09/29 08:16:29 OK 20260905000000_add_claims.sql (975.83µs)5002026/09/29 08:16:29 OK 20260920000000_drop_claims.sql (611.63µs)5012026/09/29 08:16:29 OK 20260923120000_add_pushes.sql (408.46µs)5022026/09/29 08:16:29 goose: successfully migrated database to version: 202609231200005032026/09/29 08:16:29 OK 1_commit_pending_closure.sql (872.08µs)5042026/09/29 08:16:29 OK 2_object_stats_trigger.sql (228.58µs)5052026/09/29 08:16:29 OK 3_commit_push.sql (210.67µs)5062026/09/29 08:16:29 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.15s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestGCTaskStore_StartNew513=== PAUSE TestGCTaskStore_StartNew514=== RUN TestGCTaskStore_DeduplicateSameParams515=== PAUSE TestGCTaskStore_DeduplicateSameParams516=== RUN TestGCTaskStore_ConflictDifferentParams517=== PAUSE TestGCTaskStore_ConflictDifferentParams518=== RUN TestGCTaskStore_GetEmpty519=== PAUSE TestGCTaskStore_GetEmpty520=== RUN TestGCTaskStore_GetReturnsLatest521=== PAUSE TestGCTaskStore_GetReturnsLatest522=== RUN TestGCTaskStore_CompletedAllowsNewTask523=== PAUSE TestGCTaskStore_CompletedAllowsNewTask524=== RUN TestGCTaskStore_PhaseUpdates525=== PAUSE TestGCTaskStore_PhaseUpdates526=== RUN TestGCTaskStore_Fail527=== PAUSE TestGCTaskStore_Fail528=== RUN TestGracefulShutdownDrainsInflight529=== PAUSE TestGracefulShutdownDrainsInflight530=== RUN TestService_healthCheckHandler531=== PAUSE TestService_healthCheckHandler532=== RUN TestService_readinessHandler533=== PAUSE TestService_readinessHandler534=== RUN TestGenerateLandingPage535=== PAUSE TestGenerateLandingPage536=== RUN TestCacheConfigHandlerMaxNarSize537=== PAUSE TestCacheConfigHandlerMaxNarSize538=== RUN TestCreatePendingClosureRejectsOversizedNAR539=== PAUSE TestCreatePendingClosureRejectsOversizedNAR540=== RUN TestNARDeduplicationMetadataUploadBug541=== PAUSE TestNARDeduplicationMetadataUploadBug542=== RUN TestMetricsInventory543=== PAUSE TestMetricsInventory544=== RUN TestService_NativeMTLS545=== PAUSE TestService_NativeMTLS546=== RUN TestServerTLSConfig547=== PAUSE TestServerTLSConfig548=== RUN TestMultipartCleanup549=== PAUSE TestMultipartCleanup550=== RUN TestObjectStatsTrigger551=== PAUSE TestObjectStatsTrigger552=== RUN TestOrphanedObjectsGC553=== PAUSE TestOrphanedObjectsGC554=== RUN TestOrphanedObjectsGCStressTest555=== PAUSE TestOrphanedObjectsGCStressTest556=== RUN TestResurrectedObjectNotDeleted557=== PAUSE TestResurrectedObjectNotDeleted558=== RUN TestCreatePin_ReservedPins559=== PAUSE TestCreatePin_ReservedPins560=== RUN TestParseSingleRange561=== PAUSE TestParseSingleRange562=== RUN TestProxyHeadersOnlyTrustedOnSocket563=== PAUSE TestProxyHeadersOnlyTrustedOnSocket564=== RUN TestIsValidCachePath565=== PAUSE TestIsValidCachePath566=== RUN TestReadProxyNarinfo567=== PAUSE TestReadProxyNarinfo568=== RUN TestReadProxyNarinfoAlreadyDecompressed569=== PAUSE TestReadProxyNarinfoAlreadyDecompressed570=== RUN TestReadProxyNarStreaming571=== PAUSE TestReadProxyNarStreaming572=== RUN TestReadProxy404573=== PAUSE TestReadProxy404574=== RUN TestReadProxyInvalidPath575=== PAUSE TestReadProxyInvalidPath576=== RUN TestReadProxyHead577=== PAUSE TestReadProxyHead578=== RUN TestReadProxyConditionalGet579=== PAUSE TestReadProxyConditionalGet580=== RUN TestReadProxyRootRedirectsToIndexHTML581=== PAUSE TestReadProxyRootRedirectsToIndexHTML582=== RUN TestReadProxyDisabled583=== PAUSE TestReadProxyDisabled584=== RUN TestReadRedirectNar585=== PAUSE TestReadRedirectNar586=== RUN TestReadRedirectKeepsNarinfoProxied587=== PAUSE TestReadRedirectKeepsNarinfoProxied588=== RUN TestReadProxyRangeRequest589=== PAUSE TestReadProxyRangeRequest590=== RUN TestReadRedirectUsesPublicS3URL591=== PAUSE TestReadRedirectUsesPublicS3URL592=== RUN TestPush_OverlappingRootsStoreOneRowPerKey593=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey594=== RUN TestPush_CompleteCommitsEveryRoot595=== PAUSE TestPush_CompleteCommitsEveryRoot596=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected597=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected598=== RUN TestPush_RejectsBadRequests599=== PAUSE TestPush_RejectsBadRequests600=== RUN TestPush_SignsNarinfosOfItsPendingObjects601=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects602=== RUN TestRedundantMultipartUpload603=== PAUSE TestRedundantMultipartUpload604=== RUN TestCompleteMultipartUpload_ErrorButObjectExists605=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists606=== RUN TestCompletedNarNotReofferedAcrossClosures607=== PAUSE TestCompletedNarNotReofferedAcrossClosures608=== RUN TestPresignedUploadRegisteredBeforeCommit609=== PAUSE TestPresignedUploadRegisteredBeforeCommit610=== RUN TestService_Rustfstest611=== PAUSE TestService_Rustfstest612=== RUN TestParseSize613=== PAUSE TestParseSize614=== RUN TestSkippedUploadsHandler615=== PAUSE TestSkippedUploadsHandler616=== RUN TestSystemdListenerNotActivated617--- PASS: TestSystemdListenerNotActivated (0.00s)618=== RUN TestWatchdogBeatsWhenHealthy619--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)620=== RUN TestWatchdogSkipsWhenUnhealthy6212026/09/29 08:16:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/29 08:16:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/29 08:16:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/29 08:16:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/29 08:16:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/29 08:16:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/29 08:16:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/29 08:16:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/29 08:16:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6302026/09/29 08:16:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"631--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)632=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle634=== RUN TestProxyWriteTimeout635=== PAUSE TestProxyWriteTimeout636=== RUN TestIsValidUploadKey637=== PAUSE TestIsValidUploadKey638=== RUN TestUploadHandlersRejectInvalidKeys639=== PAUSE TestUploadHandlersRejectInvalidKeys640=== RUN TestUploadHandlersRejectOversizedBody641=== PAUSE TestUploadHandlersRejectOversizedBody642=== RUN TestService_cleanupPendingClosuresHandler643=== PAUSE TestService_cleanupPendingClosuresHandler644=== RUN TestService_createPendingClosureHandler645=== PAUSE TestService_createPendingClosureHandler646=== RUN TestService_verifyS3Integrity647=== PAUSE TestService_verifyS3Integrity648=== RUN TestCompleteMultipartUnregistered649=== PAUSE TestCompleteMultipartUnregistered650=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT651=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT652=== CONT TestService_AuthMiddleware653=== CONT TestOrphanedObjectsGC654=== CONT TestPush_CompleteCommitsEveryRoot655=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle656=== CONT TestCompletedNarNotReofferedAcrossClosures657=== CONT TestReadProxyInvalidPath658=== CONT TestPush_OverlappingRootsStoreOneRowPerKey659=== CONT TestReadRedirectUsesPublicS3URL660=== CONT TestReadProxyRangeRequest661=== CONT TestReadRedirectKeepsNarinfoProxied6622026-09-29 08:16:30.461 UTC [9274] ERROR: relation "goose_db_version" does not exist at character 366632026-09-29 08:16:30.461 UTC [9274] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6642026-09-29 08:16:30.474 UTC [9275] ERROR: relation "goose_db_version" does not exist at character 366652026-09-29 08:16:30.474 UTC [9275] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6662026-09-29 08:16:30.475 UTC [9276] ERROR: relation "goose_db_version" does not exist at character 366672026-09-29 08:16:30.475 UTC [9276] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6682026-09-29 08:16:30.475 UTC [9277] ERROR: relation "goose_db_version" does not exist at character 366692026-09-29 08:16:30.475 UTC [9277] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6702026-09-29 08:16:30.478 UTC [9278] ERROR: relation "goose_db_version" does not exist at character 366712026-09-29 08:16:30.478 UTC [9278] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6722026/09/29 08:16:30 OK 20241026095416_initial_model.sql (9.09ms)6732026-09-29 08:16:30.478 UTC [9281] ERROR: relation "goose_db_version" does not exist at character 366742026-09-29 08:16:30.478 UTC [9281] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6752026-09-29 08:16:30.478 UTC [9279] ERROR: relation "goose_db_version" does not exist at character 366762026-09-29 08:16:30.478 UTC [9279] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6772026-09-29 08:16:30.478 UTC [9280] ERROR: relation "goose_db_version" does not exist at character 366782026-09-29 08:16:30.478 UTC [9280] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6792026-09-29 08:16:30.479 UTC [9283] ERROR: relation "goose_db_version" does not exist at character 366802026-09-29 08:16:30.479 UTC [9283] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6812026/09/29 08:16:30 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)6822026-09-29 08:16:30.480 UTC [9282] ERROR: relation "goose_db_version" does not exist at character 366832026-09-29 08:16:30.480 UTC [9282] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6842026/09/29 08:16:30 OK 20251218171726_add_pins.sql (2.88ms)6852026/09/29 08:16:30 OK 20260628120000_add_object_size_and_stats.sql (2.28ms)6862026/09/29 08:16:30 OK 20260905000000_add_claims.sql (2.66ms)6872026/09/29 08:16:30 OK 20241026095416_initial_model.sql (8.59ms)6882026/09/29 08:16:30 OK 20251210153512_drop_unused_gin_index.sql (885.83µs)6892026/09/29 08:16:30 OK 20241026095416_initial_model.sql (8.36ms)6902026/09/29 08:16:30 OK 20260920000000_drop_claims.sql (1.61ms)6912026/09/29 08:16:30 OK 20241026095416_initial_model.sql (9.44ms)6922026/09/29 08:16:30 OK 20251210153512_drop_unused_gin_index.sql (592.46µs)6932026/09/29 08:16:30 OK 20241026095416_initial_model.sql (8.08ms)6942026/09/29 08:16:30 OK 20260923120000_add_pushes.sql (1.06ms)6952026/09/29 08:16:30 goose: successfully migrated database to version: 202609231200006962026/09/29 08:16:30 OK 20251210153512_drop_unused_gin_index.sql (775.04µs)6972026/09/29 08:16:30 OK 20241026095416_initial_model.sql (8.32ms)6982026/09/29 08:16:30 OK 20251210153512_drop_unused_gin_index.sql (803.92µs)6992026/09/29 08:16:30 OK 20241026095416_initial_model.sql (9.45ms)7002026/09/29 08:16:30 OK 20241026095416_initial_model.sql (9.1ms)7012026/09/29 08:16:30 OK 20251218171726_add_pins.sql (2.4ms)7022026/09/29 08:16:30 OK 20251210153512_drop_unused_gin_index.sql (891.79µs)7032026/09/29 08:16:30 OK 1_commit_pending_closure.sql (1.18ms)7042026/09/29 08:16:30 OK 20241026095416_initial_model.sql (9.49ms)7052026/09/29 08:16:30 OK 20251210153512_drop_unused_gin_index.sql (780.5µs)7062026/09/29 08:16:30 OK 20251218171726_add_pins.sql (2ms)7072026/09/29 08:16:30 OK 20251210153512_drop_unused_gin_index.sql (906.46µs)7082026/09/29 08:16:30 OK 2_object_stats_trigger.sql (624.17µs)7092026/09/29 08:16:30 OK 20251210153512_drop_unused_gin_index.sql (687.54µs)7102026/09/29 08:16:30 OK 3_commit_push.sql (389.38µs)7112026/09/29 08:16:30 goose: up to current file version: 37122026/09/29 08:16:30 OK 20251218171726_add_pins.sql (1.25ms)7132026/09/29 08:16:30 OK 20251218171726_add_pins.sql (2.39ms)7142026/09/29 08:16:30 OK 20251218171726_add_pins.sql (2.07ms)7152026/09/29 08:16:30 OK 20241026095416_initial_model.sql (8.78ms)7162026/09/29 08:16:30 OK 20251218171726_add_pins.sql (1.44ms)7172026/09/29 08:16:30 OK 20260628120000_add_object_size_and_stats.sql (2.33ms)7182026/09/29 08:16:30 OK 20260628120000_add_object_size_and_stats.sql (2.06ms)7192026/09/29 08:16:30 OK 20251218171726_add_pins.sql (2.29ms)7202026/09/29 08:16:30 OK 20260628120000_add_object_size_and_stats.sql (1.52ms)7212026/09/29 08:16:30 OK 20251210153512_drop_unused_gin_index.sql (938.54µs)7222026/09/29 08:16:30 OK 20251218171726_add_pins.sql (2.47ms)7232026/09/29 08:16:30 OK 20260628120000_add_object_size_and_stats.sql (2.06ms)7242026/09/29 08:16:30 OK 20260628120000_add_object_size_and_stats.sql (1.73ms)7252026/09/29 08:16:30 OK 20260905000000_add_claims.sql (1.86ms)7262026/09/29 08:16:30 OK 20260628120000_add_object_size_and_stats.sql (1.5ms)7272026/09/29 08:16:30 OK 20260628120000_add_object_size_and_stats.sql (2.82ms)7282026/09/29 08:16:30 OK 20260628120000_add_object_size_and_stats.sql (1.55ms)7292026/09/29 08:16:30 OK 20251218171726_add_pins.sql (2.02ms)7302026/09/29 08:16:30 OK 20260905000000_add_claims.sql (11.49ms)7312026/09/29 08:16:30 OK 20260920000000_drop_claims.sql (9.92ms)7322026/09/29 08:16:30 OK 20260905000000_add_claims.sql (11.3ms)7332026/09/29 08:16:30 OK 20260905000000_add_claims.sql (10.94ms)7342026/09/29 08:16:30 OK 20260920000000_drop_claims.sql (16.7ms)7352026/09/29 08:16:30 OK 20260905000000_add_claims.sql (26.67ms)7362026/09/29 08:16:30 OK 20260923120000_add_pushes.sql (16.84ms)7372026/09/29 08:16:30 goose: successfully migrated database to version: 202609231200007382026/09/29 08:16:30 OK 20260905000000_add_claims.sql (26.78ms)7392026/09/29 08:16:30 OK 20260905000000_add_claims.sql (27.1ms)7402026/09/29 08:16:30 OK 1_commit_pending_closure.sql (1.34ms)7412026/09/29 08:16:30 OK 20260920000000_drop_claims.sql (18.07ms)7422026/09/29 08:16:30 OK 20260923120000_add_pushes.sql (1.74ms)7432026/09/29 08:16:30 goose: successfully migrated database to version: 202609231200007442026/09/29 08:16:30 OK 2_object_stats_trigger.sql (300.63µs)7452026/09/29 08:16:30 OK 3_commit_push.sql (203.63µs)7462026/09/29 08:16:30 goose: up to current file version: 37472026/09/29 08:16:30 OK 1_commit_pending_closure.sql (713.83µs)7482026/09/29 08:16:30 OK 2_object_stats_trigger.sql (178.79µs)7492026/09/29 08:16:30 OK 3_commit_push.sql (188.5µs)7502026/09/29 08:16:30 goose: up to current file version: 37512026/09/29 08:16:30 OK 20260905000000_add_claims.sql (31.25ms)7522026/09/29 08:16:30 OK 20260920000000_drop_claims.sql (21.82ms)7532026/09/29 08:16:30 OK 20260920000000_drop_claims.sql (5.17ms)7542026/09/29 08:16:30 OK 20260628120000_add_object_size_and_stats.sql (31.21ms)7552026/09/29 08:16:30 OK 20260920000000_drop_claims.sql (5.12ms)7562026/09/29 08:16:30 OK 20260920000000_drop_claims.sql (5.21ms)7572026/09/29 08:16:30 OK 20260923120000_add_pushes.sql (3.84ms)7582026/09/29 08:16:30 goose: successfully migrated database to version: 202609231200007592026/09/29 08:16:30 OK 20260920000000_drop_claims.sql (1.12ms)7602026/09/29 08:16:30 OK 1_commit_pending_closure.sql (828.67µs)7612026/09/29 08:16:30 OK 20260923120000_add_pushes.sql (952.25µs)7622026/09/29 08:16:30 goose: successfully migrated database to version: 202609231200007632026/09/29 08:16:30 OK 20260923120000_add_pushes.sql (956.25µs)7642026/09/29 08:16:30 goose: successfully migrated database to version: 202609231200007652026/09/29 08:16:30 OK 20260923120000_add_pushes.sql (1.28ms)7662026/09/29 08:16:30 goose: successfully migrated database to version: 202609231200007672026/09/29 08:16:30 OK 2_object_stats_trigger.sql (279µs)7682026/09/29 08:16:30 OK 3_commit_push.sql (213.79µs)7692026/09/29 08:16:30 goose: up to current file version: 37702026/09/29 08:16:30 OK 1_commit_pending_closure.sql (670.46µs)7712026/09/29 08:16:30 OK 1_commit_pending_closure.sql (729.83µs)7722026/09/29 08:16:30 OK 1_commit_pending_closure.sql (728µs)7732026/09/29 08:16:30 OK 2_object_stats_trigger.sql (181.79µs)7742026/09/29 08:16:30 OK 2_object_stats_trigger.sql (185.63µs)7752026/09/29 08:16:30 OK 2_object_stats_trigger.sql (161.63µs)7762026/09/29 08:16:30 OK 3_commit_push.sql (162.96µs)7772026/09/29 08:16:30 goose: up to current file version: 37782026/09/29 08:16:30 OK 3_commit_push.sql (165.08µs)7792026/09/29 08:16:30 goose: up to current file version: 37802026/09/29 08:16:30 OK 3_commit_push.sql (170.5µs)7812026/09/29 08:16:30 goose: up to current file version: 37822026/09/29 08:16:30 OK 20260923120000_add_pushes.sql (7.74ms)7832026/09/29 08:16:30 goose: successfully migrated database to version: 202609231200007842026/09/29 08:16:30 OK 1_commit_pending_closure.sql (682.25µs)7852026/09/29 08:16:30 OK 2_object_stats_trigger.sql (158.5µs)7862026/09/29 08:16:30 OK 3_commit_push.sql (161.25µs)7872026/09/29 08:16:30 goose: up to current file version: 37882026/09/29 08:16:30 OK 20260923120000_add_pushes.sql (7.88ms)7892026/09/29 08:16:30 goose: successfully migrated database to version: 202609231200007902026/09/29 08:16:30 OK 1_commit_pending_closure.sql (620.08µs)7912026/09/29 08:16:30 OK 2_object_stats_trigger.sql (176.38µs)7922026/09/29 08:16:30 OK 3_commit_push.sql (166.42µs)7932026/09/29 08:16:30 goose: up to current file version: 37942026/09/29 08:16:30 OK 20260905000000_add_claims.sql (16.81ms)7952026/09/29 08:16:30 OK 20260920000000_drop_claims.sql (5.54ms)7962026/09/29 08:16:30 OK 20260923120000_add_pushes.sql (642.08µs)7972026/09/29 08:16:30 goose: successfully migrated database to version: 202609231200007982026/09/29 08:16:30 OK 1_commit_pending_closure.sql (731.46µs)7992026/09/29 08:16:30 OK 2_object_stats_trigger.sql (199.38µs)8002026/09/29 08:16:30 OK 3_commit_push.sql (176.29µs)8012026/09/29 08:16:30 goose: up to current file version: 3802--- PASS: TestReadProxyInvalidPath (0.39s)803=== CONT TestReadRedirectNar804--- PASS: TestReadRedirectKeepsNarinfoProxied (0.54s)805=== CONT TestReadProxyDisabled806--- PASS: TestReadProxyRangeRequest (0.71s)807=== CONT TestReadProxyRootRedirectsToIndexHTML8082026/09/29 08:16:31 INFO Received push request method=POST path=/api/pushes8092026/09/29 08:16:31 INFO Received complete push request method=POST path=/api/pushes/1/complete810--- PASS: TestPush_CompleteCommitsEveryRoot (0.93s)811=== CONT TestReadProxyConditionalGet812--- PASS: TestReadRedirectUsesPublicS3URL (1.03s)813=== CONT TestReadProxyHead8142026-09-29 08:16:31.275 UTC [9304] ERROR: relation "goose_db_version" does not exist at character 368152026-09-29 08:16:31.275 UTC [9304] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/09/29 08:16:31 OK 20241026095416_initial_model.sql (50.86ms)8172026/09/29 08:16:31 OK 20251210153512_drop_unused_gin_index.sql (5.6ms)8182026/09/29 08:16:31 OK 20251218171726_add_pins.sql (13.03ms)8192026/09/29 08:16:31 INFO Received push request method=POST path=/api/pushes8202026-09-29 08:16:31.383 UTC [9310] ERROR: relation "goose_db_version" does not exist at character 368212026-09-29 08:16:31.383 UTC [9310] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8222026/09/29 08:16:31 OK 20260628120000_add_object_size_and_stats.sql (17.05ms)8232026/09/29 08:16:31 OK 20260905000000_add_claims.sql (64.71ms)824--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.25s)825=== CONT TestService_Rustfstest8262026/09/29 08:16:31 OK 20260920000000_drop_claims.sql (13.21ms)8272026/09/29 08:16:31 OK 20260923120000_add_pushes.sql (19.83ms)8282026/09/29 08:16:31 goose: successfully migrated database to version: 202609231200008292026/09/29 08:16:31 OK 1_commit_pending_closure.sql (1.49ms)8302026/09/29 08:16:31 OK 2_object_stats_trigger.sql (357.71µs)8312026/09/29 08:16:31 OK 3_commit_push.sql (213.42µs)8322026/09/29 08:16:31 goose: up to current file version: 38332026/09/29 08:16:31 OK 20241026095416_initial_model.sql (63.43ms)8342026-09-29 08:16:31.500 UTC [9313] ERROR: relation "goose_db_version" does not exist at character 368352026-09-29 08:16:31.500 UTC [9313] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8362026/09/29 08:16:31 OK 20251210153512_drop_unused_gin_index.sql (7ms)8372026/09/29 08:16:31 OK 20251218171726_add_pins.sql (4.92ms)8382026/09/29 08:16:31 OK 20260628120000_add_object_size_and_stats.sql (17.39ms)8392026/09/29 08:16:31 OK 20260905000000_add_claims.sql (12.21ms)8402026/09/29 08:16:31 OK 20260920000000_drop_claims.sql (21.65ms)8412026/09/29 08:16:31 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"842--- PASS: TestService_AuthMiddleware (1.36s)843=== CONT TestGCBugBareHashReferences8442026/09/29 08:16:31 OK 20260923120000_add_pushes.sql (13.98ms)8452026/09/29 08:16:31 goose: successfully migrated database to version: 202609231200008462026/09/29 08:16:31 OK 1_commit_pending_closure.sql (1.31ms)8472026/09/29 08:16:31 OK 2_object_stats_trigger.sql (335.42µs)8482026/09/29 08:16:31 OK 3_commit_push.sql (288.25µs)8492026/09/29 08:16:31 goose: up to current file version: 38502026/09/29 08:16:31 OK 20241026095416_initial_model.sql (79.61ms)8512026/09/29 08:16:31 OK 20251210153512_drop_unused_gin_index.sql (5.05ms)8522026/09/29 08:16:31 OK 20251218171726_add_pins.sql (3.17ms)8532026/09/29 08:16:31 OK 20260628120000_add_object_size_and_stats.sql (16.85ms)8542026/09/29 08:16:31 OK 20260905000000_add_claims.sql (6.04ms)8552026/09/29 08:16:31 OK 20260920000000_drop_claims.sql (12.12ms)8562026/09/29 08:16:31 OK 20260923120000_add_pushes.sql (5.45ms)8572026/09/29 08:16:31 goose: successfully migrated database to version: 202609231200008582026/09/29 08:16:31 OK 1_commit_pending_closure.sql (1.58ms)8592026/09/29 08:16:31 OK 2_object_stats_trigger.sql (301.75µs)8602026/09/29 08:16:31 OK 3_commit_push.sql (261µs)8612026/09/29 08:16:31 goose: up to current file version: 38622026/09/29 08:16:31 INFO Received uploads request method=POST path=/api/pending_closures8632026-09-29 08:16:31.821 UTC [9316] ERROR: relation "goose_db_version" does not exist at character 368642026-09-29 08:16:31.821 UTC [9316] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8652026/09/29 08:16:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8662026/09/29 08:16:31 OK 20241026095416_initial_model.sql (138.51ms)8672026/09/29 08:16:32 OK 20251210153512_drop_unused_gin_index.sql (12.47ms)8682026/09/29 08:16:32 OK 20251218171726_add_pins.sql (21.4ms)8692026/09/29 08:16:32 OK 20260628120000_add_object_size_and_stats.sql (21.79ms)8702026-09-29 08:16:32.070 UTC [9317] ERROR: relation "goose_db_version" does not exist at character 368712026-09-29 08:16:32.070 UTC [9317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8722026/09/29 08:16:32 OK 20260905000000_add_claims.sql (42.14ms)8732026/09/29 08:16:32 INFO Received uploads request method=POST path=/api/pending_closures8742026/09/29 08:16:32 OK 20260920000000_drop_claims.sql (25.26ms)8752026/09/29 08:16:32 OK 20260923120000_add_pushes.sql (10.71ms)8762026/09/29 08:16:32 goose: successfully migrated database to version: 202609231200008772026/09/29 08:16:32 OK 1_commit_pending_closure.sql (4.3ms)8782026/09/29 08:16:32 OK 2_object_stats_trigger.sql (1.31ms)8792026/09/29 08:16:32 OK 3_commit_push.sql (702.13µs)8802026/09/29 08:16:32 goose: up to current file version: 38812026/09/29 08:16:32 OK 20241026095416_initial_model.sql (100ms)8822026/09/29 08:16:32 OK 20251210153512_drop_unused_gin_index.sql (10.07ms)8832026/09/29 08:16:32 OK 20251218171726_add_pins.sql (31.86ms)8842026/09/29 08:16:32 OK 20260628120000_add_object_size_and_stats.sql (44.36ms)885--- PASS: TestReadRedirectNar (1.76s)886=== CONT TestMultipartCleanup8872026/09/29 08:16:32 OK 20260905000000_add_claims.sql (69.83ms)8882026/09/29 08:16:32 OK 20260920000000_drop_claims.sql (38.83ms)8892026/09/29 08:16:32 OK 20260923120000_add_pushes.sql (15.09ms)8902026/09/29 08:16:32 goose: successfully migrated database to version: 202609231200008912026/09/29 08:16:32 OK 1_commit_pending_closure.sql (1.02ms)8922026/09/29 08:16:32 OK 2_object_stats_trigger.sql (239.08µs)8932026/09/29 08:16:32 OK 3_commit_push.sql (208.88µs)8942026/09/29 08:16:32 goose: up to current file version: 3895=== NAME TestOrphanedObjectsGC896 orphaned_objects_gc_test.go:290: GC Test Summary:897 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A898 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B899 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)900 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)901 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects902--- PASS: TestOrphanedObjectsGC (2.31s)903=== CONT TestServerTLSConfig904=== RUN TestServerTLSConfig/no_client_CA905=== PAUSE TestServerTLSConfig/no_client_CA906=== RUN TestServerTLSConfig/missing_CA_file907=== PAUSE TestServerTLSConfig/missing_CA_file908=== RUN TestServerTLSConfig/not_a_PEM_file909=== PAUSE TestServerTLSConfig/not_a_PEM_file910=== CONT TestService_NativeMTLS911--- PASS: TestReadProxyDisabled (1.84s)912=== CONT TestMetricsInventory9132026-09-29 08:16:32.654 UTC [9327] ERROR: relation "goose_db_version" does not exist at character 369142026-09-29 08:16:32.654 UTC [9327] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026-09-29 08:16:32.690 UTC [9328] ERROR: relation "goose_db_version" does not exist at character 369162026-09-29 08:16:32.690 UTC [9328] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9172026/09/29 08:16:32 OK 20241026095416_initial_model.sql (94.45ms)9182026/09/29 08:16:32 OK 20251210153512_drop_unused_gin_index.sql (14.1ms)919--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.92s)920=== CONT TestReadProxy4049212026/09/29 08:16:32 OK 20251218171726_add_pins.sql (24.14ms)9222026/09/29 08:16:32 OK 20260628120000_add_object_size_and_stats.sql (19.39ms)9232026/09/29 08:16:32 OK 20241026095416_initial_model.sql (126.44ms)9242026/09/29 08:16:32 OK 20251210153512_drop_unused_gin_index.sql (10.67ms)9252026/09/29 08:16:32 OK 20260905000000_add_claims.sql (55.8ms)9262026/09/29 08:16:32 OK 20251218171726_add_pins.sql (38.3ms)9272026/09/29 08:16:32 OK 20260920000000_drop_claims.sql (20.43ms)9282026/09/29 08:16:32 OK 20260628120000_add_object_size_and_stats.sql (8.63ms)9292026/09/29 08:16:32 OK 20260923120000_add_pushes.sql (18.55ms)9302026/09/29 08:16:32 goose: successfully migrated database to version: 202609231200009312026/09/29 08:16:32 OK 20260905000000_add_claims.sql (20.59ms)9322026/09/29 08:16:32 OK 1_commit_pending_closure.sql (4.22ms)9332026/09/29 08:16:32 OK 2_object_stats_trigger.sql (831.83µs)9342026/09/29 08:16:32 OK 3_commit_push.sql (650.63µs)9352026/09/29 08:16:32 goose: up to current file version: 39362026/09/29 08:16:32 OK 20260920000000_drop_claims.sql (30.89ms)9372026/09/29 08:16:33 OK 20260923120000_add_pushes.sql (17.4ms)9382026/09/29 08:16:33 goose: successfully migrated database to version: 202609231200009392026/09/29 08:16:33 OK 1_commit_pending_closure.sql (2.56ms)9402026/09/29 08:16:33 OK 2_object_stats_trigger.sql (595.38µs)9412026/09/29 08:16:33 OK 3_commit_push.sql (576.17µs)9422026/09/29 08:16:33 goose: up to current file version: 3943--- PASS: TestReadProxyConditionalGet (1.90s)944=== CONT TestReadProxyNarStreaming945--- PASS: TestReadProxyHead (2.01s)946=== CONT TestReadProxyNarinfoAlreadyDecompressed947--- PASS: TestService_Rustfstest (1.98s)948=== CONT TestReadProxyNarinfo9492026/09/29 08:16:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9502026/09/29 08:16:33 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjEyNGRmYjQtODZmMi00MzVjLWIxZGMtZWJjYWI4ZmVmYzA2Ljg1Y2Y2ZDIxLTY1YmQtNGM5OC1iOGM3LTBlZGU0NjdhMWI2MngxNzkwNjY5NzkyMTI3NTc4MDAw parts=129512026/09/29 08:16:33 INFO Received uploads request method=POST path=/api/pending_closures952--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.34s)953=== CONT TestIsValidCachePath954=== RUN TestIsValidCachePath/narinfo955=== PAUSE TestIsValidCachePath/narinfo956=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars957=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars958=== RUN TestIsValidCachePath/nar_zst959=== PAUSE TestIsValidCachePath/nar_zst960=== RUN TestIsValidCachePath/nar_xz961=== PAUSE TestIsValidCachePath/nar_xz962=== RUN TestIsValidCachePath/nar_bz2963=== PAUSE TestIsValidCachePath/nar_bz2964=== RUN TestIsValidCachePath/nar_uncompressed965=== PAUSE TestIsValidCachePath/nar_uncompressed966=== RUN TestIsValidCachePath/ls967=== PAUSE TestIsValidCachePath/ls968=== RUN TestIsValidCachePath/log969=== PAUSE TestIsValidCachePath/log970=== RUN TestIsValidCachePath/realisation971=== PAUSE TestIsValidCachePath/realisation972=== RUN TestIsValidCachePath/nix-cache-info973=== PAUSE TestIsValidCachePath/nix-cache-info974=== RUN TestIsValidCachePath/index.html975=== PAUSE TestIsValidCachePath/index.html976=== RUN TestIsValidCachePath/traversal_parent977=== PAUSE TestIsValidCachePath/traversal_parent978=== RUN TestIsValidCachePath/traversal_in_middle979=== PAUSE TestIsValidCachePath/traversal_in_middle980=== RUN TestIsValidCachePath/invalid_char_e981=== PAUSE TestIsValidCachePath/invalid_char_e982=== RUN TestIsValidCachePath/invalid_char_u983=== PAUSE TestIsValidCachePath/invalid_char_u984=== RUN TestIsValidCachePath/random_path985=== PAUSE TestIsValidCachePath/random_path986=== RUN TestIsValidCachePath/empty987=== PAUSE TestIsValidCachePath/empty988=== RUN TestIsValidCachePath/leading_slash989=== PAUSE TestIsValidCachePath/leading_slash990=== RUN TestIsValidCachePath/wrong_extension991=== PAUSE TestIsValidCachePath/wrong_extension992=== RUN TestIsValidCachePath/short_hash993=== PAUSE TestIsValidCachePath/short_hash994=== CONT TestProxyHeadersOnlyTrustedOnSocket9952026-09-29 08:16:33.631 UTC [9339] ERROR: relation "goose_db_version" does not exist at character 369962026-09-29 08:16:33.631 UTC [9339] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9972026-09-29 08:16:33.713 UTC [9340] ERROR: relation "goose_db_version" does not exist at character 369982026-09-29 08:16:33.713 UTC [9340] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9992026-09-29 08:16:33.713 UTC [9341] ERROR: relation "goose_db_version" does not exist at character 3610002026-09-29 08:16:33.713 UTC [9341] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10012026/09/29 08:16:33 OK 20241026095416_initial_model.sql (49.87ms)10022026/09/29 08:16:33 OK 20251210153512_drop_unused_gin_index.sql (608.38µs)10032026/09/29 08:16:33 OK 20251218171726_add_pins.sql (2.03ms)10042026/09/29 08:16:33 OK 20260628120000_add_object_size_and_stats.sql (1.69ms)10052026/09/29 08:16:33 OK 20260905000000_add_claims.sql (3.07ms)10062026/09/29 08:16:33 OK 20260920000000_drop_claims.sql (1.33ms)10072026/09/29 08:16:33 OK 20241026095416_initial_model.sql (7.23ms)10082026/09/29 08:16:33 OK 20251210153512_drop_unused_gin_index.sql (633.29µs)10092026/09/29 08:16:33 OK 20241026095416_initial_model.sql (9.39ms)10102026/09/29 08:16:33 OK 20251218171726_add_pins.sql (835.42µs)10112026/09/29 08:16:33 OK 20251210153512_drop_unused_gin_index.sql (397.79µs)10122026/09/29 08:16:33 OK 20260923120000_add_pushes.sql (2.04ms)10132026/09/29 08:16:33 goose: successfully migrated database to version: 2026092312000010142026/09/29 08:16:33 OK 1_commit_pending_closure.sql (932.75µs)10152026/09/29 08:16:33 OK 2_object_stats_trigger.sql (222.25µs)10162026/09/29 08:16:33 OK 3_commit_push.sql (189.54µs)10172026/09/29 08:16:33 goose: up to current file version: 310182026/09/29 08:16:33 OK 20251218171726_add_pins.sql (13.63ms)10192026/09/29 08:16:33 OK 20260628120000_add_object_size_and_stats.sql (25.06ms)10202026/09/29 08:16:33 OK 20260628120000_add_object_size_and_stats.sql (19.15ms)10212026/09/29 08:16:33 OK 20260905000000_add_claims.sql (18.3ms)10222026/09/29 08:16:33 OK 20260905000000_add_claims.sql (11.39ms)10232026/09/29 08:16:33 OK 20260920000000_drop_claims.sql (2.14ms)10242026/09/29 08:16:33 OK 20260920000000_drop_claims.sql (1.39ms)10252026/09/29 08:16:33 OK 20260923120000_add_pushes.sql (10.14ms)10262026/09/29 08:16:33 goose: successfully migrated database to version: 2026092312000010272026/09/29 08:16:33 OK 20260923120000_add_pushes.sql (9.92ms)10282026/09/29 08:16:33 goose: successfully migrated database to version: 2026092312000010292026/09/29 08:16:33 OK 1_commit_pending_closure.sql (1.31ms)10302026/09/29 08:16:33 OK 1_commit_pending_closure.sql (1.38ms)10312026/09/29 08:16:33 OK 2_object_stats_trigger.sql (271.92µs)10322026/09/29 08:16:33 OK 2_object_stats_trigger.sql (254.83µs)10332026/09/29 08:16:33 OK 3_commit_push.sql (206.42µs)10342026/09/29 08:16:33 goose: up to current file version: 310352026/09/29 08:16:33 OK 3_commit_push.sql (213.33µs)10362026/09/29 08:16:33 goose: up to current file version: 310372026/09/29 08:16:33 INFO Received uploads request method=POST path=/api/pending_closures1038--- PASS: TestGCBugBareHashReferences (2.35s)1039=== CONT TestParseSingleRange1040=== RUN TestParseSingleRange/none1041=== PAUSE TestParseSingleRange/none1042=== RUN TestParseSingleRange/unknown_unit1043=== PAUSE TestParseSingleRange/unknown_unit1044=== RUN TestParseSingleRange/multi-range_ignored1045=== PAUSE TestParseSingleRange/multi-range_ignored1046=== RUN TestParseSingleRange/malformed_no_dash1047=== PAUSE TestParseSingleRange/malformed_no_dash1048=== RUN TestParseSingleRange/malformed_both_empty1049=== PAUSE TestParseSingleRange/malformed_both_empty1050=== RUN TestParseSingleRange/malformed_end_before_start1051=== PAUSE TestParseSingleRange/malformed_end_before_start1052=== RUN TestParseSingleRange/closed1053=== PAUSE TestParseSingleRange/closed1054=== RUN TestParseSingleRange/open-ended1055=== PAUSE TestParseSingleRange/open-ended1056=== RUN TestParseSingleRange/end_clamped_to_size1057=== PAUSE TestParseSingleRange/end_clamped_to_size1058=== RUN TestParseSingleRange/suffix1059=== PAUSE TestParseSingleRange/suffix1060=== RUN TestParseSingleRange/suffix_exceeds_size1061=== PAUSE TestParseSingleRange/suffix_exceeds_size1062=== RUN TestParseSingleRange/single_byte1063=== PAUSE TestParseSingleRange/single_byte1064=== RUN TestParseSingleRange/start_past_EOF1065=== PAUSE TestParseSingleRange/start_past_EOF1066=== RUN TestParseSingleRange/start_far_past_EOF1067=== PAUSE TestParseSingleRange/start_far_past_EOF1068=== CONT TestCreatePin_ReservedPins10692026/09/29 08:16:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56272/oidc10702026-09-29 08:16:33.985 UTC [9343] ERROR: relation "goose_db_version" does not exist at character 3610712026-09-29 08:16:33.985 UTC [9343] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10722026/09/29 08:16:34 INFO Received cleanup request method=DELETE path=/api/pending_closures10732026/09/29 08:16:34 INFO Aborted multipart uploads count=11074--- PASS: TestMultipartCleanup (1.70s)1075=== CONT TestResurrectedObjectNotDeleted10762026/09/29 08:16:34 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10772026/09/29 08:16:34 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1078--- PASS: TestService_NativeMTLS (1.57s)1079=== CONT TestOrphanedObjectsGCStressTest10802026/09/29 08:16:34 OK 20241026095416_initial_model.sql (145.31ms)10812026/09/29 08:16:34 OK 20251210153512_drop_unused_gin_index.sql (7.71ms)10822026/09/29 08:16:34 OK 20251218171726_add_pins.sql (27.57ms)10832026/09/29 08:16:34 OK 20260628120000_add_object_size_and_stats.sql (21.64ms)10842026-09-29 08:16:34.226 UTC [9349] ERROR: relation "goose_db_version" does not exist at character 3610852026-09-29 08:16:34.226 UTC [9349] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10862026/09/29 08:16:34 OK 20260905000000_add_claims.sql (22.56ms)10872026/09/29 08:16:34 OK 20260920000000_drop_claims.sql (14.25ms)10882026/09/29 08:16:34 OK 20260923120000_add_pushes.sql (14.38ms)10892026/09/29 08:16:34 goose: successfully migrated database to version: 2026092312000010902026/09/29 08:16:34 OK 1_commit_pending_closure.sql (1.33ms)10912026/09/29 08:16:34 OK 2_object_stats_trigger.sql (249.38µs)10922026/09/29 08:16:34 OK 3_commit_push.sql (227µs)10932026/09/29 08:16:34 goose: up to current file version: 310942026-09-29 08:16:34.357 UTC [9352] ERROR: relation "goose_db_version" does not exist at character 3610952026-09-29 08:16:34.357 UTC [9352] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10962026/09/29 08:16:34 OK 20241026095416_initial_model.sql (106.3ms)10972026/09/29 08:16:34 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)1098--- PASS: TestMetricsInventory (1.78s)1099=== CONT TestSkippedUploadsHandler11002026/09/29 08:16:34 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001101--- PASS: TestSkippedUploadsHandler (0.00s)1102=== CONT TestPresignedUploadRegisteredBeforeCommit11032026/09/29 08:16:34 OK 20251218171726_add_pins.sql (4.58ms)11042026/09/29 08:16:34 OK 20260628120000_add_object_size_and_stats.sql (19.8ms)11052026/09/29 08:16:34 OK 20260905000000_add_claims.sql (15.54ms)11062026/09/29 08:16:34 OK 20260920000000_drop_claims.sql (7.4ms)11072026/09/29 08:16:34 OK 20260923120000_add_pushes.sql (6.57ms)11082026/09/29 08:16:34 goose: successfully migrated database to version: 2026092312000011092026/09/29 08:16:34 OK 1_commit_pending_closure.sql (1.68ms)11102026/09/29 08:16:34 OK 2_object_stats_trigger.sql (317.67µs)11112026/09/29 08:16:34 OK 3_commit_push.sql (274.63µs)11122026/09/29 08:16:34 goose: up to current file version: 311132026/09/29 08:16:34 OK 20241026095416_initial_model.sql (74.73ms)11142026/09/29 08:16:34 OK 20251210153512_drop_unused_gin_index.sql (5.32ms)11152026/09/29 08:16:34 OK 20251218171726_add_pins.sql (26.56ms)11162026-09-29 08:16:34.497 UTC [9355] ERROR: relation "goose_db_version" does not exist at character 3611172026-09-29 08:16:34.497 UTC [9355] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1118--- PASS: TestReadProxy404 (1.67s)1119=== CONT TestService_cleanupPendingClosuresHandler11202026-09-29 08:16:34.503 UTC [9356] ERROR: relation "goose_db_version" does not exist at character 3611212026-09-29 08:16:34.503 UTC [9356] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11222026/09/29 08:16:34 OK 20260628120000_add_object_size_and_stats.sql (39.02ms)11232026/09/29 08:16:34 OK 20260905000000_add_claims.sql (3.63ms)11242026/09/29 08:16:34 OK 20260920000000_drop_claims.sql (11.86ms)11252026/09/29 08:16:34 OK 20260923120000_add_pushes.sql (6.01ms)11262026/09/29 08:16:34 goose: successfully migrated database to version: 2026092312000011272026/09/29 08:16:34 OK 1_commit_pending_closure.sql (945.21µs)11282026/09/29 08:16:34 OK 2_object_stats_trigger.sql (188.46µs)11292026/09/29 08:16:34 OK 3_commit_push.sql (151.13µs)11302026/09/29 08:16:34 goose: up to current file version: 311312026/09/29 08:16:34 OK 20241026095416_initial_model.sql (51.19ms)11322026/09/29 08:16:34 OK 20241026095416_initial_model.sql (49.5ms)11332026/09/29 08:16:34 OK 20251210153512_drop_unused_gin_index.sql (8.31ms)11342026/09/29 08:16:34 OK 20251210153512_drop_unused_gin_index.sql (8.39ms)11352026/09/29 08:16:34 OK 20251218171726_add_pins.sql (18.65ms)11362026/09/29 08:16:34 OK 20251218171726_add_pins.sql (18.62ms)11372026/09/29 08:16:34 OK 20260628120000_add_object_size_and_stats.sql (25.38ms)11382026/09/29 08:16:34 OK 20260628120000_add_object_size_and_stats.sql (25.86ms)1139--- PASS: TestReadProxyNarStreaming (1.62s)1140=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT11412026/09/29 08:16:34 OK 20260905000000_add_claims.sql (27.44ms)11422026/09/29 08:16:34 OK 20260905000000_add_claims.sql (37.84ms)11432026/09/29 08:16:34 OK 20260920000000_drop_claims.sql (16.24ms)11442026/09/29 08:16:34 OK 20260920000000_drop_claims.sql (18.88ms)11452026/09/29 08:16:34 OK 20260923120000_add_pushes.sql (17ms)11462026/09/29 08:16:34 goose: successfully migrated database to version: 2026092312000011472026/09/29 08:16:34 OK 1_commit_pending_closure.sql (2ms)11482026/09/29 08:16:34 OK 2_object_stats_trigger.sql (468.33µs)11492026/09/29 08:16:34 OK 3_commit_push.sql (900.25µs)11502026/09/29 08:16:34 goose: up to current file version: 311512026/09/29 08:16:34 OK 20260923120000_add_pushes.sql (18.29ms)11522026/09/29 08:16:34 goose: successfully migrated database to version: 2026092312000011532026/09/29 08:16:34 OK 1_commit_pending_closure.sql (23.73ms)11542026/09/29 08:16:34 OK 2_object_stats_trigger.sql (1.08ms)11552026/09/29 08:16:34 OK 3_commit_push.sql (508.08µs)11562026/09/29 08:16:34 goose: up to current file version: 31157--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.60s)1158=== CONT TestCompleteMultipartUnregistered11592026/09/29 08:16:35 INFO Starting HTTP server address=/nix/var/nix/builds/nix-9113-1245729578/TestProxyHeadersOnlyTrustedOnSocket2872664329/001/proxy.sock11602026/09/29 08:16:35 INFO Starting HTTP server address=127.0.0.1:5628511612026/09/29 08:16:35 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11622026/09/29 08:16:35 INFO Shutdown signal received, draining in-flight requests timeout=10s1163--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.51s)1164=== CONT TestService_verifyS3Integrity11652026/09/29 08:16:35 WARN Rate limiter enabled after throttle name=s3-test rate=511662026/09/29 08:16:35 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1167=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1168 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101169 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001170--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.86s)1171=== CONT TestService_createPendingClosureHandler11722026-09-29 08:16:35.096 UTC [9364] ERROR: relation "goose_db_version" does not exist at character 3611732026-09-29 08:16:35.096 UTC [9364] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11742026-09-29 08:16:35.157 UTC [9368] ERROR: relation "goose_db_version" does not exist at character 3611752026-09-29 08:16:35.157 UTC [9368] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11762026-09-29 08:16:35.184 UTC [9369] ERROR: relation "goose_db_version" does not exist at character 3611772026-09-29 08:16:35.184 UTC [9369] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11782026/09/29 08:16:35 OK 20241026095416_initial_model.sql (61.81ms)11792026/09/29 08:16:35 OK 20251210153512_drop_unused_gin_index.sql (17.43ms)11802026/09/29 08:16:35 OK 20251218171726_add_pins.sql (8.32ms)1181--- PASS: TestReadProxyNarinfo (1.80s)1182=== CONT TestGCTaskStore_PhaseUpdates1183--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1184=== CONT TestCreatePendingClosureRejectsOversizedNAR11852026/09/29 08:16:35 INFO Received uploads request method=POST path=/api/pending_closures1186--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1187=== CONT TestCacheConfigHandlerMaxNarSize1188--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1189=== CONT TestGenerateLandingPage1190--- PASS: TestGenerateLandingPage (0.00s)1191=== CONT TestService_readinessHandler11922026/09/29 08:16:35 OK 20260628120000_add_object_size_and_stats.sql (29.17ms)11932026/09/29 08:16:35 OK 20260905000000_add_claims.sql (29.06ms)11942026/09/29 08:16:35 OK 20241026095416_initial_model.sql (84.65ms)11952026/09/29 08:16:35 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)11962026/09/29 08:16:35 OK 20260920000000_drop_claims.sql (3.02ms)11972026/09/29 08:16:35 OK 20251218171726_add_pins.sql (2.37ms)11982026/09/29 08:16:35 OK 20260923120000_add_pushes.sql (2.63ms)11992026/09/29 08:16:35 goose: successfully migrated database to version: 2026092312000012002026/09/29 08:16:35 OK 1_commit_pending_closure.sql (5.78ms)12012026/09/29 08:16:35 OK 20241026095416_initial_model.sql (56.01ms)12022026/09/29 08:16:35 OK 2_object_stats_trigger.sql (461.17µs)12032026/09/29 08:16:35 OK 20251210153512_drop_unused_gin_index.sql (612.46µs)12042026-09-29 08:16:35.288 UTC [9374] ERROR: relation "goose_db_version" does not exist at character 3612052026-09-29 08:16:35.288 UTC [9374] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12062026/09/29 08:16:35 OK 3_commit_push.sql (395.58µs)12072026/09/29 08:16:35 goose: up to current file version: 312082026/09/29 08:16:35 OK 20251218171726_add_pins.sql (1.37ms)12092026/09/29 08:16:35 OK 20260628120000_add_object_size_and_stats.sql (25.86ms)12102026/09/29 08:16:35 OK 20260628120000_add_object_size_and_stats.sql (22.25ms)12112026/09/29 08:16:35 OK 20260905000000_add_claims.sql (21.3ms)12122026/09/29 08:16:35 OK 20260905000000_add_claims.sql (16.51ms)12132026/09/29 08:16:35 OK 20260920000000_drop_claims.sql (3.14ms)12142026/09/29 08:16:35 OK 20260920000000_drop_claims.sql (10.04ms)12152026/09/29 08:16:35 OK 20260923120000_add_pushes.sql (13.88ms)12162026/09/29 08:16:35 goose: successfully migrated database to version: 2026092312000012172026/09/29 08:16:35 OK 20260923120000_add_pushes.sql (6.88ms)12182026/09/29 08:16:35 goose: successfully migrated database to version: 2026092312000012192026/09/29 08:16:35 OK 1_commit_pending_closure.sql (2.21ms)12202026/09/29 08:16:35 OK 2_object_stats_trigger.sql (397.63µs)12212026/09/29 08:16:35 OK 1_commit_pending_closure.sql (1.81ms)12222026/09/29 08:16:35 OK 3_commit_push.sql (338.46µs)12232026/09/29 08:16:35 goose: up to current file version: 312242026/09/29 08:16:35 OK 2_object_stats_trigger.sql (381.88µs)12252026/09/29 08:16:35 OK 3_commit_push.sql (328.46µs)12262026/09/29 08:16:35 goose: up to current file version: 312272026/09/29 08:16:35 OK 20241026095416_initial_model.sql (65.32ms)12282026/09/29 08:16:35 OK 20251210153512_drop_unused_gin_index.sql (1.4ms)12292026/09/29 08:16:35 OK 20251218171726_add_pins.sql (12.96ms)12302026/09/29 08:16:35 OK 20260628120000_add_object_size_and_stats.sql (24.3ms)12312026/09/29 08:16:35 OK 20260905000000_add_claims.sql (32.91ms)12322026/09/29 08:16:35 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12332026/09/29 08:16:35 WARN Refused reserved pin name=worker-x86_64-linux12342026/09/29 08:16:35 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12352026/09/29 08:16:35 INFO Received create pin request method=POST path=/api/pins/my-app12362026/09/29 08:16:35 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12372026/09/29 08:16:35 OK 20260920000000_drop_claims.sql (18.63ms)1238--- PASS: TestCreatePin_ReservedPins (1.56s)1239=== CONT TestNARDeduplicationMetadataUploadBug12402026/09/29 08:16:35 OK 20260923120000_add_pushes.sql (15.29ms)12412026/09/29 08:16:35 goose: successfully migrated database to version: 2026092312000012422026/09/29 08:16:35 OK 1_commit_pending_closure.sql (1.88ms)12432026/09/29 08:16:35 OK 2_object_stats_trigger.sql (419.79µs)12442026/09/29 08:16:35 OK 3_commit_push.sql (375.83µs)12452026/09/29 08:16:35 goose: up to current file version: 312462026-09-29 08:16:35.509 UTC [9379] ERROR: relation "goose_db_version" does not exist at character 3612472026-09-29 08:16:35.509 UTC [9379] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12482026/09/29 08:16:35 OK 20241026095416_initial_model.sql (152.86ms)12492026/09/29 08:16:35 OK 20251210153512_drop_unused_gin_index.sql (16.33ms)12502026/09/29 08:16:35 OK 20251218171726_add_pins.sql (41.19ms)12512026/09/29 08:16:35 OK 20260628120000_add_object_size_and_stats.sql (61.51ms)1252--- PASS: TestResurrectedObjectNotDeleted (1.77s)1253=== CONT TestService_healthCheckHandler12542026/09/29 08:16:35 OK 20260905000000_add_claims.sql (85.76ms)12552026/09/29 08:16:35 OK 20260920000000_drop_claims.sql (29.74ms)12562026/09/29 08:16:35 OK 20260923120000_add_pushes.sql (17.64ms)12572026/09/29 08:16:35 goose: successfully migrated database to version: 2026092312000012582026/09/29 08:16:35 OK 1_commit_pending_closure.sql (972.67µs)12592026/09/29 08:16:35 OK 2_object_stats_trigger.sql (205.75µs)12602026/09/29 08:16:35 OK 3_commit_push.sql (169.13µs)12612026/09/29 08:16:35 goose: up to current file version: 312622026-09-29 08:16:36.022 UTC [9389] ERROR: relation "goose_db_version" does not exist at character 3612632026-09-29 08:16:36.022 UTC [9389] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12642026/09/29 08:16:36 INFO Received uploads request method=POST path=/api/pending_closures12652026/09/29 08:16:36 OK 20241026095416_initial_model.sql (242.53ms)12662026-09-29 08:16:36.320 UTC [9401] ERROR: relation "goose_db_version" does not exist at character 3612672026-09-29 08:16:36.320 UTC [9401] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12682026/09/29 08:16:36 OK 20251210153512_drop_unused_gin_index.sql (19.77ms)12692026/09/29 08:16:36 OK 20251218171726_add_pins.sql (41.06ms)12702026/09/29 08:16:36 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12712026/09/29 08:16:36 INFO Received uploads request method=POST path=/api/pending_closures1272--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.03s)1273=== CONT TestGracefulShutdownDrainsInflight12742026/09/29 08:16:36 INFO Starting HTTP server address=127.0.0.1:5629812752026/09/29 08:16:36 INFO Shutdown signal received, draining in-flight requests timeout=10s12762026/09/29 08:16:36 OK 20260628120000_add_object_size_and_stats.sql (29.05ms)1277--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1278=== CONT TestGCTaskStore_Fail1279--- PASS: TestGCTaskStore_Fail (0.00s)1280=== CONT TestUploadHandlersRejectInvalidKeys1281=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1282=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1283=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1284=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1285=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1286=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1287=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1288=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1289=== CONT TestUploadHandlersRejectOversizedBody1290=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1291=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1292=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1293=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1294=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1295=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1296=== CONT TestGCTaskStore_CompletedAllowsNewTask1297--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1298=== CONT TestGCTaskStore_ConflictDifferentParams1299--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1300=== CONT TestGCTaskStore_DeduplicateSameParams1301--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1302=== CONT TestGCTaskStore_GetReturnsLatest1303--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1304=== CONT TestGCTaskStore_StartNew1305--- PASS: TestGCTaskStore_StartNew (0.00s)1306=== CONT TestGCTaskStore_GetEmpty1307--- PASS: TestGCTaskStore_GetEmpty (0.00s)1308=== CONT TestGCMetrics13092026/09/29 08:16:36 OK 20260905000000_add_claims.sql (106.55ms)13102026/09/29 08:16:36 OK 20260920000000_drop_claims.sql (25.08ms)13112026/09/29 08:16:36 OK 20260923120000_add_pushes.sql (18.46ms)13122026/09/29 08:16:36 goose: successfully migrated database to version: 2026092312000013132026/09/29 08:16:36 OK 1_commit_pending_closure.sql (1.64ms)13142026/09/29 08:16:36 OK 2_object_stats_trigger.sql (329.63µs)13152026/09/29 08:16:36 OK 3_commit_push.sql (290.83µs)13162026/09/29 08:16:36 goose: up to current file version: 313172026/09/29 08:16:36 OK 20241026095416_initial_model.sql (206.85ms)13182026/09/29 08:16:36 INFO Received cleanup request method=DELETE path=/api/pending_closures13192026/09/29 08:16:36 INFO Aborted multipart uploads count=013202026/09/29 08:16:36 INFO Received uploads request method=POST path=/api/pending_closures13212026/09/29 08:16:36 OK 20251210153512_drop_unused_gin_index.sql (12.67ms)13222026/09/29 08:16:36 OK 20251218171726_add_pins.sql (43.1ms)13232026/09/29 08:16:36 INFO Received cleanup request method=DELETE path=/api/pending_closures13242026/09/29 08:16:36 INFO Aborted multipart uploads count=113252026/09/29 08:16:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13262026-09-29 08:16:36.728 UTC [9379] ERROR: Closure does not exist: id=113272026-09-29 08:16:36.728 UTC [9379] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE13282026-09-29 08:16:36.728 UTC [9379] STATEMENT: -- name: CommitPendingClosure :exec1329 SELECT commit_pending_closure($1::bigint)1330 1331--- PASS: TestService_cleanupPendingClosuresHandler (2.23s)1332=== CONT TestPush_SignsNarinfosOfItsPendingObjects13332026/09/29 08:16:36 OK 20260628120000_add_object_size_and_stats.sql (62.75ms)13342026/09/29 08:16:36 OK 20260905000000_add_claims.sql (59.53ms)13352026/09/29 08:16:36 OK 20260920000000_drop_claims.sql (31.04ms)13362026/09/29 08:16:36 OK 20260923120000_add_pushes.sql (21.77ms)13372026/09/29 08:16:36 goose: successfully migrated database to version: 2026092312000013382026/09/29 08:16:36 OK 1_commit_pending_closure.sql (2.67ms)13392026/09/29 08:16:36 OK 2_object_stats_trigger.sql (636.38µs)13402026/09/29 08:16:36 OK 3_commit_push.sql (510.58µs)13412026/09/29 08:16:36 goose: up to current file version: 313422026/09/29 08:16:36 INFO Received uploads request method=POST path=/api/pending_closures13432026-09-29 08:16:36.986 UTC [9416] ERROR: relation "goose_db_version" does not exist at character 3613442026-09-29 08:16:36.986 UTC [9416] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13452026-09-29 08:16:36.993 UTC [9417] ERROR: relation "goose_db_version" does not exist at character 3613462026-09-29 08:16:36.993 UTC [9417] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1347--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.40s)1348=== CONT TestRedundantMultipartUpload13492026/09/29 08:16:37 OK 20241026095416_initial_model.sql (234.71ms)13502026/09/29 08:16:37 OK 20251210153512_drop_unused_gin_index.sql (12.59ms)13512026/09/29 08:16:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13522026/09/29 08:16:37 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1353--- PASS: TestCompleteMultipartUnregistered (2.46s)1354=== CONT TestCompleteMultipartUpload_ErrorButObjectExists13552026/09/29 08:16:37 OK 20251218171726_add_pins.sql (47.16ms)13562026/09/29 08:16:37 OK 20241026095416_initial_model.sql (259.23ms)13572026/09/29 08:16:37 OK 20251210153512_drop_unused_gin_index.sql (8.93ms)13582026/09/29 08:16:37 OK 20260628120000_add_object_size_and_stats.sql (23.39ms)13592026/09/29 08:16:37 OK 20251218171726_add_pins.sql (20.37ms)13602026-09-29 08:16:37.413 UTC [9422] ERROR: relation "goose_db_version" does not exist at character 3613612026-09-29 08:16:37.413 UTC [9422] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13622026/09/29 08:16:37 OK 20260628120000_add_object_size_and_stats.sql (32.09ms)13632026/09/29 08:16:37 OK 20260905000000_add_claims.sql (40.27ms)13642026/09/29 08:16:37 OK 20260920000000_drop_claims.sql (51.44ms)13652026/09/29 08:16:37 OK 20260923120000_add_pushes.sql (13.72ms)13662026/09/29 08:16:37 goose: successfully migrated database to version: 2026092312000013672026/09/29 08:16:37 OK 20260905000000_add_claims.sql (67.49ms)13682026/09/29 08:16:37 OK 1_commit_pending_closure.sql (4.87ms)13692026/09/29 08:16:37 OK 2_object_stats_trigger.sql (848µs)13702026/09/29 08:16:37 OK 3_commit_push.sql (682.54µs)13712026/09/29 08:16:37 goose: up to current file version: 313722026/09/29 08:16:37 OK 20260920000000_drop_claims.sql (12.29ms)13732026/09/29 08:16:37 OK 20260923120000_add_pushes.sql (17.07ms)13742026/09/29 08:16:37 goose: successfully migrated database to version: 2026092312000013752026/09/29 08:16:37 OK 1_commit_pending_closure.sql (2.64ms)13762026/09/29 08:16:37 OK 2_object_stats_trigger.sql (615.92µs)13772026/09/29 08:16:37 OK 3_commit_push.sql (519.83µs)13782026/09/29 08:16:37 goose: up to current file version: 313792026-09-29 08:16:37.573 UTC [9423] ERROR: relation "goose_db_version" does not exist at character 3613802026-09-29 08:16:37.573 UTC [9423] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13812026/09/29 08:16:37 OK 20241026095416_initial_model.sql (210.47ms)13822026/09/29 08:16:37 OK 20251210153512_drop_unused_gin_index.sql (35.63ms)13832026/09/29 08:16:37 INFO Received uploads request method=POST path=/api/pending_closures13842026/09/29 08:16:37 OK 20251218171726_add_pins.sql (122.57ms)13852026/09/29 08:16:37 OK 20260628120000_add_object_size_and_stats.sql (60.09ms)13862026/09/29 08:16:37 OK 20241026095416_initial_model.sql (291.1ms)13872026/09/29 08:16:37 OK 20251210153512_drop_unused_gin_index.sql (18.03ms)13882026/09/29 08:16:38 OK 20251218171726_add_pins.sql (27.34ms)13892026/09/29 08:16:38 OK 20260905000000_add_claims.sql (90.79ms)13902026/09/29 08:16:38 OK 20260628120000_add_object_size_and_stats.sql (61ms)13912026/09/29 08:16:38 OK 20260920000000_drop_claims.sql (59.58ms)13922026/09/29 08:16:38 OK 20260923120000_add_pushes.sql (22.19ms)13932026/09/29 08:16:38 goose: successfully migrated database to version: 2026092312000013942026/09/29 08:16:38 OK 1_commit_pending_closure.sql (4.54ms)13952026/09/29 08:16:38 OK 2_object_stats_trigger.sql (3.39ms)13962026/09/29 08:16:38 OK 3_commit_push.sql (908.5µs)13972026/09/29 08:16:38 goose: up to current file version: 313982026/09/29 08:16:38 OK 20260905000000_add_claims.sql (94.2ms)13992026/09/29 08:16:38 OK 20260920000000_drop_claims.sql (22.05ms)14002026-09-29 08:16:38.206 UTC [9424] ERROR: relation "goose_db_version" does not exist at character 3614012026-09-29 08:16:38.206 UTC [9424] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14022026/09/29 08:16:38 OK 20260923120000_add_pushes.sql (30.12ms)14032026/09/29 08:16:38 goose: successfully migrated database to version: 2026092312000014042026/09/29 08:16:38 OK 1_commit_pending_closure.sql (2.38ms)14052026/09/29 08:16:38 OK 2_object_stats_trigger.sql (568.67µs)14062026/09/29 08:16:38 OK 3_commit_push.sql (396.67µs)14072026/09/29 08:16:38 goose: up to current file version: 314082026/09/29 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures14092026/09/29 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures14102026/09/29 08:16:38 INFO Received uploads request method=POST path=/api/pending_closures14112026/09/29 08:16:38 OK 20241026095416_initial_model.sql (302ms)14122026/09/29 08:16:38 OK 20251210153512_drop_unused_gin_index.sql (15.04ms)14132026/09/29 08:16:38 OK 20251218171726_add_pins.sql (59.73ms)14142026/09/29 08:16:38 WARN readiness check failed error="closed pool"1415--- PASS: TestService_readinessHandler (3.44s)1416=== CONT TestPush_RejectsBadRequests14172026/09/29 08:16:38 OK 20260628120000_add_object_size_and_stats.sql (52.58ms)14182026/09/29 08:16:38 OK 20260905000000_add_claims.sql (82.83ms)14192026/09/29 08:16:38 OK 20260920000000_drop_claims.sql (38.28ms)14202026/09/29 08:16:38 OK 20260923120000_add_pushes.sql (15.89ms)14212026/09/29 08:16:38 goose: successfully migrated database to version: 2026092312000014222026/09/29 08:16:38 OK 1_commit_pending_closure.sql (3.9ms)14232026/09/29 08:16:38 OK 2_object_stats_trigger.sql (716.08µs)14242026/09/29 08:16:38 OK 3_commit_push.sql (380.75µs)14252026/09/29 08:16:38 goose: up to current file version: 31426--- PASS: TestService_healthCheckHandler (3.67s)1427=== CONT TestClientPushesUseOnePush1428=== NAME TestNARDeduplicationMetadataUploadBug1429 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-9113-1245729578/TestNARDeduplicationMetadataUploadBug2872330680/001/store/h2l55p5kh26lw48qj660k2sv1jsfblvd-file1.txt14302026/09/29 08:16:39 INFO Received push request method=POST path=/api/pushes14312026/09/29 08:16:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14322026/09/29 08:16:39 INFO Uploading h2l55p5kh26lw48qj660k2sv1jsfblvd-file1.txt (160B)14332026/09/29 08:16:39 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14342026/09/29 08:16:39 WARN Failed to register uploaded object key=h2l55p5kh26lw48qj660k2sv1jsfblvd.ls error="server returned 404: 404 page not found\n"14352026/09/29 08:16:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14362026/09/29 08:16:39 INFO Signed narinfos id=1 count=114372026/09/29 08:16:39 INFO Uploading 1 narinfos14382026/09/29 08:16:39 INFO Received complete push request method=POST path=/api/pushes/1/complete14392026/09/29 08:16:39 WARN Failed to register uploaded object key=h2l55p5kh26lw48qj660k2sv1jsfblvd.narinfo error="server returned 404: 404 page not found\n"14402026/09/29 08:16:39 INFO Upload complete. (194ms)1441 metadata_upload_test.go:54: Retrieved narinfo from S3:1442 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestNARDeduplicationMetadataUploadBug2872330680/001/store/h2l55p5kh26lw48qj660k2sv1jsfblvd-file1.txt1443 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1444 Compression: zstd1445 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1446 NarSize: 1601447 References: 1448 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1449 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1450 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1451 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14522026/09/29 08:16:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14532026-09-29 08:16:39.836 UTC [9445] ERROR: relation "goose_db_version" does not exist at character 3614542026-09-29 08:16:39.836 UTC [9445] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14552026-09-29 08:16:39.841 UTC [9446] ERROR: relation "goose_db_version" does not exist at character 3614562026-09-29 08:16:39.841 UTC [9446] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14572026/09/29 08:16:39 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjEyNGRmYjQtODZmMi00MzVjLWIxZGMtZWJjYWI4ZmVmYzA2LmYzZDdlYzdiLTJhNmMtNGJlNC1iODY4LWZjZWI1YzQyNjFjYngxNzkwNjY5Nzk3ODk4MTIzMDAw parts=1014582026/09/29 08:16:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1459 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-9113-1245729578/TestNARDeduplicationMetadataUploadBug2872330680/001/store/9vb4z4mrhba0aa5yl446qy4ggampzd5x-file2.txt14602026/09/29 08:16:39 INFO Completed upload id=114612026/09/29 08:16:39 INFO Received uploads request method=POST path=/api/pending_closures14622026/09/29 08:16:39 INFO Received uploads request method=POST path=/api/pending_closures14632026/09/29 08:16:39 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14642026/09/29 08:16:39 WARN Found objects in DB but missing from S3, will re-upload count=11465--- PASS: TestService_verifyS3Integrity (4.83s)1466=== CONT TestLeadEndsOnShutdown14672026-09-29 08:16:39.939 UTC [9454] ERROR: relation "goose_db_version" does not exist at character 3614682026-09-29 08:16:39.939 UTC [9454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14692026-09-29 08:16:39.940 UTC [9455] ERROR: relation "goose_db_version" does not exist at character 3614702026-09-29 08:16:39.940 UTC [9455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14712026/09/29 08:16:39 INFO Received push request method=POST path=/api/pushes14722026/09/29 08:16:39 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14732026/09/29 08:16:39 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14742026/09/29 08:16:39 INFO Signed narinfos id=2 count=114752026/09/29 08:16:39 INFO Uploading 1 narinfos14762026/09/29 08:16:39 WARN Failed to register uploaded object key=9vb4z4mrhba0aa5yl446qy4ggampzd5x.ls error="server returned 404: 404 page not found\n"14772026/09/29 08:16:39 INFO Received complete push request method=POST path=/api/pushes/2/complete14782026/09/29 08:16:39 WARN Failed to register uploaded object key=9vb4z4mrhba0aa5yl446qy4ggampzd5x.narinfo error="server returned 404: 404 page not found\n"14792026/09/29 08:16:39 INFO Upload complete. (58ms)1480=== NAME TestNARDeduplicationMetadataUploadBug1481 metadata_upload_test.go:76: Retrieved narinfo from S3:1482 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestNARDeduplicationMetadataUploadBug2872330680/001/store/9vb4z4mrhba0aa5yl446qy4ggampzd5x-file2.txt1483 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1484 Compression: zstd1485 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1486 NarSize: 1601487 References: 1488 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1489 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1490 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1491 {"version":1,"root":{"type":"regular","size":44}}14922026/09/29 08:16:40 OK 20241026095416_initial_model.sql (120.39ms)14932026/09/29 08:16:40 OK 20241026095416_initial_model.sql (115.01ms)14942026/09/29 08:16:40 OK 20251210153512_drop_unused_gin_index.sql (10.14ms)14952026/09/29 08:16:40 OK 20251210153512_drop_unused_gin_index.sql (10.75ms)1496--- PASS: TestNARDeduplicationMetadataUploadBug (4.56s)1497=== CONT TestClientIntegration14982026/09/29 08:16:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14992026/09/29 08:16:40 OK 20251218171726_add_pins.sql (9.43ms)15002026/09/29 08:16:40 OK 20251218171726_add_pins.sql (10.08ms)15012026/09/29 08:16:40 OK 20241026095416_initial_model.sql (138.71ms)15022026/09/29 08:16:40 OK 20241026095416_initial_model.sql (138.84ms)15032026/09/29 08:16:40 OK 20260628120000_add_object_size_and_stats.sql (67ms)15042026/09/29 08:16:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjEyNGRmYjQtODZmMi00MzVjLWIxZGMtZWJjYWI4ZmVmYzA2LjMyZmFlZWEyLTAyYzItNDYxMy1hMGQyLWRkODYxMDEwMzI2M3gxNzkwNjY5Nzk4MzI2OTkxMDAw parts=1015052026/09/29 08:16:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15062026/09/29 08:16:40 OK 20260628120000_add_object_size_and_stats.sql (67.8ms)15072026/09/29 08:16:40 OK 20251210153512_drop_unused_gin_index.sql (7.76ms)15082026/09/29 08:16:40 OK 20251210153512_drop_unused_gin_index.sql (7.94ms)15092026/09/29 08:16:40 INFO Completed upload id=115102026/09/29 08:16:40 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015112026/09/29 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures15122026/09/29 08:16:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures15132026/09/29 08:16:40 INFO Aborted multipart uploads count=015142026/09/29 08:16:40 OK 20260905000000_add_claims.sql (26.07ms)15152026/09/29 08:16:40 OK 20251218171726_add_pins.sql (17.88ms)15162026/09/29 08:16:40 OK 20251218171726_add_pins.sql (17.9ms)15172026/09/29 08:16:40 OK 20260905000000_add_claims.sql (25.84ms)15182026/09/29 08:16:40 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=015192026/09/29 08:16:40 OK 20260920000000_drop_claims.sql (9.96ms)15202026/09/29 08:16:40 OK 20260920000000_drop_claims.sql (10.52ms)15212026/09/29 08:16:40 OK 20260923120000_add_pushes.sql (6ms)15222026/09/29 08:16:40 goose: successfully migrated database to version: 2026092312000015232026/09/29 08:16:40 INFO Vacuumed table table=pending_closures15242026/09/29 08:16:40 OK 1_commit_pending_closure.sql (1.66ms)15252026/09/29 08:16:40 OK 20260923120000_add_pushes.sql (8.87ms)15262026/09/29 08:16:40 goose: successfully migrated database to version: 2026092312000015272026/09/29 08:16:40 OK 2_object_stats_trigger.sql (295.83µs)15282026/09/29 08:16:40 OK 3_commit_push.sql (194.04µs)15292026/09/29 08:16:40 goose: up to current file version: 315302026/09/29 08:16:40 OK 20260628120000_add_object_size_and_stats.sql (19.61ms)15312026/09/29 08:16:40 OK 1_commit_pending_closure.sql (1.14ms)15322026/09/29 08:16:40 OK 2_object_stats_trigger.sql (224.5µs)15332026/09/29 08:16:40 OK 3_commit_push.sql (192.63µs)15342026/09/29 08:16:40 goose: up to current file version: 315352026/09/29 08:16:40 OK 20260628120000_add_object_size_and_stats.sql (26.51ms)15362026/09/29 08:16:40 INFO Vacuumed table table=pending_objects15372026/09/29 08:16:40 INFO Vacuumed table table=multipart_uploads15382026/09/29 08:16:40 OK 20260905000000_add_claims.sql (46.39ms)15392026/09/29 08:16:40 INFO Vacuumed table table=closures15402026/09/29 08:16:40 OK 20260905000000_add_claims.sql (54.56ms)15412026/09/29 08:16:40 INFO Vacuumed table table=objects15422026/09/29 08:16:40 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001543--- PASS: TestService_createPendingClosureHandler (5.15s)1544=== CONT TestPinProtectsFromGC15452026/09/29 08:16:40 OK 20260920000000_drop_claims.sql (20.68ms)15462026/09/29 08:16:40 OK 20260920000000_drop_claims.sql (25.93ms)15472026/09/29 08:16:40 OK 20260923120000_add_pushes.sql (21.77ms)15482026/09/29 08:16:40 goose: successfully migrated database to version: 2026092312000015492026/09/29 08:16:40 OK 20260923120000_add_pushes.sql (16.26ms)15502026/09/29 08:16:40 goose: successfully migrated database to version: 2026092312000015512026/09/29 08:16:40 OK 1_commit_pending_closure.sql (1.35ms)15522026/09/29 08:16:40 OK 2_object_stats_trigger.sql (306.13µs)15532026/09/29 08:16:40 OK 1_commit_pending_closure.sql (816.88µs)15542026/09/29 08:16:40 OK 3_commit_push.sql (315.63µs)15552026/09/29 08:16:40 goose: up to current file version: 315562026/09/29 08:16:40 OK 2_object_stats_trigger.sql (271.96µs)15572026/09/29 08:16:40 OK 3_commit_push.sql (164.96µs)15582026/09/29 08:16:40 goose: up to current file version: 315592026/09/29 08:16:40 INFO Received push request method=POST path=/api/pushes15602026/09/29 08:16:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15612026/09/29 08:16:40 INFO Signed narinfos id=1 count=11562--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.72s)1563=== CONT TestClientSharedPathCommittedMidPush15642026/09/29 08:16:40 INFO Aborted multipart uploads count=015652026/09/29 08:16:40 WARN Force mode enabled - objects will be deleted immediately without grace period15662026/09/29 08:16:40 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015672026/09/29 08:16:40 INFO Vacuumed table table=pending_closures15682026/09/29 08:16:40 INFO Vacuumed table table=pending_objects15692026/09/29 08:16:40 INFO Vacuumed table table=multipart_uploads15702026/09/29 08:16:40 INFO Vacuumed table table=closures15712026/09/29 08:16:40 INFO Vacuumed table table=objects1572--- PASS: TestGCMetrics (4.14s)1573=== CONT TestObjectStatsTrigger15742026-09-29 08:16:40.685 UTC [9466] ERROR: relation "goose_db_version" does not exist at character 3615752026-09-29 08:16:40.685 UTC [9466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15762026/09/29 08:16:40 INFO Received uploads request method=POST path=/api/pending_closures15772026/09/29 08:16:40 OK 20241026095416_initial_model.sql (160ms)15782026/09/29 08:16:40 OK 20251210153512_drop_unused_gin_index.sql (13.83ms)15792026/09/29 08:16:40 OK 20251218171726_add_pins.sql (26.39ms)15802026/09/29 08:16:40 OK 20260628120000_add_object_size_and_stats.sql (53.6ms)15812026/09/29 08:16:41 OK 20260905000000_add_claims.sql (80ms)15822026/09/29 08:16:41 OK 20260920000000_drop_claims.sql (40.34ms)15832026/09/29 08:16:41 OK 20260923120000_add_pushes.sql (13.93ms)15842026/09/29 08:16:41 goose: successfully migrated database to version: 2026092312000015852026/09/29 08:16:41 OK 1_commit_pending_closure.sql (830.08µs)15862026/09/29 08:16:41 OK 2_object_stats_trigger.sql (246.25µs)15872026/09/29 08:16:41 OK 3_commit_push.sql (180.13µs)15882026/09/29 08:16:41 goose: up to current file version: 315892026-09-29 08:16:41.134 UTC [9470] ERROR: relation "goose_db_version" does not exist at character 3615902026-09-29 08:16:41.134 UTC [9470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15912026/09/29 08:16:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15922026/09/29 08:16:41 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjEyNGRmYjQtODZmMi00MzVjLWIxZGMtZWJjYWI4ZmVmYzA2LjY3YjNjMDcyLTBmNzAtNDJlZi1hODg5LTA1OWU5OGJkMjM2MHgxNzkwNjY5ODAwOTEwNDg4MDAw15932026/09/29 08:16:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjEyNGRmYjQtODZmMi00MzVjLWIxZGMtZWJjYWI4ZmVmYzA2LjY3YjNjMDcyLTBmNzAtNDJlZi1hODg5LTA1OWU5OGJkMjM2MHgxNzkwNjY5ODAwOTEwNDg4MDAw parts=11594--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.84s)1595=== CONT TestClientWithDependencies15962026/09/29 08:16:41 INFO Received uploads request method=POST path=/api/pending_closures15972026/09/29 08:16:41 INFO Received uploads request method=POST path=/api/pending_closures15982026/09/29 08:16:41 OK 20241026095416_initial_model.sql (177.39ms)15992026/09/29 08:16:41 OK 20251210153512_drop_unused_gin_index.sql (11.07ms)16002026/09/29 08:16:41 OK 20251218171726_add_pins.sql (35.5ms)1601=== RUN TestPush_RejectsBadRequests/no_roots1602=== PAUSE TestPush_RejectsBadRequests/no_roots1603=== RUN TestPush_RejectsBadRequests/no_objects1604=== PAUSE TestPush_RejectsBadRequests/no_objects1605=== RUN TestPush_RejectsBadRequests/bad_root1606=== PAUSE TestPush_RejectsBadRequests/bad_root1607=== RUN TestPush_RejectsBadRequests/root_not_in_objects1608=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1609=== CONT TestClientErrorHandling1610=== RUN TestClientErrorHandling/InvalidStorePath1611=== PAUSE TestClientErrorHandling/InvalidStorePath1612=== RUN TestClientErrorHandling/InvalidAuthToken1613=== PAUSE TestClientErrorHandling/InvalidAuthToken1614=== RUN TestClientErrorHandling/ServerNotAvailable1615=== PAUSE TestClientErrorHandling/ServerNotAvailable1616=== CONT TestClientMultipleUploads16172026/09/29 08:16:41 OK 20260628120000_add_object_size_and_stats.sql (33.77ms)16182026/09/29 08:16:41 OK 20260905000000_add_claims.sql (59.39ms)16192026/09/29 08:16:41 OK 20260920000000_drop_claims.sql (20.98ms)16202026-09-29 08:16:41.521 UTC [9475] ERROR: relation "goose_db_version" does not exist at character 3616212026-09-29 08:16:41.521 UTC [9475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16222026/09/29 08:16:41 OK 20260923120000_add_pushes.sql (8.33ms)16232026/09/29 08:16:41 goose: successfully migrated database to version: 2026092312000016242026/09/29 08:16:41 OK 1_commit_pending_closure.sql (931.13µs)16252026/09/29 08:16:41 OK 2_object_stats_trigger.sql (208.21µs)16262026/09/29 08:16:41 OK 3_commit_push.sql (206.54µs)16272026/09/29 08:16:41 goose: up to current file version: 316282026-09-29 08:16:41.764 UTC [9476] ERROR: relation "goose_db_version" does not exist at character 3616292026-09-29 08:16:41.764 UTC [9476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16302026/09/29 08:16:41 OK 20241026095416_initial_model.sql (221.86ms)16312026/09/29 08:16:41 OK 20251210153512_drop_unused_gin_index.sql (12.79ms)16322026/09/29 08:16:41 OK 20251218171726_add_pins.sql (21.14ms)16332026/09/29 08:16:41 OK 20260628120000_add_object_size_and_stats.sql (58.38ms)16342026/09/29 08:16:41 OK 20260905000000_add_claims.sql (57.43ms)16352026/09/29 08:16:41 OK 20260920000000_drop_claims.sql (9.62ms)16362026/09/29 08:16:41 OK 20260923120000_add_pushes.sql (19.73ms)16372026/09/29 08:16:41 goose: successfully migrated database to version: 2026092312000016382026/09/29 08:16:41 OK 1_commit_pending_closure.sql (910.13µs)16392026/09/29 08:16:41 OK 2_object_stats_trigger.sql (235.13µs)16402026/09/29 08:16:41 OK 3_commit_push.sql (186.96µs)16412026/09/29 08:16:41 goose: up to current file version: 316422026/09/29 08:16:42 OK 20241026095416_initial_model.sql (195.33ms)16432026/09/29 08:16:42 OK 20251210153512_drop_unused_gin_index.sql (21.12ms)16442026-09-29 08:16:42.068 UTC [9479] ERROR: relation "goose_db_version" does not exist at character 3616452026-09-29 08:16:42.068 UTC [9479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16462026/09/29 08:16:42 OK 20251218171726_add_pins.sql (27.58ms)16472026/09/29 08:16:42 OK 20260628120000_add_object_size_and_stats.sql (51.07ms)16482026/09/29 08:16:42 OK 20260905000000_add_claims.sql (70.56ms)16492026/09/29 08:16:42 OK 20260920000000_drop_claims.sql (29.66ms)16502026/09/29 08:16:42 OK 20260923120000_add_pushes.sql (21.75ms)16512026/09/29 08:16:42 goose: successfully migrated database to version: 2026092312000016522026/09/29 08:16:42 OK 1_commit_pending_closure.sql (813.79µs)16532026/09/29 08:16:42 OK 2_object_stats_trigger.sql (213µs)16542026/09/29 08:16:42 OK 3_commit_push.sql (205.75µs)16552026/09/29 08:16:42 goose: up to current file version: 316562026/09/29 08:16:42 INFO lead: acquired remote=192.0.2.1:123416572026/09/29 08:16:42 INFO lead: released remote=192.0.2.1:12341658--- PASS: TestLeadEndsOnShutdown (2.44s)1659=== CONT TestClientCADerivations1660=== NAME TestOrphanedObjectsGCStressTest1661 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains16622026/09/29 08:16:42 OK 20241026095416_initial_model.sql (212.87ms)16632026/09/29 08:16:42 OK 20251210153512_drop_unused_gin_index.sql (14.74ms)16642026/09/29 08:16:42 OK 20251218171726_add_pins.sql (22.13ms)1665 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16662026/09/29 08:16:42 INFO Received push request method=POST path=/api/pushes16672026-09-29 08:16:42.499 UTC [9492] ERROR: relation "goose_db_version" does not exist at character 3616682026-09-29 08:16:42.499 UTC [9492] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16692026/09/29 08:16:42 OK 20260628120000_add_object_size_and_stats.sql (103.92ms)16702026/09/29 08:16:42 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16712026/09/29 08:16:42 INFO Uploading y27pjjd4sqwcx9f2y0cwqiyddcny5wr5-shared-dep (136B)16722026/09/29 08:16:42 INFO Uploading 82wlq5pa1xxxj5a5qj0mkfwfzcs0gjm1-b (248B)16732026/09/29 08:16:42 WARN Failed to register uploaded object key=82wlq5pa1xxxj5a5qj0mkfwfzcs0gjm1.ls error="server returned 404: 404 page not found\n"16742026/09/29 08:16:42 WARN Failed to register uploaded object key=y27pjjd4sqwcx9f2y0cwqiyddcny5wr5.ls error="server returned 404: 404 page not found\n"16752026/09/29 08:16:42 WARN Failed to register uploaded object key=nar/15vqznp2zgra2074ny1jw7bb8a3qnj5k3dw0qz5rszs6xaba6hg0.nar.zst error="server returned 404: 404 page not found\n"16762026/09/29 08:16:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16772026/09/29 08:16:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16782026/09/29 08:16:42 WARN Failed to register uploaded object key=j3lxakya5ii86cr8mdn9k9pgw0i0bscc.ls error="server returned 404: 404 page not found\n"16792026/09/29 08:16:42 INFO Signed narinfos id=1 count=316802026/09/29 08:16:42 INFO Uploading 3 narinfos16812026/09/29 08:16:42 OK 20260905000000_add_claims.sql (28.7ms)16822026/09/29 08:16:42 WARN Failed to register uploaded object key=y27pjjd4sqwcx9f2y0cwqiyddcny5wr5.narinfo error="server returned 404: 404 page not found\n"16832026/09/29 08:16:42 WARN Failed to register uploaded object key=j3lxakya5ii86cr8mdn9k9pgw0i0bscc.narinfo error="server returned 404: 404 page not found\n"16842026/09/29 08:16:42 INFO Received complete push request method=POST path=/api/pushes/1/complete16852026/09/29 08:16:42 WARN Failed to register uploaded object key=82wlq5pa1xxxj5a5qj0mkfwfzcs0gjm1.narinfo error="server returned 404: 404 page not found\n"16862026/09/29 08:16:42 INFO Upload complete. (216ms)16872026/09/29 08:16:42 OK 20260920000000_drop_claims.sql (56.93ms)1688=== NAME TestClientPushesUseOnePush1689 client_pushes_test.go:97: Retrieved narinfo from S3:1690 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestClientPushesUseOnePush2541046531/001/store/y27pjjd4sqwcx9f2y0cwqiyddcny5wr5-shared-dep1691 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1692 Compression: zstd1693 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821694 NarSize: 1361695 References: 1696 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1697 client_pushes_test.go:97: Retrieved narinfo from S3:1698 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestClientPushesUseOnePush2541046531/001/store/j3lxakya5ii86cr8mdn9k9pgw0i0bscc-a1699 URL: nar/15vqznp2zgra2074ny1jw7bb8a3qnj5k3dw0qz5rszs6xaba6hg0.nar.zst1700 Compression: zstd1701 NarHash: sha256:15vqznp2zgra2074ny1jw7bb8a3qnj5k3dw0qz5rszs6xaba6hg01702 NarSize: 2481703 References: /nix/var/nix/builds/nix-9113-1245729578/TestClientPushesUseOnePush2541046531/001/store/y27pjjd4sqwcx9f2y0cwqiyddcny5wr5-shared-dep1704 CA: text:sha256:0j7xa22kbhfw2x4nki8p2sfdhrjpjccw9sc2y0qs9338cc9zcykf1705 client_pushes_test.go:97: Retrieved narinfo from S3:1706 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestClientPushesUseOnePush2541046531/001/store/82wlq5pa1xxxj5a5qj0mkfwfzcs0gjm1-b1707 URL: nar/15vqznp2zgra2074ny1jw7bb8a3qnj5k3dw0qz5rszs6xaba6hg0.nar.zst1708 Compression: zstd1709 NarHash: sha256:15vqznp2zgra2074ny1jw7bb8a3qnj5k3dw0qz5rszs6xaba6hg01710 NarSize: 2481711 References: /nix/var/nix/builds/nix-9113-1245729578/TestClientPushesUseOnePush2541046531/001/store/y27pjjd4sqwcx9f2y0cwqiyddcny5wr5-shared-dep1712 CA: text:sha256:0j7xa22kbhfw2x4nki8p2sfdhrjpjccw9sc2y0qs9338cc9zcykf17132026/09/29 08:16:42 OK 20260923120000_add_pushes.sql (23.66ms)17142026/09/29 08:16:42 goose: successfully migrated database to version: 2026092312000017152026/09/29 08:16:42 OK 1_commit_pending_closure.sql (1.68ms)17162026/09/29 08:16:42 OK 2_object_stats_trigger.sql (256.13µs)17172026/09/29 08:16:42 OK 3_commit_push.sql (235.46µs)17182026/09/29 08:16:42 goose: up to current file version: 31719--- PASS: TestClientPushesUseOnePush (3.15s)1720=== CONT TestLeadElectsOneAndHandsOver17212026-09-29 08:16:42.720 UTC [9493] ERROR: relation "goose_db_version" does not exist at character 3617222026-09-29 08:16:42.720 UTC [9493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17232026/09/29 08:16:42 OK 20241026095416_initial_model.sql (169.44ms)17242026/09/29 08:16:42 OK 20251210153512_drop_unused_gin_index.sql (19.83ms)17252026/09/29 08:16:42 OK 20251218171726_add_pins.sql (61.75ms)17262026/09/29 08:16:42 OK 20260628120000_add_object_size_and_stats.sql (37.61ms)1727=== NAME TestClientIntegration1728 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-9113-1245729578/TestClientIntegration3695672484/002/store/lispz7qg79kabnp90sspxvzviqvk8nfs-test-file.txt17292026/09/29 08:16:42 OK 20260905000000_add_claims.sql (73.97ms)17302026/09/29 08:16:42 OK 20260920000000_drop_claims.sql (22.34ms)17312026/09/29 08:16:42 OK 20260923120000_add_pushes.sql (6.68ms)17322026/09/29 08:16:42 goose: successfully migrated database to version: 2026092312000017332026/09/29 08:16:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17342026/09/29 08:16:42 OK 1_commit_pending_closure.sql (855.17µs)17352026/09/29 08:16:42 OK 2_object_stats_trigger.sql (207.67µs)17362026/09/29 08:16:42 OK 3_commit_push.sql (204µs)17372026/09/29 08:16:42 goose: up to current file version: 317382026/09/29 08:16:42 OK 20241026095416_initial_model.sql (175.69ms)17392026/09/29 08:16:42 INFO Received push request method=POST path=/api/pushes17402026/09/29 08:16:43 OK 20251210153512_drop_unused_gin_index.sql (18.32ms)17412026/09/29 08:16:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17422026/09/29 08:16:43 INFO Uploading lispz7qg79kabnp90sspxvzviqvk8nfs-test-file.txt (152B)17432026/09/29 08:16:43 OK 20251218171726_add_pins.sql (27.18ms)17442026/09/29 08:16:43 WARN Failed to register uploaded object key=lispz7qg79kabnp90sspxvzviqvk8nfs.ls error="server returned 404: 404 page not found\n"17452026/09/29 08:16:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjEyNGRmYjQtODZmMi00MzVjLWIxZGMtZWJjYWI4ZmVmYzA2LjY5MTc5Mjc2LWY0N2YtNGY2MC1iYmQ1LTQ5NmY4NDJkMDc0NngxNzkwNjY5ODAxMjA3NTQyMDAw parts=121746--- PASS: TestRedundantMultipartUpload (5.98s)1747=== CONT TestCacheStatsHandler17482026/09/29 08:16:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17492026/09/29 08:16:43 INFO Signed narinfos id=1 count=117502026/09/29 08:16:43 INFO Uploading 1 narinfos17512026/09/29 08:16:43 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17522026/09/29 08:16:43 OK 20260628120000_add_object_size_and_stats.sql (35.37ms)17532026/09/29 08:16:43 INFO Received complete push request method=POST path=/api/pushes/1/complete17542026/09/29 08:16:43 WARN Failed to register uploaded object key=lispz7qg79kabnp90sspxvzviqvk8nfs.narinfo error="server returned 404: 404 page not found\n"17552026/09/29 08:16:43 INFO Upload complete. (179ms)17562026/09/29 08:16:43 INFO All 1 paths already cached1757=== NAME TestClientIntegration1758 client_integration_test.go:312: Retrieved narinfo from S3:1759 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestClientIntegration3695672484/002/store/lispz7qg79kabnp90sspxvzviqvk8nfs-test-file.txt1760 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1761 Compression: zstd1762 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11763 NarSize: 1521764 References: 1765 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11766 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1767 client_integration_test.go:313: Decompressed .ls content (64 bytes):1768 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1769 client_integration_test.go:316: Testing garbage collection...17702026/09/29 08:16:43 OK 20260905000000_add_claims.sql (81.24ms)17712026/09/29 08:16:43 OK 20260920000000_drop_claims.sql (19.37ms)17722026/09/29 08:16:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures17732026/09/29 08:16:43 INFO Garbage collection started17742026/09/29 08:16:43 INFO Aborted multipart uploads count=017752026/09/29 08:16:43 WARN Force mode enabled - objects will be deleted immediately without grace period17762026/09/29 08:16:43 OK 20260923120000_add_pushes.sql (25.19ms)17772026/09/29 08:16:43 goose: successfully migrated database to version: 2026092312000017782026-09-29 08:16:43.194 UTC [9508] ERROR: relation "goose_db_version" does not exist at character 3617792026-09-29 08:16:43.194 UTC [9508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17802026/09/29 08:16:43 OK 1_commit_pending_closure.sql (864.83µs)17812026/09/29 08:16:43 OK 2_object_stats_trigger.sql (215.83µs)17822026/09/29 08:16:43 OK 3_commit_push.sql (182.04µs)17832026/09/29 08:16:43 goose: up to current file version: 31784=== NAME TestPinProtectsFromGC1785 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-9113-1245729578/TestPinProtectsFromGC830845598/001/store/8vd6vygzn2nzxppqzbyankwhzzrlyjf2-pinned-file.txt1786 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-9113-1245729578/TestPinProtectsFromGC830845598/001/store/nnzx2dsv7m9skk9bp4z8ga26fn9qz35x-unpinned-file.txt17872026-09-29 08:16:43.276 UTC [9516] ERROR: relation "goose_db_version" does not exist at character 3617882026-09-29 08:16:43.276 UTC [9516] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17892026/09/29 08:16:43 OK 20241026095416_initial_model.sql (112.49ms)17902026/09/29 08:16:43 OK 20251210153512_drop_unused_gin_index.sql (13.59ms)17912026/09/29 08:16:43 INFO Received push request method=POST path=/api/pushes17922026/09/29 08:16:43 OK 20251218171726_add_pins.sql (26.37ms)17932026/09/29 08:16:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17942026/09/29 08:16:43 INFO Uploading 8vd6vygzn2nzxppqzbyankwhzzrlyjf2-pinned-file.txt (128B)17952026/09/29 08:16:43 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=017962026/09/29 08:16:43 WARN Failed to register uploaded object key=8vd6vygzn2nzxppqzbyankwhzzrlyjf2.ls error="server returned 404: 404 page not found\n"17972026/09/29 08:16:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17982026/09/29 08:16:43 INFO Signed narinfos id=1 count=117992026/09/29 08:16:43 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18002026/09/29 08:16:43 INFO Uploading 1 narinfos18012026/09/29 08:16:43 OK 20260628120000_add_object_size_and_stats.sql (25.22ms)18022026/09/29 08:16:43 INFO Received complete push request method=POST path=/api/pushes/1/complete18032026/09/29 08:16:43 WARN Failed to register uploaded object key=8vd6vygzn2nzxppqzbyankwhzzrlyjf2.narinfo error="server returned 404: 404 page not found\n"18042026/09/29 08:16:43 INFO Vacuumed table table=pending_closures18052026/09/29 08:16:43 INFO Upload complete. (123ms)18062026/09/29 08:16:43 INFO Vacuumed table table=pending_objects18072026/09/29 08:16:43 INFO Vacuumed table table=multipart_uploads18082026/09/29 08:16:43 INFO Vacuumed table table=closures18092026/09/29 08:16:43 OK 20260905000000_add_claims.sql (58.66ms)18102026/09/29 08:16:43 INFO Vacuumed table table=objects18112026/09/29 08:16:43 OK 20260920000000_drop_claims.sql (23.92ms)18122026/09/29 08:16:43 OK 20241026095416_initial_model.sql (160.05ms)18132026/09/29 08:16:43 OK 20260923120000_add_pushes.sql (5.5ms)18142026/09/29 08:16:43 goose: successfully migrated database to version: 2026092312000018152026/09/29 08:16:43 OK 20251210153512_drop_unused_gin_index.sql (5.35ms)18162026/09/29 08:16:43 OK 1_commit_pending_closure.sql (1.14ms)18172026/09/29 08:16:43 OK 2_object_stats_trigger.sql (229.21µs)18182026/09/29 08:16:43 OK 3_commit_push.sql (172.46µs)18192026/09/29 08:16:43 goose: up to current file version: 318202026/09/29 08:16:43 INFO Received push request method=POST path=/api/pushes18212026/09/29 08:16:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18222026/09/29 08:16:43 INFO Uploading nnzx2dsv7m9skk9bp4z8ga26fn9qz35x-unpinned-file.txt (128B)18232026/09/29 08:16:43 OK 20251218171726_add_pins.sql (33.91ms)18242026/09/29 08:16:43 WARN Failed to register uploaded object key=nnzx2dsv7m9skk9bp4z8ga26fn9qz35x.ls error="server returned 404: 404 page not found\n"18252026/09/29 08:16:43 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18262026/09/29 08:16:43 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18272026/09/29 08:16:43 INFO Signed narinfos id=2 count=118282026/09/29 08:16:43 INFO Uploading 1 narinfos18292026/09/29 08:16:43 INFO Received complete push request method=POST path=/api/pushes/2/complete18302026/09/29 08:16:43 WARN Failed to register uploaded object key=nnzx2dsv7m9skk9bp4z8ga26fn9qz35x.narinfo error="server returned 404: 404 page not found\n"1831--- PASS: TestObjectStatsTrigger (2.91s)1832=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected18332026/09/29 08:16:43 INFO Upload complete. (89ms)18342026/09/29 08:16:43 OK 20260628120000_add_object_size_and_stats.sql (27.96ms)18352026/09/29 08:16:43 INFO Received create pin request method=POST path=/api/pins/myapp18362026/09/29 08:16:43 OK 20260905000000_add_claims.sql (43.7ms)18372026/09/29 08:16:43 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-9113-1245729578/TestPinProtectsFromGC830845598/001/store/8vd6vygzn2nzxppqzbyankwhzzrlyjf2-pinned-file.txt narinfo_key=8vd6vygzn2nzxppqzbyankwhzzrlyjf2.narinfo18382026/09/29 08:16:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures18392026/09/29 08:16:43 INFO Garbage collection started18402026/09/29 08:16:43 INFO Aborted multipart uploads count=018412026/09/29 08:16:43 WARN Force mode enabled - objects will be deleted immediately without grace period18422026/09/29 08:16:43 OK 20260920000000_drop_claims.sql (17.32ms)18432026/09/29 08:16:43 INFO Received push request method=POST path=/api/pushes18442026/09/29 08:16:43 OK 20260923120000_add_pushes.sql (11.48ms)18452026/09/29 08:16:43 goose: successfully migrated database to version: 2026092312000018462026/09/29 08:16:43 OK 1_commit_pending_closure.sql (1.09ms)18472026/09/29 08:16:43 OK 2_object_stats_trigger.sql (197.96µs)18482026/09/29 08:16:43 OK 3_commit_push.sql (159.67µs)18492026/09/29 08:16:43 goose: up to current file version: 318502026/09/29 08:16:43 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18512026/09/29 08:16:43 INFO Uploading zfjjsb1mvfcdvcpn5xv971fqyq9914qn-top (256B)18522026/09/29 08:16:43 INFO Uploading iskxjvnrq0b75l4jrqblcg26bbh972q7-shared-dep (136B)18532026/09/29 08:16:43 WARN Failed to register uploaded object key=iskxjvnrq0b75l4jrqblcg26bbh972q7.ls error="server returned 404: 404 page not found\n"18542026/09/29 08:16:43 WARN Failed to register uploaded object key=nar/1chbbn9kkkxymqps9n2z9lpshd8gcmxjwr3kd6v2fslqs2gg2kq2.nar.zst error="server returned 404: 404 page not found\n"18552026/09/29 08:16:43 WARN Failed to register uploaded object key=zfjjsb1mvfcdvcpn5xv971fqyq9914qn.ls error="server returned 404: 404 page not found\n"18562026/09/29 08:16:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18572026/09/29 08:16:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18582026/09/29 08:16:43 INFO Signed narinfos id=1 count=218592026/09/29 08:16:43 INFO Uploading 2 narinfos18602026/09/29 08:16:43 WARN Failed to register uploaded object key=zfjjsb1mvfcdvcpn5xv971fqyq9914qn.narinfo error="server returned 404: 404 page not found\n"18612026/09/29 08:16:43 INFO Received complete push request method=POST path=/api/pushes/1/complete18622026/09/29 08:16:43 WARN Failed to register uploaded object key=iskxjvnrq0b75l4jrqblcg26bbh972q7.narinfo error="server returned 404: 404 page not found\n"18632026/09/29 08:16:43 INFO Upload complete. (127ms)1864=== NAME TestClientSharedPathCommittedMidPush1865 client_integration_test.go:680: Retrieved narinfo from S3:1866 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestClientSharedPathCommittedMidPush1186460222/001/store/iskxjvnrq0b75l4jrqblcg26bbh972q7-shared-dep1867 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1868 Compression: zstd1869 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821870 NarSize: 1361871 References: 1872 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1873 client_integration_test.go:680: Retrieved narinfo from S3:1874 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestClientSharedPathCommittedMidPush1186460222/001/store/zfjjsb1mvfcdvcpn5xv971fqyq9914qn-top1875 URL: nar/1chbbn9kkkxymqps9n2z9lpshd8gcmxjwr3kd6v2fslqs2gg2kq2.nar.zst1876 Compression: zstd1877 NarHash: sha256:1chbbn9kkkxymqps9n2z9lpshd8gcmxjwr3kd6v2fslqs2gg2kq21878 NarSize: 2561879 References: /nix/var/nix/builds/nix-9113-1245729578/TestClientSharedPathCommittedMidPush1186460222/001/store/iskxjvnrq0b75l4jrqblcg26bbh972q7-shared-dep1880 CA: text:sha256:1yvypybqy8kfq3a3r5f6i99m3hyyw5vqf004sg0bmli4wij1pls91881--- PASS: TestClientSharedPathCommittedMidPush (3.30s)1882=== CONT TestResolveDBConnectionString1883=== RUN TestResolveDBConnectionString/flag_wins1884=== PAUSE TestResolveDBConnectionString/flag_wins1885=== RUN TestResolveDBConnectionString/file_when_flag_empty1886=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1887=== RUN TestResolveDBConnectionString/missing_file_is_an_error1888=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1889=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1890=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1891=== RUN TestResolveDBConnectionString/nothing_configured1892=== PAUSE TestResolveDBConnectionString/nothing_configured1893=== CONT TestCacheConfigHandler1894=== RUN TestCacheConfigHandler/full_config,_no_issuer1895=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1896=== RUN TestCacheConfigHandler/no_cache_url_configured1897=== PAUSE TestCacheConfigHandler/no_cache_url_configured1898=== RUN TestCacheConfigHandler/no_signing_keys1899=== PAUSE TestCacheConfigHandler/no_signing_keys1900=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1901=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1902=== CONT TestClientFallsBackToClosures19032026/09/29 08:16:43 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=019042026/09/29 08:16:43 INFO Vacuumed table table=pending_closures19052026/09/29 08:16:43 INFO Vacuumed table table=pending_objects19062026/09/29 08:16:43 INFO Vacuumed table table=multipart_uploads19072026/09/29 08:16:43 INFO Vacuumed table table=closures19082026/09/29 08:16:43 INFO Vacuumed table table=objects19092026-09-29 08:16:43.923 UTC [9546] ERROR: relation "goose_db_version" does not exist at character 3619102026-09-29 08:16:43.923 UTC [9546] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1911=== NAME TestClientMultipleUploads1912 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-9113-1245729578/TestClientMultipleUploads2371060502/001/store/v1cag2zs13yhynr3jjkgvmsqawqi3q6b-test-file-0.txt19132026/09/29 08:16:43 OK 20241026095416_initial_model.sql (37.71ms)19142026/09/29 08:16:43 OK 20251210153512_drop_unused_gin_index.sql (604.42µs)19152026-09-29 08:16:43.985 UTC [9550] ERROR: relation "goose_db_version" does not exist at character 3619162026-09-29 08:16:43.985 UTC [9550] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19172026/09/29 08:16:43 OK 20251218171726_add_pins.sql (1.04ms)19182026/09/29 08:16:43 OK 20260628120000_add_object_size_and_stats.sql (4.97ms)19192026/09/29 08:16:43 OK 20260905000000_add_claims.sql (1.72ms)19202026/09/29 08:16:43 OK 20260920000000_drop_claims.sql (1.1ms)19212026/09/29 08:16:43 OK 20260923120000_add_pushes.sql (1.73ms)19222026/09/29 08:16:43 goose: successfully migrated database to version: 2026092312000019232026/09/29 08:16:43 OK 20241026095416_initial_model.sql (6.17ms)19242026/09/29 08:16:43 OK 20251210153512_drop_unused_gin_index.sql (540.67µs)19252026/09/29 08:16:43 OK 1_commit_pending_closure.sql (1.28ms)19262026/09/29 08:16:43 OK 2_object_stats_trigger.sql (487.38µs)19272026/09/29 08:16:43 OK 20251218171726_add_pins.sql (931.96µs)19282026/09/29 08:16:43 OK 3_commit_push.sql (511.71µs)19292026/09/29 08:16:43 goose: up to current file version: 319302026/09/29 08:16:43 OK 20260628120000_add_object_size_and_stats.sql (1.45ms)19312026/09/29 08:16:44 OK 20260905000000_add_claims.sql (1.17ms)19322026/09/29 08:16:44 OK 20260920000000_drop_claims.sql (13.37ms)19332026/09/29 08:16:44 OK 20260923120000_add_pushes.sql (7.72ms)19342026/09/29 08:16:44 goose: successfully migrated database to version: 2026092312000019352026/09/29 08:16:44 OK 1_commit_pending_closure.sql (990.38µs)19362026/09/29 08:16:44 OK 2_object_stats_trigger.sql (209.71µs)19372026/09/29 08:16:44 OK 3_commit_push.sql (202.83µs)19382026/09/29 08:16:44 goose: up to current file version: 319392026-09-29 08:16:44.029 UTC [9553] ERROR: relation "goose_db_version" does not exist at character 3619402026-09-29 08:16:44.029 UTC [9553] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1941 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-9113-1245729578/TestClientMultipleUploads2371060502/001/store/8m1hvhh2xm4gxdd34ly1p8grvnj7y7in-test-file-1.txt1942=== NAME TestClientWithDependencies1943 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-9113-1245729578/TestClientWithDependencies3981664939/001/store/y3iiplhaxbjffand6gdkqrbsqf5j1l6h-test-script1944=== NAME TestClientMultipleUploads1945 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-9113-1245729578/TestClientMultipleUploads2371060502/001/store/d1dlmyirq7zblkfqf03mvlyz69pxzm7i-test-file-2.txt19462026/09/29 08:16:44 OK 20241026095416_initial_model.sql (31.12ms)19472026/09/29 08:16:44 OK 20251210153512_drop_unused_gin_index.sql (6.27ms)1948=== NAME TestClientWithDependencies1949 client_integration_test.go:615: Found 1 dependencies (including self)19502026/09/29 08:16:44 OK 20251218171726_add_pins.sql (7.31ms)19512026/09/29 08:16:44 OK 20260628120000_add_object_size_and_stats.sql (9.61ms)19522026/09/29 08:16:44 OK 20260905000000_add_claims.sql (14.02ms)19532026/09/29 08:16:44 OK 20260920000000_drop_claims.sql (7.36ms)19542026/09/29 08:16:44 OK 20260923120000_add_pushes.sql (5.85ms)19552026/09/29 08:16:44 goose: successfully migrated database to version: 2026092312000019562026/09/29 08:16:44 OK 1_commit_pending_closure.sql (900.42µs)19572026/09/29 08:16:44 OK 2_object_stats_trigger.sql (199.79µs)19582026/09/29 08:16:44 OK 3_commit_push.sql (163.29µs)19592026/09/29 08:16:44 goose: up to current file version: 319602026/09/29 08:16:44 INFO Received push request method=POST path=/api/pushes19612026/09/29 08:16:44 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19622026/09/29 08:16:44 INFO Uploading d1dlmyirq7zblkfqf03mvlyz69pxzm7i-test-file-2.txt (160B)19632026/09/29 08:16:44 INFO Uploading v1cag2zs13yhynr3jjkgvmsqawqi3q6b-test-file-0.txt (160B)19642026/09/29 08:16:44 INFO Uploading 8m1hvhh2xm4gxdd34ly1p8grvnj7y7in-test-file-1.txt (160B)19652026/09/29 08:16:44 INFO Received push request method=POST path=/api/pushes19662026/09/29 08:16:44 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19672026/09/29 08:16:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19682026/09/29 08:16:44 WARN Failed to register uploaded object key=v1cag2zs13yhynr3jjkgvmsqawqi3q6b.ls error="server returned 404: 404 page not found\n"19692026/09/29 08:16:44 INFO Uploading y3iiplhaxbjffand6gdkqrbsqf5j1l6h-test-script (136B)19702026/09/29 08:16:44 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19712026/09/29 08:16:44 WARN Failed to register uploaded object key=d1dlmyirq7zblkfqf03mvlyz69pxzm7i.ls error="server returned 404: 404 page not found\n"19722026/09/29 08:16:44 WARN Failed to register uploaded object key=8m1hvhh2xm4gxdd34ly1p8grvnj7y7in.ls error="server returned 404: 404 page not found\n"19732026/09/29 08:16:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19742026/09/29 08:16:44 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19752026/09/29 08:16:44 INFO Signed narinfos id=1 count=319762026/09/29 08:16:44 INFO Uploading 3 narinfos19772026/09/29 08:16:44 WARN Failed to register uploaded object key=y3iiplhaxbjffand6gdkqrbsqf5j1l6h.ls error="server returned 404: 404 page not found\n"19782026/09/29 08:16:44 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19792026/09/29 08:16:44 WARN Failed to register uploaded object key=log/czvclvsh8py6r2aqmscs6gzd5f4lm0ms-test-script.drv error="server returned 404: 404 page not found\n"19802026/09/29 08:16:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19812026/09/29 08:16:44 INFO Signed narinfos id=1 count=119822026/09/29 08:16:44 INFO Uploading 1 narinfos19832026/09/29 08:16:44 WARN Failed to register uploaded object key=v1cag2zs13yhynr3jjkgvmsqawqi3q6b.narinfo error="server returned 404: 404 page not found\n"19842026/09/29 08:16:44 INFO Received complete push request method=POST path=/api/pushes/1/complete19852026/09/29 08:16:44 WARN Failed to register uploaded object key=d1dlmyirq7zblkfqf03mvlyz69pxzm7i.narinfo error="server returned 404: 404 page not found\n"19862026/09/29 08:16:44 WARN Failed to register uploaded object key=8m1hvhh2xm4gxdd34ly1p8grvnj7y7in.narinfo error="server returned 404: 404 page not found\n"19872026/09/29 08:16:44 INFO Received complete push request method=POST path=/api/pushes/1/complete19882026/09/29 08:16:44 WARN Failed to register uploaded object key=y3iiplhaxbjffand6gdkqrbsqf5j1l6h.narinfo error="server returned 404: 404 page not found\n"19892026/09/29 08:16:44 INFO Upload complete. (120ms)1990=== NAME TestClientMultipleUploads1991 client_integration_test.go:369: Uploaded 3 paths in 153.850083ms19922026/09/29 08:16:44 INFO Upload complete. (108ms)1993=== NAME TestClientWithDependencies1994 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-9113-1245729578/TestClientWithDependencies3981664939/001/store) requires matching store prefix1995--- PASS: TestClientMultipleUploads (2.87s)1996=== CONT TestIsValidUploadKey1997=== RUN TestIsValidUploadKey/narinfo1998=== PAUSE TestIsValidUploadKey/narinfo1999=== RUN TestIsValidUploadKey/nar_zst2000=== PAUSE TestIsValidUploadKey/nar_zst2001=== RUN TestIsValidUploadKey/nar_xz2002--- PASS: TestClientWithDependencies (3.15s)2003=== CONT TestService_ReadScope_PublicByDefault2004=== PAUSE TestIsValidUploadKey/nar_xz2005=== RUN TestIsValidUploadKey/nar_plain2006=== PAUSE TestIsValidUploadKey/nar_plain2007=== RUN TestIsValidUploadKey/listing2008=== PAUSE TestIsValidUploadKey/listing2009=== RUN TestIsValidUploadKey/build_log2010=== PAUSE TestIsValidUploadKey/build_log2011=== RUN TestIsValidUploadKey/build_log_home-manager_file2012=== PAUSE TestIsValidUploadKey/build_log_home-manager_file2013=== RUN TestIsValidUploadKey/build_log_plus_in_name2014=== PAUSE TestIsValidUploadKey/build_log_plus_in_name2015=== RUN TestIsValidUploadKey/build_log_question_mark2016=== PAUSE TestIsValidUploadKey/build_log_question_mark2017=== RUN TestIsValidUploadKey/build_log_equals2018=== PAUSE TestIsValidUploadKey/build_log_equals2019=== RUN TestIsValidUploadKey/realisation2020=== PAUSE TestIsValidUploadKey/realisation2021=== RUN TestIsValidUploadKey/realisation_plus_in_output2022=== PAUSE TestIsValidUploadKey/realisation_plus_in_output2023=== RUN TestIsValidUploadKey/nix-cache-info2024=== PAUSE TestIsValidUploadKey/nix-cache-info2025=== RUN TestIsValidUploadKey/index.html2026=== PAUSE TestIsValidUploadKey/index.html2027=== RUN TestIsValidUploadKey/narinfo_key,_nar_type2028=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type2029=== RUN TestIsValidUploadKey/nar_key,_narinfo_type2030=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type2031=== RUN TestIsValidUploadKey/listing_key,_narinfo_type2032=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type2033=== RUN TestIsValidUploadKey/traversal2034=== PAUSE TestIsValidUploadKey/traversal2035=== RUN TestIsValidUploadKey/traversal_nar2036=== PAUSE TestIsValidUploadKey/traversal_nar2037=== RUN TestIsValidUploadKey/absolute2038=== PAUSE TestIsValidUploadKey/absolute2039=== RUN TestIsValidUploadKey/empty_key2040=== PAUSE TestIsValidUploadKey/empty_key2041=== RUN TestIsValidUploadKey/unknown_type2042=== PAUSE TestIsValidUploadKey/unknown_type2043=== CONT TestService_AuthMiddleware_MTLSBoundSubjects20442026-09-29 08:16:44.376 UTC [9574] ERROR: relation "goose_db_version" does not exist at character 3620452026-09-29 08:16:44.376 UTC [9574] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20462026/09/29 08:16:44 INFO lead: acquired remote=192.0.2.1:123420472026/09/29 08:16:44 OK 20241026095416_initial_model.sql (53.2ms)20482026/09/29 08:16:44 OK 20251210153512_drop_unused_gin_index.sql (7.76ms)2049=== NAME TestOrphanedObjectsGCStressTest2050 orphaned_objects_gc_test.go:509: Stress test completed successfully:2051 orphaned_objects_gc_test.go:510: - Active objects preserved: 202052 orphaned_objects_gc_test.go:511: - Objects deleted: 2102053 orphaned_objects_gc_test.go:512: - Total GC'd: 2102054--- PASS: TestOrphanedObjectsGCStressTest (10.39s)2055=== CONT TestService_AuthMiddleware_MTLSProxyHeader20562026/09/29 08:16:44 OK 20251218171726_add_pins.sql (17.39ms)20572026/09/29 08:16:44 OK 20260628120000_add_object_size_and_stats.sql (17.41ms)20582026-09-29 08:16:44.512 UTC [9577] ERROR: relation "goose_db_version" does not exist at character 3620592026-09-29 08:16:44.512 UTC [9577] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20602026/09/29 08:16:44 OK 20260905000000_add_claims.sql (32.61ms)20612026/09/29 08:16:44 INFO lead: released remote=192.0.2.1:123420622026/09/29 08:16:44 OK 20260920000000_drop_claims.sql (9.54ms)2063=== NAME TestClientCADerivations2064 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-9113-1245729578/TestClientCADerivations2852412919/001/store/s1pps883289ks7qxbmancp8pzd11zd2a-ca-test20652026/09/29 08:16:44 OK 20260923120000_add_pushes.sql (6.48ms)20662026/09/29 08:16:44 goose: successfully migrated database to version: 2026092312000020672026/09/29 08:16:44 OK 1_commit_pending_closure.sql (968.21µs)20682026/09/29 08:16:44 OK 2_object_stats_trigger.sql (217.08µs)20692026/09/29 08:16:44 OK 3_commit_push.sql (184.29µs)20702026/09/29 08:16:44 goose: up to current file version: 320712026/09/29 08:16:44 INFO lead: acquired remote=192.0.2.1:123420722026/09/29 08:16:44 INFO lead: released remote=192.0.2.1:12342073--- PASS: TestLeadElectsOneAndHandsOver (1.95s)2074=== CONT TestService_RequireScope_OIDC2075=== NAME TestClientCADerivations2076 client_ca_test.go:139: Found 1 dependencies (including self)2077--- PASS: TestCacheStatsHandler (1.57s)2078=== CONT TestService_AuthMiddleware_OIDC20792026/09/29 08:16:44 OK 20241026095416_initial_model.sql (74.07ms)20802026/09/29 08:16:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56390/oidc20812026/09/29 08:16:44 OK 20251210153512_drop_unused_gin_index.sql (7.78ms)20822026/09/29 08:16:44 OK 20251218171726_add_pins.sql (5.39ms)20832026/09/29 08:16:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56392/oidc20842026/09/29 08:16:44 OK 20260628120000_add_object_size_and_stats.sql (7.68ms)20852026/09/29 08:16:44 OK 20260905000000_add_claims.sql (22.15ms)20862026/09/29 08:16:44 OK 20260920000000_drop_claims.sql (26.47ms)20872026/09/29 08:16:44 OK 20260923120000_add_pushes.sql (9.02ms)20882026/09/29 08:16:44 goose: successfully migrated database to version: 2026092312000020892026/09/29 08:16:44 OK 1_commit_pending_closure.sql (925.08µs)20902026/09/29 08:16:44 OK 2_object_stats_trigger.sql (224.75µs)20912026/09/29 08:16:44 OK 3_commit_push.sql (195.33µs)20922026/09/29 08:16:44 goose: up to current file version: 320932026/09/29 08:16:44 INFO Received push request method=POST path=/api/pushes20942026/09/29 08:16:44 INFO Received push request method=POST path=/api/pushes20952026/09/29 08:16:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20962026/09/29 08:16:44 INFO Uploading s1pps883289ks7qxbmancp8pzd11zd2a-ca-test (144B)20972026/09/29 08:16:44 WARN Failed to register uploaded object key=s1pps883289ks7qxbmancp8pzd11zd2a.ls error="server returned 404: 404 page not found\n"20982026/09/29 08:16:44 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20992026/09/29 08:16:44 INFO Received complete push request method=POST path=/api/pushes/1/complete21002026/09/29 08:16:44 WARN Failed to register uploaded object key=log/fws0cqhmamnzblbp7y2581ijadc68vaz-ca-test.drv error="server returned 404: 404 page not found\n"21012026/09/29 08:16:44 INFO Received push request method=POST path=/api/pushes21022026/09/29 08:16:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21032026/09/29 08:16:44 INFO Signed narinfos id=1 count=121042026/09/29 08:16:44 INFO Uploading 1 narinfos21052026/09/29 08:16:44 INFO Received complete push request method=POST path=/api/pushes/1/complete21062026/09/29 08:16:44 WARN Failed to register uploaded object key=s1pps883289ks7qxbmancp8pzd11zd2a.narinfo error="server returned 404: 404 page not found\n"21072026/09/29 08:16:44 INFO Received complete push request method=POST path=/api/pushes/2/complete21082026-09-29 08:16:44.821 UTC [9593] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo21092026-09-29 08:16:44.821 UTC [9593] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE21102026-09-29 08:16:44.821 UTC [9593] STATEMENT: -- name: CommitPush :exec2111 SELECT commit_push($1::bigint)2112 2113--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (1.27s)2114=== CONT TestProxyWriteTimeout2115=== RUN TestProxyWriteTimeout/narinfo2116=== PAUSE TestProxyWriteTimeout/narinfo2117=== RUN TestProxyWriteTimeout/1_GiB_nar2118=== PAUSE TestProxyWriteTimeout/1_GiB_nar2119=== RUN TestProxyWriteTimeout/10_GiB_nar2120=== PAUSE TestProxyWriteTimeout/10_GiB_nar2121=== RUN TestProxyWriteTimeout/unknown_size2122=== PAUSE TestProxyWriteTimeout/unknown_size2123=== CONT TestService_ReadAuthMiddleware21242026/09/29 08:16:44 INFO Upload complete. (202ms)2125=== NAME TestClientCADerivations2126 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestClientCADerivations2852412919/001/store/s1pps883289ks7qxbmancp8pzd11zd2a-ca-test2127 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2128 Compression: zstd2129 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2130 NarSize: 1442131 References: 2132 Deriver: /nix/var/nix/builds/nix-9113-1245729578/TestClientCADerivations2852412919/001/store/fws0cqhmamnzblbp7y2581ijadc68vaz-ca-test.drv2133 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2134 client_ca_test.go:185: Checking for realisation files in S3...2135 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2136 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2137 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket53?endpoint=http://localhost:56167®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-9113-1245729578/TestClientCADerivations2852412919/001/store'2138 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12139--- PASS: TestClientCADerivations (2.61s)2140=== CONT TestParseSize2141--- PASS: TestParseSize (0.00s)2142=== CONT TestServerTLSConfig/no_client_CA2143=== CONT TestServerTLSConfig/not_a_PEM_file2144=== CONT TestServerTLSConfig/missing_CA_file2145--- PASS: TestServerTLSConfig (0.00s)2146 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2147 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2148 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2149=== CONT TestIsValidCachePath/narinfo2150=== CONT TestIsValidCachePath/invalid_char_u2151=== CONT TestIsValidCachePath/invalid_char_e2152=== CONT TestIsValidCachePath/traversal_in_middle2153=== CONT TestIsValidCachePath/traversal_parent2154=== CONT TestIsValidCachePath/index.html2155=== CONT TestIsValidCachePath/nix-cache-info2156=== CONT TestIsValidCachePath/realisation2157=== CONT TestIsValidCachePath/log2158=== CONT TestIsValidCachePath/ls2159=== CONT TestIsValidCachePath/nar_uncompressed2160=== CONT TestIsValidCachePath/nar_bz22161=== CONT TestIsValidCachePath/nar_xz2162=== CONT TestIsValidCachePath/nar_zst2163=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2164=== CONT TestIsValidCachePath/wrong_extension2165=== CONT TestIsValidCachePath/random_path2166=== CONT TestIsValidCachePath/leading_slash2167=== CONT TestIsValidCachePath/empty2168=== CONT TestIsValidCachePath/short_hash2169--- PASS: TestIsValidCachePath (0.00s)2170 --- PASS: TestIsValidCachePath/narinfo (0.00s)2171 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2172 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2173 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2174 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2175 --- PASS: TestIsValidCachePath/index.html (0.00s)2176 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2177 --- PASS: TestIsValidCachePath/realisation (0.00s)2178 --- PASS: TestIsValidCachePath/log (0.00s)2179 --- PASS: TestIsValidCachePath/ls (0.00s)2180 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2181 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2182 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2183 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2184 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2185 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2186 --- PASS: TestIsValidCachePath/random_path (0.00s)2187 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2188 --- PASS: TestIsValidCachePath/empty (0.00s)2189 --- PASS: TestIsValidCachePath/short_hash (0.00s)2190=== CONT TestParseSingleRange/none2191=== CONT TestParseSingleRange/open-ended2192=== CONT TestParseSingleRange/start_far_past_EOF2193=== CONT TestParseSingleRange/start_past_EOF2194=== CONT TestParseSingleRange/single_byte2195=== CONT TestParseSingleRange/suffix_exceeds_size2196=== CONT TestParseSingleRange/suffix2197=== CONT TestParseSingleRange/end_clamped_to_size2198=== CONT TestParseSingleRange/malformed_both_empty2199=== CONT TestParseSingleRange/closed2200=== CONT TestParseSingleRange/malformed_end_before_start2201=== CONT TestParseSingleRange/multi-range_ignored2202=== CONT TestParseSingleRange/malformed_no_dash2203=== CONT TestParseSingleRange/unknown_unit2204=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2205--- PASS: TestParseSingleRange (0.00s)2206 --- PASS: TestParseSingleRange/none (0.00s)2207 --- PASS: TestParseSingleRange/open-ended (0.00s)2208 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2209 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2210 --- PASS: TestParseSingleRange/single_byte (0.00s)2211 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2212 --- PASS: TestParseSingleRange/suffix (0.00s)2213 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2214 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2215 --- PASS: TestParseSingleRange/closed (0.00s)2216 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2217 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2218 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2219 --- PASS: TestParseSingleRange/unknown_unit (0.00s)22202026/09/29 08:16:44 INFO Received uploads request method=POST path=/2221=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key22222026/09/29 08:16:44 INFO Received complete multipart upload request method=POST path=/2223=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key22242026/09/29 08:16:44 INFO Received request for more parts method=POST path=/2225=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal22262026/09/29 08:16:44 INFO Received uploads request method=POST path=/2227=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure2228--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2229 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2230 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2231 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2232 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)22332026/09/29 08:16:44 INFO Received uploads request method=POST path=/22342026-09-29 08:16:45.002 UTC [9601] ERROR: relation "goose_db_version" does not exist at character 3622352026-09-29 08:16:45.002 UTC [9601] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22362026-09-29 08:16:45.002 UTC [9602] ERROR: relation "goose_db_version" does not exist at character 3622372026-09-29 08:16:45.002 UTC [9602] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22382026/09/29 08:16:45 OK 20241026095416_initial_model.sql (7.51ms)22392026/09/29 08:16:45 OK 20241026095416_initial_model.sql (5.94ms)22402026/09/29 08:16:45 OK 20251210153512_drop_unused_gin_index.sql (504.63µs)22412026/09/29 08:16:45 OK 20251210153512_drop_unused_gin_index.sql (616.17µs)22422026/09/29 08:16:45 OK 20251218171726_add_pins.sql (1.36ms)22432026/09/29 08:16:45 OK 20251218171726_add_pins.sql (1.31ms)22442026/09/29 08:16:45 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)22452026/09/29 08:16:45 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)22462026/09/29 08:16:45 OK 20260905000000_add_claims.sql (1.54ms)22472026/09/29 08:16:45 OK 20260920000000_drop_claims.sql (673.29µs)22482026/09/29 08:16:45 OK 20260923120000_add_pushes.sql (514.83µs)22492026/09/29 08:16:45 goose: successfully migrated database to version: 2026092312000022502026/09/29 08:16:45 OK 20260905000000_add_claims.sql (2.7ms)22512026/09/29 08:16:45 OK 20260920000000_drop_claims.sql (792.42µs)22522026/09/29 08:16:45 OK 1_commit_pending_closure.sql (1.63ms)22532026/09/29 08:16:45 OK 2_object_stats_trigger.sql (395.46µs)22542026/09/29 08:16:45 OK 3_commit_push.sql (212.67µs)22552026/09/29 08:16:45 goose: up to current file version: 322562026/09/29 08:16:45 OK 20260923120000_add_pushes.sql (1.1ms)22572026/09/29 08:16:45 goose: successfully migrated database to version: 2026092312000022582026/09/29 08:16:45 OK 1_commit_pending_closure.sql (905.08µs)22592026/09/29 08:16:45 OK 2_object_stats_trigger.sql (244.67µs)22602026/09/29 08:16:45 OK 3_commit_push.sql (358.13µs)22612026/09/29 08:16:45 goose: up to current file version: 322622026/09/29 08:16:45 INFO Received uploads request method=POST path=/api/pending_closures22632026/09/29 08:16:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"22642026/09/29 08:16:45 WARN mTLS auth: bound subjects configured but subject DN unavailable22652026/09/29 08:16:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2266--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.86s)2267=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22682026/09/29 08:16:45 INFO Received request for more parts method=POST path=/22692026/09/29 08:16:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02270=== NAME TestClientIntegration2271 client_integration_test.go:323: Objects in database after GC:2272 client_integration_test.go:323: Successfully deleted all objects with GC --force2273=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart22742026/09/29 08:16:45 INFO Received complete multipart upload request method=POST path=/2275=== CONT TestPush_RejectsBadRequests/no_roots22762026/09/29 08:16:45 INFO Received push request method=POST path=/api/pushes2277=== CONT TestPush_RejectsBadRequests/bad_root22782026/09/29 08:16:45 INFO Received push request method=POST path=/api/pushes2279=== CONT TestPush_RejectsBadRequests/root_not_in_objects22802026/09/29 08:16:45 INFO Received push request method=POST path=/api/pushes2281=== CONT TestPush_RejectsBadRequests/no_objects22822026/09/29 08:16:45 INFO Received push request method=POST path=/api/pushes2283=== CONT TestClientErrorHandling/InvalidStorePath2284--- PASS: TestPush_RejectsBadRequests (2.76s)2285 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2286 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2287 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2288 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2289--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)2290 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2291 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2292 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)2293=== CONT TestClientErrorHandling/InvalidAuthToken22942026/09/29 08:16:45 INFO Received uploads request method=POST path=/api/pending_closures22952026/09/29 08:16:45 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)22962026/09/29 08:16:45 INFO Uploading 2yk72g923m9r7vbv7ijwqqzb9lzw9gnc-shared-dep (136B)22972026/09/29 08:16:45 INFO Uploading 0wkw3ip5h6d3pmcjsv77mwz53a3c03qf-a (248B)2298--- PASS: TestClientIntegration (5.20s)2299=== CONT TestClientErrorHandling/ServerNotAvailable23002026/09/29 08:16:45 WARN Failed to register uploaded object key=0wkw3ip5h6d3pmcjsv77mwz53a3c03qf.ls error="server returned 404: 404 page not found\n"23012026/09/29 08:16:45 WARN Failed to register uploaded object key=5qxaj4frmrmrkxs7ck6ks4bbw566hhrd.ls error="server returned 404: 404 page not found\n"23022026/09/29 08:16:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23032026/09/29 08:16:45 WARN Failed to register uploaded object key=2yk72g923m9r7vbv7ijwqqzb9lzw9gnc.ls error="server returned 404: 404 page not found\n"23042026/09/29 08:16:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23052026/09/29 08:16:45 WARN Failed to register uploaded object key=nar/0nwyh5q1ynwp1j5xxgwz1p05wyn1vkvjzv6s5b4isda5bzlfi425.nar.zst error="server returned 404: 404 page not found\n"23062026/09/29 08:16:45 INFO Signed narinfos id=1 count=223072026/09/29 08:16:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign23082026/09/29 08:16:45 INFO Signed narinfos id=2 count=223092026/09/29 08:16:45 INFO Uploading 4 narinfos23102026/09/29 08:16:45 WARN Failed to register uploaded object key=2yk72g923m9r7vbv7ijwqqzb9lzw9gnc.narinfo error="server returned 404: 404 page not found\n"23112026/09/29 08:16:45 WARN Failed to register uploaded object key=5qxaj4frmrmrkxs7ck6ks4bbw566hhrd.narinfo error="server returned 404: 404 page not found\n"23122026/09/29 08:16:45 WARN Failed to register uploaded object key=0wkw3ip5h6d3pmcjsv77mwz53a3c03qf.narinfo error="server returned 404: 404 page not found\n"23132026/09/29 08:16:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23142026/09/29 08:16:45 WARN Failed to register uploaded object key=2yk72g923m9r7vbv7ijwqqzb9lzw9gnc.narinfo error="server returned 404: 404 page not found\n"23152026/09/29 08:16:45 INFO Completed upload id=123162026/09/29 08:16:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23172026/09/29 08:16:45 INFO Completed upload id=223182026/09/29 08:16:45 INFO Upload complete. (225ms)2319=== NAME TestClientFallsBackToClosures2320 client_pushes_test.go:112: Retrieved narinfo from S3:2321 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestClientFallsBackToClosures3067346809/001/store/2yk72g923m9r7vbv7ijwqqzb9lzw9gnc-shared-dep2322 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2323 Compression: zstd2324 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822325 NarSize: 1362326 References: 2327 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2328 client_pushes_test.go:112: Retrieved narinfo from S3:2329 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestClientFallsBackToClosures3067346809/001/store/0wkw3ip5h6d3pmcjsv77mwz53a3c03qf-a2330 URL: nar/0nwyh5q1ynwp1j5xxgwz1p05wyn1vkvjzv6s5b4isda5bzlfi425.nar.zst2331 Compression: zstd2332 NarHash: sha256:0nwyh5q1ynwp1j5xxgwz1p05wyn1vkvjzv6s5b4isda5bzlfi4252333 NarSize: 2482334 References: /nix/var/nix/builds/nix-9113-1245729578/TestClientFallsBackToClosures3067346809/001/store/2yk72g923m9r7vbv7ijwqqzb9lzw9gnc-shared-dep2335 CA: text:sha256:13gwrkgdfsa3092281f38ami0mcl6fgacdyxd9qm8q5b2x2nzzxk2336 client_pushes_test.go:112: Retrieved narinfo from S3:2337 StorePath: /nix/var/nix/builds/nix-9113-1245729578/TestClientFallsBackToClosures3067346809/001/store/5qxaj4frmrmrkxs7ck6ks4bbw566hhrd-b2338 URL: nar/0nwyh5q1ynwp1j5xxgwz1p05wyn1vkvjzv6s5b4isda5bzlfi425.nar.zst2339 Compression: zstd2340 NarHash: sha256:0nwyh5q1ynwp1j5xxgwz1p05wyn1vkvjzv6s5b4isda5bzlfi4252341 NarSize: 2482342 References: /nix/var/nix/builds/nix-9113-1245729578/TestClientFallsBackToClosures3067346809/001/store/2yk72g923m9r7vbv7ijwqqzb9lzw9gnc-shared-dep2343 CA: text:sha256:13gwrkgdfsa3092281f38ami0mcl6fgacdyxd9qm8q5b2x2nzzxk2344--- PASS: TestClientFallsBackToClosures (1.63s)2345=== CONT TestResolveDBConnectionString/flag_wins2346=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2347=== CONT TestResolveDBConnectionString/nothing_configured2348=== CONT TestResolveDBConnectionString/missing_file_is_an_error2349=== CONT TestResolveDBConnectionString/file_when_flag_empty2350=== CONT TestCacheConfigHandler/full_config,_no_issuer2351=== CONT TestCacheConfigHandler/no_signing_keys2352=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2353=== CONT TestCacheConfigHandler/no_cache_url_configured2354--- PASS: TestCacheConfigHandler (0.00s)2355 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2356 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2357 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2358 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2359=== CONT TestIsValidUploadKey/narinfo2360=== CONT TestIsValidUploadKey/realisation_plus_in_output2361=== CONT TestIsValidUploadKey/unknown_type2362=== CONT TestIsValidUploadKey/empty_key2363=== CONT TestIsValidUploadKey/absolute2364=== CONT TestIsValidUploadKey/traversal_nar2365=== CONT TestIsValidUploadKey/traversal2366=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2367=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2368=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2369=== CONT TestIsValidUploadKey/index.html2370=== CONT TestIsValidUploadKey/nix-cache-info2371=== CONT TestIsValidUploadKey/build_log_home-manager_file2372=== CONT TestIsValidUploadKey/realisation2373=== CONT TestIsValidUploadKey/build_log_equals2374=== CONT TestIsValidUploadKey/build_log_question_mark2375=== CONT TestIsValidUploadKey/build_log_plus_in_name2376=== CONT TestIsValidUploadKey/nar_xz2377=== CONT TestIsValidUploadKey/build_log2378=== CONT TestIsValidUploadKey/nar_zst2379=== CONT TestIsValidUploadKey/listing2380=== CONT TestIsValidUploadKey/nar_plain2381--- PASS: TestIsValidUploadKey (0.00s)2382 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2383 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2384 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2385 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2386 --- PASS: TestIsValidUploadKey/absolute (0.00s)2387 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2388 --- PASS: TestIsValidUploadKey/traversal (0.00s)2389 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2390 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2391 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2392 --- PASS: TestIsValidUploadKey/index.html (0.00s)2393 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2394 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2395 --- PASS: TestIsValidUploadKey/realisation (0.00s)2396 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2397 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2398 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2399 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2400 --- PASS: TestIsValidUploadKey/build_log (0.00s)2401 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2402 --- PASS: TestIsValidUploadKey/listing (0.00s)2403 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2404=== CONT TestProxyWriteTimeout/narinfo2405=== CONT TestProxyWriteTimeout/10_GiB_nar2406=== CONT TestProxyWriteTimeout/unknown_size2407=== CONT TestProxyWriteTimeout/1_GiB_nar2408--- PASS: TestProxyWriteTimeout (0.00s)2409 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2410 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2411 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2412 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2413--- PASS: TestResolveDBConnectionString (0.01s)2414 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2415 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2416 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2417 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2418 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)24192026/09/29 08:16:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2420--- PASS: TestService_ReadScope_PublicByDefault (1.14s)24212026-09-29 08:16:45.487 UTC [9618] ERROR: relation "goose_db_version" does not exist at character 3624222026-09-29 08:16:45.487 UTC [9618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24232026-09-29 08:16:45.488 UTC [9619] ERROR: relation "goose_db_version" does not exist at character 3624242026-09-29 08:16:45.488 UTC [9619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24252026-09-29 08:16:45.489 UTC [9620] ERROR: relation "goose_db_version" does not exist at character 3624262026-09-29 08:16:45.489 UTC [9620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24272026/09/29 08:16:45 OK 20241026095416_initial_model.sql (8.9ms)24282026/09/29 08:16:45 OK 20241026095416_initial_model.sql (10.14ms)24292026/09/29 08:16:45 OK 20251210153512_drop_unused_gin_index.sql (404.29µs)24302026/09/29 08:16:45 OK 20251210153512_drop_unused_gin_index.sql (719.88µs)24312026/09/29 08:16:45 OK 20251218171726_add_pins.sql (1.09ms)24322026/09/29 08:16:45 OK 20251218171726_add_pins.sql (8.83ms)24332026-09-29 08:16:45.513 UTC [9621] ERROR: relation "goose_db_version" does not exist at character 3624342026-09-29 08:16:45.513 UTC [9621] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24352026/09/29 08:16:45 OK 20241026095416_initial_model.sql (19.38ms)24362026/09/29 08:16:45 OK 20251210153512_drop_unused_gin_index.sql (330.79µs)24372026/09/29 08:16:45 OK 20251218171726_add_pins.sql (679.13µs)24382026/09/29 08:16:45 OK 20260628120000_add_object_size_and_stats.sql (23.61ms)24392026/09/29 08:16:45 OK 20260628120000_add_object_size_and_stats.sql (7.58ms)24402026/09/29 08:16:45 OK 20260628120000_add_object_size_and_stats.sql (15.99ms)24412026/09/29 08:16:45 OK 20260905000000_add_claims.sql (1.38ms)24422026/09/29 08:16:45 OK 20260905000000_add_claims.sql (1.7ms)24432026/09/29 08:16:45 OK 20260905000000_add_claims.sql (1.24ms)24442026/09/29 08:16:45 OK 20260920000000_drop_claims.sql (912.17µs)24452026/09/29 08:16:45 OK 20260920000000_drop_claims.sql (848.42µs)24462026/09/29 08:16:45 OK 20260923120000_add_pushes.sql (710.08µs)24472026/09/29 08:16:45 goose: successfully migrated database to version: 2026092312000024482026/09/29 08:16:45 OK 20260920000000_drop_claims.sql (1.08ms)24492026/09/29 08:16:45 OK 20260923120000_add_pushes.sql (649.54µs)24502026/09/29 08:16:45 goose: successfully migrated database to version: 2026092312000024512026/09/29 08:16:45 OK 20260923120000_add_pushes.sql (784.42µs)24522026/09/29 08:16:45 goose: successfully migrated database to version: 2026092312000024532026/09/29 08:16:45 OK 1_commit_pending_closure.sql (935.38µs)24542026/09/29 08:16:45 OK 1_commit_pending_closure.sql (923.5µs)24552026/09/29 08:16:45 OK 2_object_stats_trigger.sql (229.96µs)24562026/09/29 08:16:45 OK 2_object_stats_trigger.sql (196.46µs)24572026/09/29 08:16:45 OK 3_commit_push.sql (308.75µs)24582026/09/29 08:16:45 goose: up to current file version: 324592026/09/29 08:16:45 OK 3_commit_push.sql (303.17µs)24602026/09/29 08:16:45 goose: up to current file version: 324612026/09/29 08:16:45 OK 1_commit_pending_closure.sql (989.96µs)24622026/09/29 08:16:45 OK 2_object_stats_trigger.sql (203.88µs)24632026/09/29 08:16:45 OK 3_commit_push.sql (164.29µs)24642026/09/29 08:16:45 goose: up to current file version: 324652026/09/29 08:16:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.82017ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24662026/09/29 08:16:45 OK 20241026095416_initial_model.sql (38.09ms)24672026/09/29 08:16:45 OK 20251210153512_drop_unused_gin_index.sql (1.19ms)24682026/09/29 08:16:45 OK 20251218171726_add_pins.sql (16.55ms)24692026/09/29 08:16:45 OK 20260628120000_add_object_size_and_stats.sql (6.41ms)24702026/09/29 08:16:45 OK 20260905000000_add_claims.sql (9.96ms)24712026/09/29 08:16:45 OK 20260920000000_drop_claims.sql (5.88ms)24722026/09/29 08:16:45 OK 20260923120000_add_pushes.sql (815.54µs)24732026/09/29 08:16:45 goose: successfully migrated database to version: 2026092312000024742026/09/29 08:16:45 OK 1_commit_pending_closure.sql (1.02ms)24752026/09/29 08:16:45 OK 2_object_stats_trigger.sql (240.58µs)24762026/09/29 08:16:45 OK 3_commit_push.sql (224.67µs)24772026/09/29 08:16:45 goose: up to current file version: 324782026/09/29 08:16:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02479=== NAME TestPinProtectsFromGC2480 client_integration_test.go:794: Pin successfully protected closure from garbage collection2481--- PASS: TestPinProtectsFromGC (5.41s)2482=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2483=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2484=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2485=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2486=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2487=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2488=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2489=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2490=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2491=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2492=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected24932026/09/29 08:16:45 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]2494=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured24952026/09/29 08:16:45 WARN Authentication failed token_preview=eyJhbGciOi...3VldpTn3mw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2496--- PASS: TestService_AuthMiddleware_OIDC (1.07s)2497 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2498 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2499 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2500 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)25012026/09/29 08:16:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=401.516931ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2502=== RUN TestService_RequireScope_OIDC/builder_may_write2503=== PAUSE TestService_RequireScope_OIDC/builder_may_write2504=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2505=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2506=== RUN TestService_RequireScope_OIDC/ops_may_admin2507=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2508=== RUN TestService_RequireScope_OIDC/ops_may_not_write2509=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2510=== RUN TestService_RequireScope_OIDC/reader_may_not_write2511=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2512=== RUN TestService_RequireScope_OIDC/static_token_may_admin2513=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2514=== RUN TestService_RequireScope_OIDC/static_token_may_write2515=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2516=== RUN TestService_RequireScope_OIDC/reader_may_read2517=== PAUSE TestService_RequireScope_OIDC/reader_may_read2518=== RUN TestService_RequireScope_OIDC/writer_implies_read2519=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2520=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2521=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2522=== CONT TestService_RequireScope_OIDC/builder_may_write2523=== CONT TestService_RequireScope_OIDC/static_token_may_admin2524=== CONT TestService_RequireScope_OIDC/writer_implies_read2525=== CONT TestService_RequireScope_OIDC/ops_may_not_write2526=== CONT TestService_RequireScope_OIDC/reader_may_read2527=== CONT TestService_RequireScope_OIDC/ops_may_admin2528=== CONT TestService_RequireScope_OIDC/reader_may_not_write2529=== CONT TestService_RequireScope_OIDC/static_token_may_write2530=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2531=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2532--- PASS: TestService_RequireScope_OIDC (1.23s)2533 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2534 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2535 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2536 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2537 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2538 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2539 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2540 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2541 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2542 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2543--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.49s)25442026-09-29 08:16:46.041 UTC [9622] ERROR: relation "goose_db_version" does not exist at character 3625452026-09-29 08:16:46.041 UTC [9622] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25462026-09-29 08:16:46.052 UTC [9623] ERROR: relation "goose_db_version" does not exist at character 3625472026-09-29 08:16:46.052 UTC [9623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2548--- PASS: TestService_ReadAuthMiddleware (1.31s)25492026/09/29 08:16:46 OK 20241026095416_initial_model.sql (71.8ms)25502026/09/29 08:16:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=831.273088ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25512026/09/29 08:16:46 OK 20251210153512_drop_unused_gin_index.sql (6.91ms)25522026/09/29 08:16:46 OK 20241026095416_initial_model.sql (72.19ms)25532026/09/29 08:16:46 OK 20251210153512_drop_unused_gin_index.sql (8.12ms)25542026/09/29 08:16:46 OK 20251218171726_add_pins.sql (16.15ms)25552026/09/29 08:16:46 OK 20251218171726_add_pins.sql (8.01ms)25562026/09/29 08:16:46 OK 20260628120000_add_object_size_and_stats.sql (7.7ms)25572026/09/29 08:16:46 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)25582026/09/29 08:16:46 OK 20260905000000_add_claims.sql (5.1ms)25592026/09/29 08:16:46 OK 20260920000000_drop_claims.sql (2.43ms)25602026/09/29 08:16:46 OK 20260905000000_add_claims.sql (3.98ms)25612026/09/29 08:16:46 OK 20260923120000_add_pushes.sql (1.65ms)25622026/09/29 08:16:46 goose: successfully migrated database to version: 2026092312000025632026/09/29 08:16:46 OK 20260920000000_drop_claims.sql (2.04ms)25642026/09/29 08:16:46 OK 20260923120000_add_pushes.sql (1.42ms)25652026/09/29 08:16:46 goose: successfully migrated database to version: 2026092312000025662026/09/29 08:16:46 OK 1_commit_pending_closure.sql (2.87ms)25672026/09/29 08:16:46 OK 2_object_stats_trigger.sql (584.96µs)25682026/09/29 08:16:46 OK 3_commit_push.sql (510.67µs)25692026/09/29 08:16:46 goose: up to current file version: 325702026/09/29 08:16:46 OK 1_commit_pending_closure.sql (2.31ms)25712026/09/29 08:16:46 OK 2_object_stats_trigger.sql (601.83µs)25722026/09/29 08:16:46 OK 3_commit_push.sql (526.21µs)25732026/09/29 08:16:46 goose: up to current file version: 325742026/09/29 08:16:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25752026/09/29 08:16:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25762026/09/29 08:16:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.742912915s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25772026/09/29 08:16:48 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25782026/09/29 08:16:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.302394ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25792026/09/29 08:16:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=418.692439ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25802026/09/29 08:16:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=727.452028ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25812026/09/29 08:16:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.706838918s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25822026/09/29 08:16:51 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 127.0.0.1:19999: connect: connection refused"25832026/09/29 08:16:51 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25842026/09/29 08:16:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.785549ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25852026/09/29 08:16:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.172478ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25862026/09/29 08:16:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=812.932163ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25872026/09/29 08:16:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.472068721s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25882026/09/29 08:16:54 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25892026/09/29 08:16:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.424978ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25902026/09/29 08:16:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=419.12773ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25912026/09/29 08:16:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=745.52895ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25922026/09/29 08:16:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.482625175s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2593--- PASS: TestClientErrorHandling (0.00s)2594 --- PASS: TestClientErrorHandling/InvalidStorePath (1.14s)2595 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.27s)2596 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.69s)2597PASS2598{"timestamp":"2026-09-29T08:16:57.922103Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56315","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}25992026-09-29 08:16:58.022 UTC [9169] LOG: received smart shutdown request26002026-09-29 08:16:58.023 UTC [9169] LOG: background worker "logical replication launcher" (PID 9179) exited with exit code 126012026-09-29 08:16:58.030 UTC [9174] LOG: shutting down26022026-09-29 08:16:58.030 UTC [9174] LOG: checkpoint starting: shutdown immediate26032026-09-29 08:16:59.161 UTC [9174] LOG: checkpoint complete: wrote 12645 buffers (77.2%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.730 s, sync=0.369 s, total=1.132 s; sync files=21874, longest=0.001 s, average=0.001 s; distance=302636 kB, estimate=302636 kB; lsn=0/13F181C8, redo lsn=0/13F181C826042026-09-29 08:16:59.166 UTC [9169] LOG: database system is shut down2605Running OIDC tests...2606=== RUN TestAudienceForIssuer2607=== PAUSE TestAudienceForIssuer2608=== RUN TestGlobMatch2609=== PAUSE TestGlobMatch2610=== RUN TestValidateToken_ValidToken2611=== PAUSE TestValidateToken_ValidToken2612=== RUN TestValidateToken_WrongAudience2613=== PAUSE TestValidateToken_WrongAudience2614=== RUN TestValidateToken_Expired2615=== PAUSE TestValidateToken_Expired2616=== RUN TestValidateToken_BoundClaimsMismatch2617=== PAUSE TestValidateToken_BoundClaimsMismatch2618=== RUN TestValidateToken_BoundSubjectMismatch2619=== PAUSE TestValidateToken_BoundSubjectMismatch2620=== RUN TestValidateToken_MultipleProviders2621=== PAUSE TestValidateToken_MultipleProviders2622=== RUN TestValidateToken_NoMatchingProvider2623=== PAUSE TestValidateToken_NoMatchingProvider2624=== RUN TestValidateToken_KubernetesServiceAccount2625=== PAUSE TestValidateToken_KubernetesServiceAccount2626=== RUN TestNewValidator_KubernetesRequiresCA2627=== PAUSE TestNewValidator_KubernetesRequiresCA2628=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2629=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2630=== RUN TestPins_ReservedForMatchingRule2631=== PAUSE TestPins_ReservedForMatchingRule2632=== RUN TestPins_TopLevelShorthand2633=== PAUSE TestPins_TopLevelShorthand2634=== RUN TestPins_ConfigValidation2635=== PAUSE TestPins_ConfigValidation2636=== RUN TestScopes_LegacyProviderDefaultsToWrite2637=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2638=== RUN TestScopes_Rules2639=== PAUSE TestScopes_Rules2640=== RUN TestScopes_ConfigValidation2641=== PAUSE TestScopes_ConfigValidation2642=== CONT TestAudienceForIssuer2643--- PASS: TestAudienceForIssuer (0.00s)2644=== CONT TestValidateToken_NoMatchingProvider2645=== CONT TestValidateToken_KubernetesServiceAccount2646=== CONT TestPins_ConfigValidation2647=== CONT TestValidateToken_Expired2648=== CONT TestScopes_LegacyProviderDefaultsToWrite2649=== CONT TestScopes_Rules2650=== CONT TestScopes_ConfigValidation2651--- PASS: TestScopes_ConfigValidation (0.00s)2652=== CONT TestPins_ReservedForMatchingRule2653=== CONT TestPins_TopLevelShorthand2654=== CONT TestValidateToken_ValidToken2655=== CONT TestValidateToken_WrongAudience2656--- PASS: TestPins_ConfigValidation (0.01s)2657=== CONT TestValidateToken_BoundSubjectMismatch26582026/09/29 08:17:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56475/oidc2659--- PASS: TestScopes_Rules (0.05s)2660=== CONT TestGlobMatch2661=== RUN TestGlobMatch/foo_foo2662=== PAUSE TestGlobMatch/foo_foo2663=== RUN TestGlobMatch/foo_bar2664=== PAUSE TestGlobMatch/foo_bar2665=== RUN TestGlobMatch/*_2666=== PAUSE TestGlobMatch/*_2667=== RUN TestGlobMatch/*_anything2668=== PAUSE TestGlobMatch/*_anything2669=== RUN TestGlobMatch/foo*_foo2670=== PAUSE TestGlobMatch/foo*_foo2671=== RUN TestGlobMatch/foo*_foobar2672=== PAUSE TestGlobMatch/foo*_foobar2673=== RUN TestGlobMatch/foo*_bar2674=== PAUSE TestGlobMatch/foo*_bar2675=== RUN TestGlobMatch/*bar_bar2676=== PAUSE TestGlobMatch/*bar_bar2677=== RUN TestGlobMatch/*bar_foobar2678=== PAUSE TestGlobMatch/*bar_foobar2679=== RUN TestGlobMatch/*bar_foo2680=== PAUSE TestGlobMatch/*bar_foo2681=== RUN TestGlobMatch/foo*bar_foobar2682=== PAUSE TestGlobMatch/foo*bar_foobar2683=== RUN TestGlobMatch/foo*bar_foo123bar2684=== PAUSE TestGlobMatch/foo*bar_foo123bar2685=== RUN TestGlobMatch/foo*bar_foobarbaz2686=== PAUSE TestGlobMatch/foo*bar_foobarbaz2687=== RUN TestGlobMatch/*/*_foo/bar2688=== PAUSE TestGlobMatch/*/*_foo/bar2689=== RUN TestGlobMatch/*/*_foo2690=== PAUSE TestGlobMatch/*/*_foo2691=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2692=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2693=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02694=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02695=== RUN TestGlobMatch/refs/*/main_refs/heads/main2696=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2697=== RUN TestGlobMatch/fo?_foo2698=== PAUSE TestGlobMatch/fo?_foo2699=== RUN TestGlobMatch/fo?_fo2700=== PAUSE TestGlobMatch/fo?_fo2701=== RUN TestGlobMatch/fo?_fooo2702=== PAUSE TestGlobMatch/fo?_fooo2703=== RUN TestGlobMatch/?oo_foo2704=== PAUSE TestGlobMatch/?oo_foo2705=== RUN TestGlobMatch/?oo_boo2706=== PAUSE TestGlobMatch/?oo_boo2707=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2708=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2709=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2710=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2711=== CONT TestValidateToken_BoundClaimsMismatch27122026/09/29 08:17:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56478/oidc2713--- PASS: TestPins_TopLevelShorthand (0.07s)2714=== CONT TestValidateToken_KubernetesIssuerFromOwnToken27152026/09/29 08:17:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56480/oidc2716--- PASS: TestValidateToken_Expired (0.08s)2717=== CONT TestNewValidator_KubernetesRequiresCA27182026/09/29 08:17:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56482/oidc27192026/09/29 08:17:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56484/oidc2720--- PASS: TestPins_ReservedForMatchingRule (0.08s)2721=== CONT TestValidateToken_MultipleProviders27222026/09/29 08:17:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:56477/oidc2723--- PASS: TestValidateToken_ValidToken (0.08s)2724=== CONT TestGlobMatch/foo_foo2725=== CONT TestGlobMatch/*/*_foo/bar2726=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2727=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2728=== CONT TestGlobMatch/?oo_boo2729=== CONT TestGlobMatch/?oo_foo2730=== CONT TestGlobMatch/fo?_fooo2731=== CONT TestGlobMatch/fo?_fo2732=== CONT TestGlobMatch/fo?_foo2733=== CONT TestGlobMatch/refs/*/main_refs/heads/main2734=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02735=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2736=== CONT TestGlobMatch/*/*_foo2737=== CONT TestGlobMatch/foo*bar_foobarbaz2738=== CONT TestGlobMatch/foo*bar_foo123bar2739=== CONT TestGlobMatch/foo*bar_foobar2740=== CONT TestGlobMatch/*bar_foo2741=== CONT TestGlobMatch/*bar_foobar2742=== CONT TestGlobMatch/*bar_bar2743=== CONT TestGlobMatch/foo*_bar2744=== CONT TestGlobMatch/foo*_foobar2745=== CONT TestGlobMatch/foo*_foo2746=== CONT TestGlobMatch/*_anything2747=== CONT TestGlobMatch/*_2748=== CONT TestGlobMatch/foo_bar2749--- PASS: TestGlobMatch (0.00s)2750 --- PASS: TestGlobMatch/foo_foo (0.00s)2751 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2752 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2753 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2754 --- PASS: TestGlobMatch/?oo_boo (0.00s)2755 --- PASS: TestGlobMatch/?oo_foo (0.00s)2756 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2757 --- PASS: TestGlobMatch/fo?_fo (0.00s)2758 --- PASS: TestGlobMatch/fo?_foo (0.00s)2759 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2760 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2761 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2762 --- PASS: TestGlobMatch/*/*_foo (0.00s)2763 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2764 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2765 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2766 --- PASS: TestGlobMatch/*bar_foo (0.00s)2767 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2768 --- PASS: TestGlobMatch/*bar_bar (0.00s)2769 --- PASS: TestGlobMatch/foo*_bar (0.00s)2770 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2771 --- PASS: TestGlobMatch/foo*_foo (0.00s)2772 --- PASS: TestGlobMatch/*_anything (0.00s)2773 --- PASS: TestGlobMatch/*_ (0.00s)2774 --- PASS: TestGlobMatch/foo_bar (0.00s)2775--- PASS: TestValidateToken_NoMatchingProvider (0.09s)27762026/09/29 08:17:00 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:564882777--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)27782026/09/29 08:17:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56490/oidc2779--- PASS: TestValidateToken_WrongAudience (0.10s)27802026/09/29 08:17:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56492/oidc2781--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)27822026/09/29 08:17:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56496/oidc27832026/09/29 08:17:00 http: TLS handshake error from 127.0.0.1:56495: remote error: tls: bad certificate2784--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)2785--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)27862026/09/29 08:17:00 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232787--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)27882026/09/29 08:17:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56501/oidc2789--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.14s)27902026/09/29 08:17:00 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:56503/oidc27912026/09/29 08:17:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:56500/oidc2792--- PASS: TestValidateToken_MultipleProviders (0.07s)2793PASS2794Running hook tests...2795=== RUN TestSendPathsEmpty2796=== PAUSE TestSendPathsEmpty2797=== RUN TestQueueEnqueueAndFetch2798=== PAUSE TestQueueEnqueueAndFetch2799=== RUN TestQueueDeduplication2800=== PAUSE TestQueueDeduplication2801=== RUN TestQueueRemove2802=== PAUSE TestQueueRemove2803=== RUN TestQueueFetchBatchLimit2804=== PAUSE TestQueueFetchBatchLimit2805=== RUN TestQueueRetryMovesToBack2806=== PAUSE TestQueueRetryMovesToBack2807=== RUN TestQueueFetchRemoveLifecycle2808=== PAUSE TestQueueFetchRemoveLifecycle2809=== RUN TestQueueConcurrentWriters2810=== PAUSE TestQueueConcurrentWriters2811=== RUN TestQueueRemoveLargeClosure2812=== PAUSE TestQueueRemoveLargeClosure2813=== RUN TestServerClientIntegration2814=== PAUSE TestServerClientIntegration2815=== RUN TestServerQueueError2816=== PAUSE TestServerQueueError2817=== RUN TestGetListenerSocketActivation2818 server_test.go:210: === RUN TestGetListenerSocketActivation2819 --- PASS: TestGetListenerSocketActivation (0.00s)2820 PASS2821 2822--- PASS: TestGetListenerSocketActivation (0.01s)2823=== RUN TestDrainIsolatesPoisonPath2824=== PAUSE TestDrainIsolatesPoisonPath2825=== RUN TestRunNotBlockedByPoisonHead2826=== PAUSE TestRunNotBlockedByPoisonHead2827=== RUN TestDrainGivesUpWhenServerDown2828=== PAUSE TestDrainGivesUpWhenServerDown2829=== RUN TestFailedPathPrunedByLaterClosure2830=== PAUSE TestFailedPathPrunedByLaterClosure2831=== RUN TestWorkerUploadsAndRemoves2832=== PAUSE TestWorkerUploadsAndRemoves2833=== RUN TestWorkerSkipsGCdPaths2834=== PAUSE TestWorkerSkipsGCdPaths2835=== RUN TestWorkerPrunesClosureDeps2836=== PAUSE TestWorkerPrunesClosureDeps2837=== RUN TestDrainTimeout2838=== PAUSE TestDrainTimeout2839=== CONT TestSendPathsEmpty2840=== CONT TestServerQueueError2841--- PASS: TestSendPathsEmpty (0.00s)2842=== CONT TestServerClientIntegration2843=== CONT TestWorkerUploadsAndRemoves2844=== CONT TestDrainGivesUpWhenServerDown2845=== CONT TestWorkerPrunesClosureDeps2846=== CONT TestDrainIsolatesPoisonPath2847=== CONT TestFailedPathPrunedByLaterClosure2848=== CONT TestWorkerSkipsGCdPaths2849=== CONT TestRunNotBlockedByPoisonHead2850=== CONT TestQueueDeduplication28512026/09/29 08:17:00 ERROR Failed to queue paths error="permission denied" count=12852--- PASS: TestServerClientIntegration (0.00s)2853=== CONT TestQueueRemoveLargeClosure2854--- PASS: TestServerQueueError (0.00s)2855=== CONT TestQueueConcurrentWriters28562026/09/29 08:17:00 INFO Upload queue status pending=228572026/09/29 08:17:00 INFO Upload queue status pending=228582026/09/29 08:17:00 INFO Uploading batch count=128592026/09/29 08:17:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-9113-1245729578/TestWorkerSkipsGCdPaths3660495739/002/nonexistent2860--- PASS: TestQueueDeduplication (0.01s)2861=== CONT TestQueueFetchRemoveLifecycle28622026/09/29 08:17:00 INFO Upload queue status pending=328632026/09/29 08:17:00 INFO Uploading batch count=128642026/09/29 08:17:00 ERROR Upload failed error="upload failed" count=128652026/09/29 08:17:00 INFO Uploading batch count=128662026/09/29 08:17:00 ERROR Upload failed error="upload failed" count=128672026/09/29 08:17:00 INFO Uploading batch count=128682026/09/29 08:17:00 INFO Upload queue status pending=228692026/09/29 08:17:00 INFO Uploading batch count=228702026/09/29 08:17:00 INFO Uploading batch count=128712026/09/29 08:17:00 INFO Uploading batch count=428722026/09/29 08:17:00 ERROR Upload failed error="upload failed" count=428732026/09/29 08:17:00 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9113-1245729578/TestDrainIsolatesPoisonPath3177365318/002/bbb28742026/09/29 08:17:00 INFO Uploading batch count=128752026/09/29 08:17:00 INFO Uploading batch count=228762026/09/29 08:17:00 ERROR Upload failed error="upload failed" count=228772026/09/29 08:17:00 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9113-1245729578/TestDrainGivesUpWhenServerDown1143162254/002/a28782026/09/29 08:17:00 INFO Uploading batch count=128792026/09/29 08:17:00 ERROR Upload failed error="upload failed" count=128802026/09/29 08:17:00 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9113-1245729578/TestDrainGivesUpWhenServerDown1143162254/002/b28812026/09/29 08:17:00 INFO Uploading batch count=128822026/09/29 08:17:00 ERROR Upload failed error="upload failed" count=128832026/09/29 08:17:00 INFO Uploading batch count=228842026/09/29 08:17:00 ERROR Upload failed error="upload failed" count=228852026/09/29 08:17:00 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9113-1245729578/TestDrainGivesUpWhenServerDown1143162254/002/c28862026/09/29 08:17:00 INFO Uploading batch count=128872026/09/29 08:17:00 ERROR Upload failed error="upload failed" count=12888--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2889=== CONT TestQueueRetryMovesToBack28902026/09/29 08:17:00 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9113-1245729578/TestDrainGivesUpWhenServerDown1143162254/002/d28912026/09/29 08:17:00 ERROR Drain finished with paths left in queue remaining=128922026/09/29 08:17:00 INFO Uploading batch count=228932026/09/29 08:17:00 ERROR Upload failed error="upload failed" count=228942026/09/29 08:17:00 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9113-1245729578/TestDrainGivesUpWhenServerDown1143162254/002/e28952026/09/29 08:17:00 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-9113-1245729578/TestDrainGivesUpWhenServerDown1143162254/002/f28962026/09/29 08:17:00 ERROR Drain finished with paths left in queue remaining=102897--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2898=== CONT TestQueueFetchBatchLimit2899--- PASS: TestDrainIsolatesPoisonPath (0.01s)2900=== CONT TestQueueRemove2901--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2902=== CONT TestQueueEnqueueAndFetch2903--- PASS: TestQueueRetryMovesToBack (0.00s)2904=== CONT TestDrainTimeout2905--- PASS: TestQueueFetchBatchLimit (0.00s)2906--- PASS: TestQueueRemove (0.00s)29072026/09/29 08:17:00 INFO Uploading batch count=22908--- PASS: TestQueueEnqueueAndFetch (0.00s)2909--- PASS: TestWorkerSkipsGCdPaths (0.03s)2910--- PASS: TestWorkerPrunesClosureDeps (0.03s)2911--- PASS: TestWorkerUploadsAndRemoves (0.03s)2912--- PASS: TestQueueRemoveLargeClosure (0.05s)2913--- PASS: TestQueueConcurrentWriters (0.15s)29142026/09/29 08:17:00 ERROR Upload failed error="context deadline exceeded" count=229152026/09/29 08:17:00 ERROR Drain finished with paths left in queue remaining=42916--- PASS: TestDrainTimeout (0.21s)29172026/09/29 08:17:01 INFO Uploading batch count=129182026/09/29 08:17:01 INFO Uploading batch count=129192026/09/29 08:17:01 INFO Uploading batch count=129202026/09/29 08:17:01 ERROR Upload failed error="upload failed" count=129212026/09/29 08:17:01 INFO Uploading batch count=129222026/09/29 08:17:01 ERROR Upload failed error="upload failed" count=129232026/09/29 08:17:01 INFO Uploading batch count=129242026/09/29 08:17:01 ERROR Upload failed error="upload failed" count=129252026/09/29 08:17:01 INFO Uploading batch count=129262026/09/29 08:17:01 ERROR Upload failed error="upload failed" count=129272026/09/29 08:17:01 ERROR Drain finished with paths left in queue remaining=12928--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2929PASS