niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #269
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenScriptFails97=== CONT TestScriptTokenBadJSON98=== CONT TestScriptTokenEmptyCommand99--- PASS: TestScriptTokenEmptyCommand (0.00s)100=== CONT TestSetClientTLSDoesNotMutateDefaultTransport101=== CONT TestEncodeNixBase32WithRealHash102--- PASS: TestEncodeNixBase32WithRealHash (0.00s)103=== CONT TestSetClientTLS104=== CONT TestResolveStorePath105=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess106--- PASS: TestScriptTokenScriptFails (0.00s)1072026/09/23 13:29:34 WARN Rate limiter enabled after throttle name=server-test rate=5108=== CONT TestDoWithRetry_BodyReplayedViaGetBody109=== CONT TestRateLimiterFeedback110=== CONT TestPathInfoCACompatibility111=== CONT TestScriptTokenEmptyToken112=== CONT TestScriptTokenCachesUntilRefresh113=== CONT TestParsePathInfoJSONMultiplePaths114=== CONT TestScriptTokenNoExpiryRerunsEveryCall115=== CONT TestParsePathInfoJSON116=== CONT TestFileTokenEmpty117=== CONT TestPathInfoHashCompatibility118=== CONT TestFileTokenMissing119=== CONT TestGetStorePathHash120=== CONT TestFileTokenReadsAndCaches121=== CONT TestConvertHashToNix32122=== CONT TestStaticToken123=== CONT TestSetClientTLSErrors124=== CONT TestDumpPathWriterError125=== RUN TestRateLimiterFeedback/429_enables_limiter126--- PASS: TestStaticToken (0.00s)127=== RUN TestPathInfoCACompatibility/null_ca_field128=== PAUSE TestPathInfoCACompatibility/null_ca_field129=== RUN TestPathInfoCACompatibility/old_string_format_-_text130=== PAUSE TestRateLimiterFeedback/429_enables_limiter131=== RUN TestRateLimiterFeedback/503_enables_limiter132--- PASS: TestResolveStorePath (0.00s)133=== RUN TestConvertHashToNix32/SRI_format_to_Nix32134=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)135=== RUN TestGetStorePathHash/valid_store_path136=== CONT TestStreamPushReportsSignatures137=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text138=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix321392026/09/23 13:29:34 WARN Rate limiter enabled after throttle name=server-test rate=5140=== RUN TestParsePathInfoJSON/Nix_format1412026/09/23 13:29:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34357142=== CONT TestClientSignaturesByStorePath143=== CONT TestEncodeNixBase32144=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1452026/09/23 13:29:34 ERROR Upload failed error=boom count=1146=== PAUSE TestRateLimiterFeedback/503_enables_limiter147=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter148=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths149=== CONT TestStreamPushBatchesUnderLoad1502026/09/23 13:29:34 WARN Rate limiter backed off name=server-test rate=5151=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter1522026/09/23 13:29:34 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34357153=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths154=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths155--- PASS: TestFileTokenEmpty (0.00s)156--- PASS: TestFileTokenMissing (0.00s)157=== CONT TestStreamPushRequestLine158=== CONT TestShellSplitErrors159=== CONT TestCaseHackSuffix160=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)161=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive162=== CONT TestShellSplit163=== CONT TestFilterOversizedClosures1642026/09/23 13:29:34 ERROR Upload failed error=boom count=1165=== RUN TestFilterOversizedClosures/no_limit_keeps_everything166=== CONT TestDumpPathSingleFile167=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon168=== PAUSE TestParsePathInfoJSON/Nix_format169=== CONT TestStreamPushGivesUpOnDeadServer170=== RUN TestConvertHashToNix32/already_Nix32_format171=== CONT TestStreamPushIsolatesFailures172=== PAUSE TestConvertHashToNix32/already_Nix32_format173=== CONT TestPartSizeForNAR174=== RUN TestEncodeNixBase32/test_string_hash175=== RUN TestSetClientTLSErrors/missing_cert_file176=== CONT TestUploadMultipart_PartsInParallel177=== PAUSE TestGetStorePathHash/valid_store_path178=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter179=== CONT TestStreamPushReportsEveryPath180--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)181=== CONT TestRegisterUploadedObjectReusesConnections1822026/09/23 13:29:34 ERROR Upload failed error="connection refused" count=20183--- PASS: TestScriptTokenBadJSON (0.01s)184=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive185=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything186=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon187=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI188=== CONT TestUploadMultipart_SupersededByPeer189=== RUN TestUploadMultipart_SupersededByPeer/exists190=== PAUSE TestUploadMultipart_SupersededByPeer/exists191=== RUN TestUploadMultipart_SupersededByPeer/missing192=== PAUSE TestUploadMultipart_SupersededByPeer/missing193=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths194=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped195=== RUN TestConvertHashToNix32/invalid_format196=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI197=== RUN TestParsePathInfoJSON/Lix_format198=== PAUSE TestParsePathInfoJSON/Lix_format199=== RUN TestPathInfoCACompatibility/new_structured_format_-_text200=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text2012026/09/23 13:29:34 ERROR Server seems unavailable, giving up on batch untried=17202=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method203=== RUN TestSetClientTLS/rejects_connection_without_client_cert204=== RUN TestParsePathInfoJSON/empty_input205=== PAUSE TestParsePathInfoJSON/empty_input206=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method207=== PAUSE TestEncodeNixBase32/test_string_hash208=== PAUSE TestSetClientTLSErrors/missing_cert_file209=== RUN TestSetClientTLSErrors/missing_key_file210=== PAUSE TestSetClientTLSErrors/missing_key_file211=== RUN TestSetClientTLSErrors/missing_ca_file2122026/09/23 13:29:34 ERROR Upload failed error="bad path" count=3213=== PAUSE TestSetClientTLSErrors/missing_ca_file214=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths215=== CONT TestPathInfoCACompatibility/new_structured_format_-_text216=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method217--- PASS: TestClientSignaturesByStorePath (0.00s)218--- PASS: TestFileTokenReadsAndCaches (0.00s)219=== RUN TestGetStorePathHash/basename_without_hyphen_should_error220=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error221=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error222=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error223=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error224=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error225=== CONT TestGetStorePathHash/valid_store_path226=== CONT TestPathInfoCACompatibility/old_string_format_-_text227=== CONT TestDumpPathMatchesNix228=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error229=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error230=== CONT TestGetStorePathHash/basename_without_hyphen_should_error231=== PAUSE TestConvertHashToNix32/invalid_format232=== CONT TestConvertHashToNix32/SRI_format_to_Nix32233=== CONT TestConvertHashToNix32/invalid_format234=== RUN TestPartSizeForNAR/zero_stays_at_minimum235=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum236=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512237=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped238=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert239=== CONT TestConvertHashToNix32/already_Nix32_format240=== RUN TestParsePathInfoJSON/whitespace_only241=== PAUSE TestParsePathInfoJSON/whitespace_only242=== CONT TestPathInfoCACompatibility/null_ca_field243=== CONT TestUploadMultipart_SupersededByPeer/missing244=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive245=== RUN TestEncodeNixBase32/empty_input246=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter247=== CONT TestUploadMultipart_SupersededByPeer/exists248=== RUN TestSetClientTLSErrors/invalid_ca_file249--- PASS: TestStreamPushReportsSignatures (0.00s)250=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512251=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)252=== PAUSE TestSetClientTLSErrors/invalid_ca_file253=== RUN TestPartSizeForNAR/small_stays_at_minimum254=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512255=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI256=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter257=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter258=== PAUSE TestEncodeNixBase32/empty_input259=== RUN TestParsePathInfoJSON/invalid_JSON260--- PASS: TestDoServerRequestAttachesToken (0.01s)261=== CONT TestSetClientTLSErrors/missing_cert_file262=== CONT TestRateLimiterFeedback/503_enables_limiter263=== PAUSE TestPartSizeForNAR/small_stays_at_minimum264=== RUN TestFilterOversizedClosures/all_closures_skipped265=== CONT TestSetClientTLSErrors/invalid_ca_file266=== CONT TestSetClientTLSErrors/missing_ca_file267=== CONT TestSetClientTLSErrors/missing_key_file268=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA269=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon270--- PASS: TestShellSplitErrors (0.00s)271=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum272=== CONT TestRateLimiterFeedback/429_enables_limiter273=== CONT TestEncodeNixBase32/test_string_hash274=== CONT TestEncodeNixBase32/empty_input275=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum276=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts277=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts278=== RUN TestPartSizeForNAR/1_TiB279=== PAUSE TestPartSizeForNAR/1_TiB280=== RUN TestPartSizeForNAR/5_TiB_S3_max_object281=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object282=== RUN TestPartSizeForNAR/capped_at_5_GiB283=== PAUSE TestPartSizeForNAR/capped_at_5_GiB284=== CONT TestPartSizeForNAR/zero_stays_at_minimum285=== PAUSE TestParsePathInfoJSON/invalid_JSON286=== CONT TestParsePathInfoJSON/Nix_format2872026/09/23 13:29:34 WARN Rate limiter enabled after throttle name=server-test rate=52882026/09/23 13:29:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:39979289=== CONT TestPartSizeForNAR/capped_at_5_GiB290=== CONT TestPartSizeForNAR/5_TiB_S3_max_object291=== CONT TestPartSizeForNAR/1_TiB292--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)293--- PASS: TestShellSplit (0.00s)294=== PAUSE TestFilterOversizedClosures/all_closures_skipped295=== CONT TestFilterOversizedClosures/no_limit_keeps_everything296=== CONT TestParsePathInfoJSON/invalid_JSON297=== CONT TestParsePathInfoJSON/whitespace_only2982026/09/23 13:29:34 WARN Rate limiter backed off name=server-test rate=5299=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts300=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum301=== CONT TestPartSizeForNAR/small_stays_at_minimum302=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA303=== RUN TestSetClientTLS/preserves_debug_logging_transport304=== PAUSE TestSetClientTLS/preserves_debug_logging_transport305=== CONT TestSetClientTLS/rejects_connection_without_client_cert3062026/09/23 13:29:34 WARN Rate limiter enabled after throttle name=server-test rate=53072026/09/23 13:29:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:44049308=== CONT TestParsePathInfoJSON/empty_input309=== CONT TestParsePathInfoJSON/Lix_format310=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3112026/09/23 13:29:34 WARN Rate limiter backed off name=server-test rate=5312--- PASS: TestScriptTokenEmptyToken (0.01s)313--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)314--- PASS: TestStreamPushReportsEveryPath (0.00s)315=== CONT TestFilterOversizedClosures/all_closures_skipped3162026/09/23 13:29:34 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=50317=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3182026/09/23 13:29:34 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=2000319=== CONT TestSetClientTLS/preserves_debug_logging_transport320--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)321--- PASS: TestStreamPushGivesUpOnDeadServer (0.05s)322--- PASS: TestDumpPathSingleFile (0.05s)323--- PASS: TestStreamPushIsolatesFailures (0.05s)324--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)325 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)326 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)327--- PASS: TestGetStorePathHash (0.06s)328 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)329 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)330 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)331 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)332--- PASS: TestConvertHashToNix32 (0.06s)333 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)334 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)335 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)336--- PASS: TestPathInfoCACompatibility (0.06s)337 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)338 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)339 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)340 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)341 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)342--- PASS: TestEncodeNixBase32 (0.07s)343 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)344 --- PASS: TestEncodeNixBase32/empty_input (0.00s)345--- PASS: TestPathInfoHashCompatibility (0.06s)346 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)347 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)348 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.01s)349 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)350--- PASS: TestFilterOversizedClosures (0.06s)351 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)352 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)353 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)354--- PASS: TestPartSizeForNAR (0.06s)355 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)356 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)357 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)358 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)359 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)360 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)361 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)362--- PASS: TestParsePathInfoJSON (0.07s)363 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)364 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)365 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)366 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)367 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)368--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)369 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)370 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)371--- PASS: TestRateLimiterFeedback (0.06s)372 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)373 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)374 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)375 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)376--- PASS: TestSetClientTLSErrors (0.06s)377 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)378 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)380 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)381--- PASS: TestRegisterUploadedObjectReusesConnections (0.08s)382--- PASS: TestDumpPathWriterError (0.09s)383--- PASS: TestCaseHackSuffix (0.08s)3842026/09/23 13:29:34 http: TLS handshake error from 127.0.0.1:53022: remote error: tls: bad certificate385--- PASS: TestSetClientTLS (0.08s)386 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)387 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)388 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)389--- PASS: TestStreamPushRequestLine (0.10s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.10s)392--- PASS: TestUploadMultipart_PartsInParallel (0.67s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres1835535621/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres1835535621/data -l logfile start422423/build/postgres1835535621:5432 - no response4242026-09-23 13:29:35.867 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-09-23 13:29:35.868 UTC [128] LOG: listening on Unix socket "/build/postgres1835535621/.s.PGSQL.5432"4262026-09-23 13:29:35.872 UTC [135] LOG: database system was shut down at 2026-09-23 13:29:35 UTC4272026-09-23 13:29:35.876 UTC [128] LOG: database system is ready to accept connections428/build/postgres1835535621:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestResolveDBConnectionString466=== PAUSE TestResolveDBConnectionString467=== RUN TestLeadElectsOneAndHandsOver468=== PAUSE TestLeadElectsOneAndHandsOver469=== RUN TestLeadIncumbentWinsAfterRestart4702026-09-23 13:29:36.292 UTC [370] ERROR: relation "goose_db_version" does not exist at character 364712026-09-23 13:29:36.292 UTC [370] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4722026/09/23 13:29:36 OK 20241026095416_initial_model.sql (13.7ms)4732026/09/23 13:29:36 OK 20251210153512_drop_unused_gin_index.sql (2.42ms)4742026/09/23 13:29:36 OK 20251218171726_add_pins.sql (3.73ms)4752026/09/23 13:29:36 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)4762026/09/23 13:29:36 OK 20260905000000_add_claims.sql (3.87ms)4772026/09/23 13:29:36 OK 20260920000000_drop_claims.sql (2.21ms)4782026/09/23 13:29:36 OK 20260923120000_add_pushes.sql (1.67ms)4792026/09/23 13:29:36 goose: successfully migrated database to version: 202609231200004802026/09/23 13:29:36 OK 1_commit_pending_closure.sql (2.02ms)4812026/09/23 13:29:36 OK 2_object_stats_trigger.sql (948.27µs)4822026/09/23 13:29:36 OK 3_commit_push.sql (928.63µs)4832026/09/23 13:29:36 goose: up to current file version: 34842026/09/23 13:29:36 INFO lead: acquired remote=192.0.2.1:12344852026/09/23 13:29:36 INFO lead: released remote=192.0.2.1:12344862026/09/23 13:29:37 INFO lead: acquired remote=192.0.2.1:12344872026/09/23 13:29:37 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadIncumbentWinsAfterRestart (0.84s)489=== RUN TestLeadEndsOnShutdown490=== PAUSE TestLeadEndsOnShutdown491=== RUN TestGCAdvisoryLockBlocksConcurrentRun4922026-09-23 13:29:37.067 UTC [380] ERROR: relation "goose_db_version" does not exist at character 364932026-09-23 13:29:37.067 UTC [380] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4942026/09/23 13:29:37 OK 20241026095416_initial_model.sql (9.8ms)4952026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)4962026/09/23 13:29:37 OK 20251218171726_add_pins.sql (3.06ms)4972026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (2.87ms)4982026/09/23 13:29:37 OK 20260905000000_add_claims.sql (2.18ms)4992026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (1.33ms)5002026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (943.77µs)5012026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200005022026/09/23 13:29:37 OK 1_commit_pending_closure.sql (1.35ms)5032026/09/23 13:29:37 OK 2_object_stats_trigger.sql (679.03µs)5042026/09/23 13:29:37 OK 3_commit_push.sql (535.53µs)5052026/09/23 13:29:37 goose: up to current file version: 3506--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.11s)507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestGCTaskStore_StartNew512=== PAUSE TestGCTaskStore_StartNew513=== RUN TestGCTaskStore_DeduplicateSameParams514=== PAUSE TestGCTaskStore_DeduplicateSameParams515=== RUN TestGCTaskStore_ConflictDifferentParams516=== PAUSE TestGCTaskStore_ConflictDifferentParams517=== RUN TestGCTaskStore_GetEmpty518=== PAUSE TestGCTaskStore_GetEmpty519=== RUN TestGCTaskStore_GetReturnsLatest520=== PAUSE TestGCTaskStore_GetReturnsLatest521=== RUN TestGCTaskStore_CompletedAllowsNewTask522=== PAUSE TestGCTaskStore_CompletedAllowsNewTask523=== RUN TestGCTaskStore_PhaseUpdates524=== PAUSE TestGCTaskStore_PhaseUpdates525=== RUN TestGCTaskStore_Fail526=== PAUSE TestGCTaskStore_Fail527=== RUN TestGracefulShutdownDrainsInflight528=== PAUSE TestGracefulShutdownDrainsInflight529=== RUN TestService_healthCheckHandler530=== PAUSE TestService_healthCheckHandler531=== RUN TestService_readinessHandler532=== PAUSE TestService_readinessHandler533=== RUN TestGenerateLandingPage534=== PAUSE TestGenerateLandingPage535=== RUN TestCacheConfigHandlerMaxNarSize536=== PAUSE TestCacheConfigHandlerMaxNarSize537=== RUN TestCreatePendingClosureRejectsOversizedNAR538=== PAUSE TestCreatePendingClosureRejectsOversizedNAR539=== RUN TestNARDeduplicationMetadataUploadBug540=== PAUSE TestNARDeduplicationMetadataUploadBug541=== RUN TestMetricsInventory542=== PAUSE TestMetricsInventory543=== RUN TestService_NativeMTLS544=== PAUSE TestService_NativeMTLS545=== RUN TestServerTLSConfig546=== PAUSE TestServerTLSConfig547=== RUN TestMultipartCleanup548=== PAUSE TestMultipartCleanup549=== RUN TestObjectStatsTrigger550=== PAUSE TestObjectStatsTrigger551=== RUN TestOrphanedObjectsGC552=== PAUSE TestOrphanedObjectsGC553=== RUN TestOrphanedObjectsGCStressTest554=== PAUSE TestOrphanedObjectsGCStressTest555=== RUN TestResurrectedObjectNotDeleted556=== PAUSE TestResurrectedObjectNotDeleted557=== RUN TestCreatePin_ReservedPins558=== PAUSE TestCreatePin_ReservedPins559=== RUN TestParseSingleRange560=== PAUSE TestParseSingleRange561=== RUN TestProxyHeadersOnlyTrustedOnSocket562=== PAUSE TestProxyHeadersOnlyTrustedOnSocket563=== RUN TestIsValidCachePath564=== PAUSE TestIsValidCachePath565=== RUN TestReadProxyNarinfo566=== PAUSE TestReadProxyNarinfo567=== RUN TestReadProxyNarinfoAlreadyDecompressed568=== PAUSE TestReadProxyNarinfoAlreadyDecompressed569=== RUN TestReadProxyNarStreaming570=== PAUSE TestReadProxyNarStreaming571=== RUN TestReadProxy404572=== PAUSE TestReadProxy404573=== RUN TestReadProxyInvalidPath574=== PAUSE TestReadProxyInvalidPath575=== RUN TestReadProxyHead576=== PAUSE TestReadProxyHead577=== RUN TestReadProxyConditionalGet578=== PAUSE TestReadProxyConditionalGet579=== RUN TestReadProxyRootRedirectsToIndexHTML580=== PAUSE TestReadProxyRootRedirectsToIndexHTML581=== RUN TestReadProxyDisabled582=== PAUSE TestReadProxyDisabled583=== RUN TestReadRedirectNar584=== PAUSE TestReadRedirectNar585=== RUN TestReadRedirectKeepsNarinfoProxied586=== PAUSE TestReadRedirectKeepsNarinfoProxied587=== RUN TestReadProxyRangeRequest588=== PAUSE TestReadProxyRangeRequest589=== RUN TestReadRedirectUsesPublicS3URL590=== PAUSE TestReadRedirectUsesPublicS3URL591=== RUN TestPush_OverlappingRootsStoreOneRowPerKey592=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey593=== RUN TestPush_CompleteCommitsEveryRoot594=== PAUSE TestPush_CompleteCommitsEveryRoot595=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected596=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected597=== RUN TestPush_RejectsBadRequests598=== PAUSE TestPush_RejectsBadRequests599=== RUN TestPush_SignsNarinfosOfItsPendingObjects600=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects601=== RUN TestRedundantMultipartUpload602=== PAUSE TestRedundantMultipartUpload603=== RUN TestCompleteMultipartUpload_ErrorButObjectExists604=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists605=== RUN TestCompletedNarNotReofferedAcrossClosures606=== PAUSE TestCompletedNarNotReofferedAcrossClosures607=== RUN TestPresignedUploadRegisteredBeforeCommit608=== PAUSE TestPresignedUploadRegisteredBeforeCommit609=== RUN TestService_Rustfstest610=== PAUSE TestService_Rustfstest611=== RUN TestParseSize612=== PAUSE TestParseSize613=== RUN TestSkippedUploadsHandler614=== PAUSE TestSkippedUploadsHandler615=== RUN TestSystemdListenerNotActivated616--- PASS: TestSystemdListenerNotActivated (0.00s)617=== RUN TestWatchdogBeatsWhenHealthy618--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)619=== RUN TestWatchdogSkipsWhenUnhealthy6202026/09/23 13:29:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6212026/09/23 13:29:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:29:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:29:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:29:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:29:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:29:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:29:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:29:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/23 13:29:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"630--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)631=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle632=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== RUN TestProxyWriteTimeout634=== PAUSE TestProxyWriteTimeout635=== RUN TestIsValidUploadKey636=== PAUSE TestIsValidUploadKey637=== RUN TestUploadHandlersRejectInvalidKeys638=== PAUSE TestUploadHandlersRejectInvalidKeys639=== RUN TestUploadHandlersRejectOversizedBody640=== PAUSE TestUploadHandlersRejectOversizedBody641=== RUN TestService_cleanupPendingClosuresHandler642=== PAUSE TestService_cleanupPendingClosuresHandler643=== RUN TestService_createPendingClosureHandler644=== PAUSE TestService_createPendingClosureHandler645=== RUN TestService_verifyS3Integrity646=== PAUSE TestService_verifyS3Integrity647=== RUN TestCompleteMultipartUnregistered648=== PAUSE TestCompleteMultipartUnregistered649=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT650=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT651=== CONT TestSkippedUploadsHandler652=== CONT TestService_AuthMiddleware653=== CONT TestParseSize654--- PASS: TestParseSize (0.00s)655=== CONT TestReadRedirectNar656=== CONT TestService_Rustfstest6572026/09/23 13:29:37 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000658=== CONT TestPresignedUploadRegisteredBeforeCommit659=== CONT TestCompletedNarNotReofferedAcrossClosures660=== CONT TestCompleteMultipartUpload_ErrorButObjectExists661=== CONT TestService_cleanupPendingClosuresHandler662=== CONT TestRedundantMultipartUpload663=== CONT TestPush_SignsNarinfosOfItsPendingObjects664=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT665=== CONT TestPush_RejectsBadRequests666=== CONT TestCompleteMultipartUnregistered667=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected668=== CONT TestService_verifyS3Integrity669=== CONT TestPush_CompleteCommitsEveryRoot670=== CONT TestPush_OverlappingRootsStoreOneRowPerKey671=== CONT TestService_createPendingClosureHandler672=== CONT TestReadRedirectUsesPublicS3URL673=== CONT TestReadProxyRangeRequest674=== CONT TestGracefulShutdownDrainsInflight675=== CONT TestGCTaskStore_Fail676--- PASS: TestGCTaskStore_Fail (0.00s)677=== CONT TestGCTaskStore_CompletedAllowsNewTask678=== CONT TestReadRedirectKeepsNarinfoProxied679=== CONT TestGCTaskStore_PhaseUpdates680--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)681=== CONT TestReadProxyDisabled682--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)683=== CONT TestGCTaskStore_GetReturnsLatest684--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)685=== CONT TestReadProxyRootRedirectsToIndexHTML6862026/09/23 13:29:37 INFO Starting HTTP server address=127.0.0.1:348316872026/09/23 13:29:37 INFO Shutdown signal received, draining in-flight requests timeout=10s688--- PASS: TestSkippedUploadsHandler (0.01s)689=== CONT TestGCTaskStore_GetEmpty690--- PASS: TestGCTaskStore_GetEmpty (0.00s)691=== CONT TestReadProxyConditionalGet692--- PASS: TestGracefulShutdownDrainsInflight (0.07s)693=== CONT TestGCTaskStore_ConflictDifferentParams694--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)695=== CONT TestReadProxyHead6962026-09-23 13:29:37.449 UTC [446] ERROR: relation "goose_db_version" does not exist at character 366972026-09-23 13:29:37.449 UTC [446] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6982026-09-23 13:29:37.449 UTC [447] ERROR: relation "goose_db_version" does not exist at character 366992026-09-23 13:29:37.449 UTC [447] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7002026-09-23 13:29:37.453 UTC [448] ERROR: relation "goose_db_version" does not exist at character 367012026-09-23 13:29:37.453 UTC [448] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7022026-09-23 13:29:37.466 UTC [449] ERROR: relation "goose_db_version" does not exist at character 367032026-09-23 13:29:37.466 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7042026-09-23 13:29:37.514 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367052026-09-23 13:29:37.514 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7062026-09-23 13:29:37.517 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367072026-09-23 13:29:37.517 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7082026/09/23 13:29:37 OK 20241026095416_initial_model.sql (42.17ms)7092026/09/23 13:29:37 OK 20241026095416_initial_model.sql (40.68ms)7102026/09/23 13:29:37 OK 20241026095416_initial_model.sql (40.58ms)7112026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (4.14ms)7122026-09-23 13:29:37.537 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367132026-09-23 13:29:37.537 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7142026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (4.07ms)7152026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (5.4ms)7162026/09/23 13:29:37 OK 20241026095416_initial_model.sql (43.41ms)7172026/09/23 13:29:37 OK 20251218171726_add_pins.sql (8.08ms)7182026/09/23 13:29:37 OK 20251218171726_add_pins.sql (7.2ms)7192026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (4.33ms)7202026/09/23 13:29:37 OK 20251218171726_add_pins.sql (9.05ms)7212026/09/23 13:29:37 OK 20241026095416_initial_model.sql (17.82ms)7222026-09-23 13:29:37.551 UTC [455] ERROR: relation "goose_db_version" does not exist at character 367232026-09-23 13:29:37.551 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026/09/23 13:29:37 OK 20241026095416_initial_model.sql (20.04ms)7252026-09-23 13:29:37.555 UTC [456] ERROR: relation "goose_db_version" does not exist at character 367262026-09-23 13:29:37.555 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7272026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (10.3ms)7282026/09/23 13:29:37 OK 20251218171726_add_pins.sql (17.15ms)7292026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (17.66ms)7302026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (18.62ms)7312026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (10.21ms)7322026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (15.52ms)7332026/09/23 13:29:37 OK 20251218171726_add_pins.sql (8.27ms)7342026/09/23 13:29:37 OK 20260905000000_add_claims.sql (7.8ms)7352026/09/23 13:29:37 OK 20251218171726_add_pins.sql (7.75ms)7362026/09/23 13:29:37 OK 20260905000000_add_claims.sql (8.01ms)7372026/09/23 13:29:37 OK 20260905000000_add_claims.sql (7.65ms)7382026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (9.52ms)7392026/09/23 13:29:37 OK 20241026095416_initial_model.sql (28.58ms)7402026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (6.62ms)7412026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.98ms)7422026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.26ms)7432026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (6.65ms)7442026/09/23 13:29:37 OK 20260905000000_add_claims.sql (4.78ms)7452026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (8.28ms)7462026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (4.92ms)7472026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (3.79ms)7482026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (5.36ms)7492026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200007502026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (5.32ms)7512026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200007522026/09/23 13:29:37 OK 20260905000000_add_claims.sql (6.3ms)7532026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (4.88ms)7542026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200007552026-09-23 13:29:37.584 UTC [458] ERROR: relation "goose_db_version" does not exist at character 367562026-09-23 13:29:37.584 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7572026-09-23 13:29:37.585 UTC [459] ERROR: relation "goose_db_version" does not exist at character 367582026-09-23 13:29:37.585 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7592026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (14.4ms)7602026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200007612026/09/23 13:29:37 OK 20260905000000_add_claims.sql (18.65ms)7622026/09/23 13:29:37 OK 20241026095416_initial_model.sql (29.08ms)7632026/09/23 13:29:37 OK 1_commit_pending_closure.sql (15.18ms)7642026/09/23 13:29:37 OK 20251218171726_add_pins.sql (18.33ms)7652026/09/23 13:29:37 OK 1_commit_pending_closure.sql (15.43ms)7662026/09/23 13:29:37 OK 1_commit_pending_closure.sql (15.49ms)7672026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (16.38ms)7682026/09/23 13:29:37 OK 20241026095416_initial_model.sql (27.42ms)7692026/09/23 13:29:37 OK 2_object_stats_trigger.sql (3.22ms)7702026/09/23 13:29:37 OK 2_object_stats_trigger.sql (3.2ms)7712026/09/23 13:29:37 OK 2_object_stats_trigger.sql (3.45ms)7722026/09/23 13:29:37 OK 1_commit_pending_closure.sql (4.99ms)7732026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.8ms)7742026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (3.85ms)7752026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200007762026/09/23 13:29:37 OK 3_commit_push.sql (2.49ms)7772026/09/23 13:29:37 goose: up to current file version: 37782026/09/23 13:29:37 OK 3_commit_push.sql (3.6ms)7792026/09/23 13:29:37 goose: up to current file version: 37802026/09/23 13:29:37 OK 2_object_stats_trigger.sql (3.52ms)7812026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (7.36ms)7822026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (4.23ms)7832026/09/23 13:29:37 OK 1_commit_pending_closure.sql (3.55ms)7842026/09/23 13:29:37 OK 3_commit_push.sql (2.25ms)7852026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (4.88ms)7862026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200007872026/09/23 13:29:37 goose: up to current file version: 37882026/09/23 13:29:37 OK 3_commit_push.sql (3.3ms)7892026/09/23 13:29:37 goose: up to current file version: 37902026/09/23 13:29:37 OK 2_object_stats_trigger.sql (3.74ms)7912026/09/23 13:29:37 OK 20260905000000_add_claims.sql (5.74ms)7922026-09-23 13:29:37.612 UTC [460] ERROR: relation "goose_db_version" does not exist at character 367932026-09-23 13:29:37.612 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (3.94ms)7952026/09/23 13:29:37 OK 3_commit_push.sql (2.3ms)7962026/09/23 13:29:37 goose: up to current file version: 37972026/09/23 13:29:37 OK 20251218171726_add_pins.sql (6.7ms)7982026/09/23 13:29:37 OK 1_commit_pending_closure.sql (4.78ms)7992026/09/23 13:29:37 OK 2_object_stats_trigger.sql (3.23ms)8002026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.79ms)8012026/09/23 13:29:37 OK 3_commit_push.sql (2.34ms)8022026/09/23 13:29:37 goose: up to current file version: 38032026/09/23 13:29:37 OK 20251218171726_add_pins.sql (6.61ms)8042026/09/23 13:29:37 OK 20241026095416_initial_model.sql (11.95ms)8052026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (3.19ms)8062026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200008072026/09/23 13:29:37 OK 20241026095416_initial_model.sql (15.67ms)8082026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (6.84ms)8092026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)8102026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)8112026-09-23 13:29:37.623 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368122026-09-23 13:29:37.623 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8132026/09/23 13:29:37 OK 1_commit_pending_closure.sql (4.21ms)8142026-09-23 13:29:37.624 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368152026-09-23 13:29:37.624 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026-09-23 13:29:37.625 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368172026-09-23 13:29:37.625 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026-09-23 13:29:37.625 UTC [464] ERROR: relation "goose_db_version" does not exist at character 368192026-09-23 13:29:37.625 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8202026-09-23 13:29:37.626 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368212026-09-23 13:29:37.626 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8222026-09-23 13:29:37.626 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368232026-09-23 13:29:37.626 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8242026/09/23 13:29:37 OK 2_object_stats_trigger.sql (3.58ms)8252026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (9.14ms)8262026/09/23 13:29:37 OK 20260905000000_add_claims.sql (8.01ms)8272026/09/23 13:29:37 OK 20251218171726_add_pins.sql (6.88ms)8282026/09/23 13:29:37 OK 20251218171726_add_pins.sql (6.14ms)8292026-09-23 13:29:37.629 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368302026-09-23 13:29:37.629 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-09-23 13:29:37.630 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368322026-09-23 13:29:37.630 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026/09/23 13:29:37 OK 3_commit_push.sql (2.53ms)8342026/09/23 13:29:37 goose: up to current file version: 38352026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.39ms)8362026-09-23 13:29:37.633 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368372026-09-23 13:29:37.633 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8382026/09/23 13:29:37 OK 20241026095416_initial_model.sql (12.55ms)8392026-09-23 13:29:37.633 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368402026-09-23 13:29:37.633 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8412026-09-23 13:29:37.634 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368422026-09-23 13:29:37.634 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8432026/09/23 13:29:37 OK 20260905000000_add_claims.sql (6.28ms)8442026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (6.11ms)8452026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (6.03ms)8462026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (4.51ms)8472026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200008482026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (3.95ms)8492026-09-23 13:29:37.639 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368502026-09-23 13:29:37.639 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8512026/09/23 13:29:37 OK 20260905000000_add_claims.sql (5ms)8522026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (5.17ms)8532026/09/23 13:29:37 OK 20260905000000_add_claims.sql (4.94ms)8542026/09/23 13:29:37 OK 1_commit_pending_closure.sql (2.97ms)8552026/09/23 13:29:37 INFO Received uploads request method=POST path=/api/pending_closures8562026/09/23 13:29:37 OK 20251218171726_add_pins.sql (5.58ms)8572026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.55ms)8582026/09/23 13:29:37 OK 2_object_stats_trigger.sql (4.15ms)8592026/09/23 13:29:37 OK 20241026095416_initial_model.sql (11.8ms)8602026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (4.94ms)8612026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200008622026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (5.55ms)8632026/09/23 13:29:37 OK 20241026095416_initial_model.sql (11.74ms)8642026/09/23 13:29:37 OK 3_commit_push.sql (2.75ms)8652026/09/23 13:29:37 goose: up to current file version: 38662026/09/23 13:29:37 OK 20241026095416_initial_model.sql (14.54ms)8672026/09/23 13:29:37 OK 20241026095416_initial_model.sql (14.62ms)8682026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (2.86ms)8692026/09/23 13:29:37 OK 1_commit_pending_closure.sql (3.5ms)8702026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (5.25ms)8712026/09/23 13:29:37 OK 20241026095416_initial_model.sql (14.23ms)8722026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (4.2ms)8732026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200008742026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (4.27ms)8752026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200008762026/09/23 13:29:37 OK 20241026095416_initial_model.sql (13.4ms)8772026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (3.44ms)8782026/09/23 13:29:37 OK 2_object_stats_trigger.sql (2.49ms)8792026/09/23 13:29:37 OK 20241026095416_initial_model.sql (15.73ms)8802026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)8812026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (3.6ms)8822026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)8832026/09/23 13:29:37 OK 20251218171726_add_pins.sql (4.67ms)8842026/09/23 13:29:37 OK 1_commit_pending_closure.sql (3.62ms)8852026/09/23 13:29:37 OK 20241026095416_initial_model.sql (14.35ms)8862026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)8872026/09/23 13:29:37 OK 3_commit_push.sql (2.72ms)8882026/09/23 13:29:37 goose: up to current file version: 38892026/09/23 13:29:37 OK 20260905000000_add_claims.sql (5.15ms)8902026/09/23 13:29:37 OK 1_commit_pending_closure.sql (3.85ms)8912026/09/23 13:29:37 OK 20241026095416_initial_model.sql (11.34ms)8922026/09/23 13:29:37 OK 20251218171726_add_pins.sql (4.81ms)8932026/09/23 13:29:37 OK 20241026095416_initial_model.sql (14.59ms)8942026/09/23 13:29:37 OK 2_object_stats_trigger.sql (2.68ms)8952026/09/23 13:29:37 OK 20251218171726_add_pins.sql (5.19ms)8962026/09/23 13:29:37 OK 20251218171726_add_pins.sql (5.17ms)8972026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)8982026/09/23 13:29:37 OK 2_object_stats_trigger.sql (2.57ms)8992026/09/23 13:29:37 OK 20251218171726_add_pins.sql (5.24ms)9002026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)9012026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (3.21ms)9022026/09/23 13:29:37 OK 3_commit_push.sql (1.9ms)9032026/09/23 13:29:37 goose: up to current file version: 39042026/09/23 13:29:37 OK 20241026095416_initial_model.sql (13.41ms)9052026/09/23 13:29:37 OK 20251218171726_add_pins.sql (4.42ms)9062026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)9072026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)9082026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)9092026/09/23 13:29:37 OK 3_commit_push.sql (933.13µs)9102026/09/23 13:29:37 goose: up to current file version: 39112026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)9122026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (2.96ms)9132026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)9142026/09/23 13:29:37 OK 20241026095416_initial_model.sql (11.99ms)9152026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200009162026/09/23 13:29:37 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9172026/09/23 13:29:37 INFO Received uploads request method=POST path=/api/pending_closures9182026/09/23 13:29:37 OK 20251218171726_add_pins.sql (3.79ms)9192026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)9202026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (4.42ms)9212026/09/23 13:29:37 OK 20251218171726_add_pins.sql (4.83ms)9222026/09/23 13:29:37 OK 20251218171726_add_pins.sql (5.77ms)9232026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)9242026/09/23 13:29:37 OK 20260905000000_add_claims.sql (5.61ms)9252026/09/23 13:29:37 OK 20251218171726_add_pins.sql (5.12ms)9262026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (5.88ms)9272026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (2.61ms)9282026/09/23 13:29:37 OK 1_commit_pending_closure.sql (3.11ms)9292026/09/23 13:29:37 OK 20260905000000_add_claims.sql (3.19ms)9302026/09/23 13:29:37 OK 20251218171726_add_pins.sql (3.85ms)931--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.31s)932=== CONT TestIsValidUploadKey933=== RUN TestIsValidUploadKey/narinfo934=== PAUSE TestIsValidUploadKey/narinfo935=== RUN TestIsValidUploadKey/nar_zst936=== PAUSE TestIsValidUploadKey/nar_zst937=== RUN TestIsValidUploadKey/nar_xz938=== PAUSE TestIsValidUploadKey/nar_xz939=== RUN TestIsValidUploadKey/nar_plain940=== PAUSE TestIsValidUploadKey/nar_plain941=== RUN TestIsValidUploadKey/listing942=== PAUSE TestIsValidUploadKey/listing943=== RUN TestIsValidUploadKey/build_log944=== PAUSE TestIsValidUploadKey/build_log945=== RUN TestIsValidUploadKey/build_log_home-manager_file946=== PAUSE TestIsValidUploadKey/build_log_home-manager_file947=== RUN TestIsValidUploadKey/build_log_plus_in_name948=== PAUSE TestIsValidUploadKey/build_log_plus_in_name949=== RUN TestIsValidUploadKey/build_log_question_mark950=== PAUSE TestIsValidUploadKey/build_log_question_mark951=== RUN TestIsValidUploadKey/build_log_equals952=== PAUSE TestIsValidUploadKey/build_log_equals953=== RUN TestIsValidUploadKey/realisation954=== PAUSE TestIsValidUploadKey/realisation955=== RUN TestIsValidUploadKey/realisation_plus_in_output956=== PAUSE TestIsValidUploadKey/realisation_plus_in_output957=== RUN TestIsValidUploadKey/nix-cache-info958=== PAUSE TestIsValidUploadKey/nix-cache-info959=== RUN TestIsValidUploadKey/index.html960=== PAUSE TestIsValidUploadKey/index.html961=== RUN TestIsValidUploadKey/narinfo_key,_nar_type962=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type963=== RUN TestIsValidUploadKey/nar_key,_narinfo_type964=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type965=== RUN TestIsValidUploadKey/listing_key,_narinfo_type9662026/09/23 13:29:37 OK 20260905000000_add_claims.sql (3.38ms)967=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type968=== RUN TestIsValidUploadKey/traversal969=== PAUSE TestIsValidUploadKey/traversal970=== RUN TestIsValidUploadKey/traversal_nar971=== PAUSE TestIsValidUploadKey/traversal_nar972=== RUN TestIsValidUploadKey/absolute973=== PAUSE TestIsValidUploadKey/absolute974=== RUN TestIsValidUploadKey/empty_key975=== PAUSE TestIsValidUploadKey/empty_key976=== RUN TestIsValidUploadKey/unknown_type977=== PAUSE TestIsValidUploadKey/unknown_type978=== CONT TestUploadHandlersRejectOversizedBody9792026/09/23 13:29:37 OK 2_object_stats_trigger.sql (2.89ms)9802026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (5.04ms)9812026/09/23 13:29:37 OK 20260905000000_add_claims.sql (5ms)9822026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.42ms)9832026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (5.01ms)9842026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (5ms)9852026/09/23 13:29:37 OK 20251218171726_add_pins.sql (4.72ms)9862026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (4.86ms)9872026/09/23 13:29:37 OK 20260905000000_add_claims.sql (4.93ms)9882026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)9892026/09/23 13:29:37 OK 20260905000000_add_claims.sql (5.1ms)9902026/09/23 13:29:37 OK 3_commit_push.sql (1.5ms)9912026/09/23 13:29:37 goose: up to current file version: 39922026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (5.02ms)9932026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (3.9ms)9942026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (2.21ms)9952026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (2.01ms)9962026/09/23 13:29:37 goose: successfully migrated database to version: 202609231200009972026/09/23 13:29:37 OK 20260905000000_add_claims.sql (3.47ms)9982026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (2.17ms)9992026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (1.63ms)10002026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010012026/09/23 13:29:37 OK 1_commit_pending_closure.sql (2.05ms)10022026/09/23 13:29:37 OK 20260905000000_add_claims.sql (31.41ms)10032026/09/23 13:29:37 INFO Received uploads request method=POST path=/api/pending_closures1004=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1005=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1006=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1007=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1008=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1009=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1010=== CONT TestGCTaskStore_DeduplicateSameParams1011--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1012=== CONT TestUploadHandlersRejectInvalidKeys1013=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1014=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1015=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1016=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1017=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1018=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1019=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1020=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1021=== CONT TestClientMultipleUploads10222026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (89.57ms)10232026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010242026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (89.68ms)10252026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010262026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (3.28ms)10272026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010282026/09/23 13:29:37 OK 1_commit_pending_closure.sql (89.73ms)10292026/09/23 13:29:37 OK 20260905000000_add_claims.sql (4.57ms)10302026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.87ms)10312026/09/23 13:29:37 OK 20260905000000_add_claims.sql (90.39ms)10322026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.21ms)10332026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (90.75ms)10342026/09/23 13:29:37 OK 2_object_stats_trigger.sql (2.2ms)10352026/09/23 13:29:37 OK 1_commit_pending_closure.sql (3.72ms)10362026/09/23 13:29:37 OK 2_object_stats_trigger.sql (3.42ms)10372026/09/23 13:29:37 OK 1_commit_pending_closure.sql (4.47ms)10382026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (4.24ms)10392026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (4.19ms)10402026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010412026/09/23 13:29:37 OK 3_commit_push.sql (2.61ms)10422026/09/23 13:29:37 goose: up to current file version: 310432026/09/23 13:29:37 OK 2_object_stats_trigger.sql (1.55ms)10442026/09/23 13:29:37 OK 20260905000000_add_claims.sql (6.27ms)10452026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (6.43ms)10462026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (4.55ms)10472026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010482026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010492026/09/23 13:29:37 OK 1_commit_pending_closure.sql (4.92ms)10502026/09/23 13:29:37 OK 3_commit_push.sql (1.62ms)10512026/09/23 13:29:37 goose: up to current file version: 310522026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (6.13ms)10532026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (5.32ms)10542026/09/23 13:29:37 OK 2_object_stats_trigger.sql (1.5ms)10552026/09/23 13:29:37 OK 3_commit_push.sql (1.61ms)10562026/09/23 13:29:37 goose: up to current file version: 310572026/09/23 13:29:37 OK 1_commit_pending_closure.sql (4.42ms)10582026/09/23 13:29:37 OK 3_commit_push.sql (3.54ms)10592026/09/23 13:29:37 goose: up to current file version: 310602026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.87ms)10612026/09/23 13:29:37 OK 2_object_stats_trigger.sql (3.77ms)10622026/09/23 13:29:37 OK 1_commit_pending_closure.sql (4.5ms)10632026/09/23 13:29:37 OK 1_commit_pending_closure.sql (4.97ms)10642026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (4.06ms)10652026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010662026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (3.59ms)10672026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010682026/09/23 13:29:37 OK 3_commit_push.sql (1.98ms)10692026/09/23 13:29:37 goose: up to current file version: 310702026/09/23 13:29:37 OK 2_object_stats_trigger.sql (2.32ms)10712026/09/23 13:29:37 OK 20260905000000_add_claims.sql (6.75ms)10722026/09/23 13:29:37 OK 2_object_stats_trigger.sql (1.74ms)10732026/09/23 13:29:37 OK 2_object_stats_trigger.sql (3.46ms)10742026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (5.3ms)10752026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010762026/09/23 13:29:37 OK 1_commit_pending_closure.sql (4.67ms)10772026/09/23 13:29:37 OK 1_commit_pending_closure.sql (4.93ms)10782026/09/23 13:29:37 OK 3_commit_push.sql (3.03ms)10792026/09/23 13:29:37 goose: up to current file version: 310802026/09/23 13:29:37 OK 3_commit_push.sql (3.83ms)10812026/09/23 13:29:37 goose: up to current file version: 310822026/09/23 13:29:37 OK 3_commit_push.sql (2.76ms)10832026/09/23 13:29:37 goose: up to current file version: 310842026/09/23 13:29:37 OK 2_object_stats_trigger.sql (1.77ms)10852026/09/23 13:29:37 OK 2_object_stats_trigger.sql (1.66ms)10862026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (4.9ms)10872026/09/23 13:29:37 OK 1_commit_pending_closure.sql (2.57ms)10882026/09/23 13:29:37 OK 3_commit_push.sql (1.45ms)10892026/09/23 13:29:37 goose: up to current file version: 310902026/09/23 13:29:37 OK 3_commit_push.sql (1.56ms)10912026/09/23 13:29:37 goose: up to current file version: 310922026/09/23 13:29:37 OK 2_object_stats_trigger.sql (2.23ms)10932026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (3.88ms)10942026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000010952026/09/23 13:29:37 OK 3_commit_push.sql (2.67ms)10962026/09/23 13:29:37 goose: up to current file version: 310972026/09/23 13:29:37 OK 1_commit_pending_closure.sql (3.75ms)10982026/09/23 13:29:37 OK 2_object_stats_trigger.sql (2.1ms)10992026/09/23 13:29:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11002026/09/23 13:29:37 OK 3_commit_push.sql (2.69ms)11012026/09/23 13:29:37 goose: up to current file version: 311022026/09/23 13:29:37 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTk5ODFmMzYtNGMyZS00OWY2LWE4YWItZDIwNTYxOTFiZTBjLmRmY2E2ZjY5LWI4M2UtNDA1YS1hZTNlLWMzY2MwMDViNWY0ZngxNzkwMTcwMTc3ODc4ODk0Nzk21103--- PASS: TestReadRedirectNar (0.57s)1104=== CONT TestGCTaskStore_StartNew1105--- PASS: TestGCTaskStore_StartNew (0.00s)1106=== CONT TestClientIntegration11072026/09/23 13:29:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTk5ODFmMzYtNGMyZS00OWY2LWE4YWItZDIwNTYxOTFiZTBjLmRmY2E2ZjY5LWI4M2UtNDA1YS1hZTNlLWMzY2MwMDViNWY0ZngxNzkwMTcwMTc3ODc4ODk0Nzk2 parts=11108--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.57s)1109=== CONT TestGCMetrics1110--- PASS: TestService_Rustfstest (0.59s)1111=== CONT TestClientErrorHandling1112=== RUN TestClientErrorHandling/InvalidStorePath1113=== PAUSE TestClientErrorHandling/InvalidStorePath1114=== RUN TestClientErrorHandling/InvalidAuthToken1115=== PAUSE TestClientErrorHandling/InvalidAuthToken1116=== RUN TestClientErrorHandling/ServerNotAvailable1117=== PAUSE TestClientErrorHandling/ServerNotAvailable1118=== CONT TestGCBugBareHashReferences11192026-09-23 13:29:37.954 UTC [483] ERROR: relation "goose_db_version" does not exist at character 3611202026-09-23 13:29:37.954 UTC [483] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11212026/09/23 13:29:37 INFO Received cleanup request method=DELETE path=/api/pending_closures11222026/09/23 13:29:37 INFO Aborted multipart uploads count=011232026/09/23 13:29:37 INFO Received uploads request method=POST path=/api/pending_closures11242026/09/23 13:29:37 OK 20241026095416_initial_model.sql (11.9ms)11252026/09/23 13:29:37 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)11262026/09/23 13:29:37 INFO Received cleanup request method=DELETE path=/api/pending_closures11272026/09/23 13:29:37 OK 20251218171726_add_pins.sql (4.12ms)11282026/09/23 13:29:37 INFO Aborted multipart uploads count=111292026/09/23 13:29:37 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)11302026/09/23 13:29:37 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1131--- PASS: TestService_AuthMiddleware (0.64s)1132=== CONT TestReadProxyInvalidPath11332026/09/23 13:29:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11342026-09-23 13:29:37.991 UTC [453] ERROR: Closure does not exist: id=111352026-09-23 13:29:37.991 UTC [453] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11362026-09-23 13:29:37.991 UTC [453] STATEMENT: -- name: CommitPendingClosure :exec1137 SELECT commit_pending_closure($1::bigint)1138 1139--- PASS: TestService_cleanupPendingClosuresHandler (0.64s)1140=== CONT TestClientCADerivations11412026/09/23 13:29:37 OK 20260905000000_add_claims.sql (3.95ms)11422026/09/23 13:29:37 OK 20260920000000_drop_claims.sql (2.02ms)11432026/09/23 13:29:37 OK 20260923120000_add_pushes.sql (2.28ms)11442026/09/23 13:29:37 goose: successfully migrated database to version: 2026092312000011452026/09/23 13:29:37 OK 1_commit_pending_closure.sql (1.83ms)11462026/09/23 13:29:38 OK 2_object_stats_trigger.sql (1.3ms)11472026/09/23 13:29:38 OK 3_commit_push.sql (2.3ms)11482026/09/23 13:29:38 goose: up to current file version: 311492026-09-23 13:29:38.004 UTC [488] ERROR: relation "goose_db_version" does not exist at character 3611502026-09-23 13:29:38.004 UTC [488] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11512026-09-23 13:29:38.007 UTC [489] ERROR: relation "goose_db_version" does not exist at character 3611522026-09-23 13:29:38.007 UTC [489] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11532026-09-23 13:29:38.008 UTC [490] ERROR: relation "goose_db_version" does not exist at character 3611542026-09-23 13:29:38.008 UTC [490] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11552026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures11562026/09/23 13:29:38 OK 20241026095416_initial_model.sql (13.09ms)11572026/09/23 13:29:38 OK 20241026095416_initial_model.sql (19.1ms)11582026/09/23 13:29:38 OK 20241026095416_initial_model.sql (19.37ms)11592026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (10.63ms)11602026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (3.09ms)11612026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.88ms)11622026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.38ms)11632026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.39ms)11642026/09/23 13:29:38 OK 20251218171726_add_pins.sql (5.2ms)11652026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures11662026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)11672026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)11682026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (5.52ms)11692026/09/23 13:29:38 OK 20260905000000_add_claims.sql (5.08ms)11702026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.91ms)11712026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.1ms)11722026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.89ms)11732026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.5ms)11742026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (2.79ms)11752026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures11762026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (2ms)11772026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000011782026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (1.71ms)11792026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000011802026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (1.93ms)11812026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000011822026/09/23 13:29:38 OK 1_commit_pending_closure.sql (2.08ms)11832026/09/23 13:29:38 OK 1_commit_pending_closure.sql (2.03ms)11842026/09/23 13:29:38 OK 2_object_stats_trigger.sql (1.1ms)11852026/09/23 13:29:38 OK 2_object_stats_trigger.sql (1.19ms)11862026/09/23 13:29:38 OK 1_commit_pending_closure.sql (2.28ms)11872026/09/23 13:29:38 OK 3_commit_push.sql (968.23µs)11882026/09/23 13:29:38 goose: up to current file version: 311892026/09/23 13:29:38 OK 3_commit_push.sql (887.53µs)11902026/09/23 13:29:38 goose: up to current file version: 311912026/09/23 13:29:38 OK 2_object_stats_trigger.sql (1.08ms)11922026/09/23 13:29:38 OK 3_commit_push.sql (684.71µs)11932026/09/23 13:29:38 goose: up to current file version: 311942026-09-23 13:29:38.065 UTC [491] ERROR: relation "goose_db_version" does not exist at character 3611952026-09-23 13:29:38.065 UTC [491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11962026-09-23 13:29:38.066 UTC [492] ERROR: relation "goose_db_version" does not exist at character 3611972026-09-23 13:29:38.066 UTC [492] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11982026/09/23 13:29:38 OK 20241026095416_initial_model.sql (8.88ms)11992026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)12002026/09/23 13:29:38 OK 20241026095416_initial_model.sql (10.89ms)12012026/09/23 13:29:38 INFO Received push request method=POST path=/api/pushes12022026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)12032026/09/23 13:29:38 OK 20251218171726_add_pins.sql (2.67ms)12042026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.27ms)12052026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)12062026/09/23 13:29:38 OK 20260905000000_add_claims.sql (3.4ms)12072026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)12082026/09/23 13:29:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12092026/09/23 13:29:38 INFO Signed narinfos id=1 count=112102026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (7.62ms)1211--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.75s)1212=== CONT TestReadProxy40412132026/09/23 13:29:38 OK 20260905000000_add_claims.sql (8.44ms)12142026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (2.55ms)12152026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000012162026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (2.4ms)12172026/09/23 13:29:38 OK 1_commit_pending_closure.sql (1.99ms)12182026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (1.77ms)12192026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000012202026/09/23 13:29:38 OK 2_object_stats_trigger.sql (923.89µs)12212026/09/23 13:29:38 OK 3_commit_push.sql (864.71µs)12222026/09/23 13:29:38 goose: up to current file version: 312232026/09/23 13:29:38 OK 1_commit_pending_closure.sql (1.81ms)12242026/09/23 13:29:38 OK 2_object_stats_trigger.sql (937.19µs)12252026/09/23 13:29:38 OK 3_commit_push.sql (849.69µs)12262026/09/23 13:29:38 goose: up to current file version: 31227--- PASS: TestReadProxyRangeRequest (0.77s)1228=== CONT TestCacheStatsHandler12292026/09/23 13:29:38 INFO Received push request method=POST path=/api/pushes12302026/09/23 13:29:38 INFO Received complete push request method=POST path=/api/pushes/1/complete1231=== RUN TestPush_RejectsBadRequests/no_roots1232=== PAUSE TestPush_RejectsBadRequests/no_roots1233=== RUN TestPush_RejectsBadRequests/no_objects1234=== PAUSE TestPush_RejectsBadRequests/no_objects1235=== RUN TestPush_RejectsBadRequests/bad_root1236=== PAUSE TestPush_RejectsBadRequests/bad_root1237=== RUN TestPush_RejectsBadRequests/root_not_in_objects1238=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1239=== CONT TestReadProxyNarStreaming12402026-09-23 13:29:38.168 UTC [498] ERROR: relation "goose_db_version" does not exist at character 3612412026-09-23 13:29:38.168 UTC [498] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12422026/09/23 13:29:38 INFO Received push request method=POST path=/api/pushes12432026/09/23 13:29:38 OK 20241026095416_initial_model.sql (11.23ms)12442026/09/23 13:29:38 INFO Received complete push request method=POST path=/api/pushes/2/complete12452026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)12462026-09-23 13:29:38.188 UTC [497] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo12472026-09-23 13:29:38.188 UTC [497] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE12482026-09-23 13:29:38.188 UTC [497] STATEMENT: -- name: CommitPush :exec1249 SELECT commit_push($1::bigint)1250 1251--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (0.84s)1252=== CONT TestLeadEndsOnShutdown12532026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.57ms)12542026-09-23 13:29:38.193 UTC [501] ERROR: relation "goose_db_version" does not exist at character 3612552026-09-23 13:29:38.193 UTC [501] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12562026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures12572026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (11.9ms)12582026/09/23 13:29:38 OK 20260905000000_add_claims.sql (3.82ms)12592026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.22ms)12602026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (4.22ms)12612026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000012622026/09/23 13:29:38 OK 20241026095416_initial_model.sql (12.3ms)12632026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.72ms)12642026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)12652026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.75ms)12662026/09/23 13:29:38 OK 3_commit_push.sql (2.61ms)12672026/09/23 13:29:38 goose: up to current file version: 312682026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.73ms)12692026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (7.36ms)12702026/09/23 13:29:38 INFO Received push request method=POST path=/api/pushes12712026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.32ms)12722026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.45ms)12732026-09-23 13:29:38.244 UTC [504] ERROR: relation "goose_db_version" does not exist at character 3612742026-09-23 13:29:38.244 UTC [504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12752026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.17ms)12762026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000012772026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.3ms)12782026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.42ms)12792026/09/23 13:29:38 OK 3_commit_push.sql (2.13ms)12802026/09/23 13:29:38 goose: up to current file version: 312812026/09/23 13:29:38 OK 20241026095416_initial_model.sql (10.72ms)12822026/09/23 13:29:38 INFO Received complete push request method=POST path=/api/pushes/1/complete12832026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)12842026/09/23 13:29:38 OK 20251218171726_add_pins.sql (3.64ms)12852026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)1286--- PASS: TestReadProxyDisabled (0.92s)1287=== CONT TestReadProxyNarinfoAlreadyDecompressed12882026-09-23 13:29:38.270 UTC [507] ERROR: relation "goose_db_version" does not exist at character 3612892026-09-23 13:29:38.270 UTC [507] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1290--- PASS: TestPush_CompleteCommitsEveryRoot (0.92s)1291=== CONT TestReadProxyNarinfo12922026/09/23 13:29:38 OK 20260905000000_add_claims.sql (5.97ms)12932026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (2.42ms)12942026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (2.29ms)12952026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000012962026/09/23 13:29:38 OK 1_commit_pending_closure.sql (2.76ms)12972026/09/23 13:29:38 OK 2_object_stats_trigger.sql (1.74ms)12982026/09/23 13:29:38 OK 3_commit_push.sql (1.4ms)12992026/09/23 13:29:38 goose: up to current file version: 313002026/09/23 13:29:38 OK 20241026095416_initial_model.sql (11.18ms)13012026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)13022026/09/23 13:29:38 OK 20251218171726_add_pins.sql (3.1ms)13032026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)13042026/09/23 13:29:38 OK 20260905000000_add_claims.sql (3.31ms)13052026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (2.47ms)13062026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (2.36ms)13072026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000013082026/09/23 13:29:38 OK 1_commit_pending_closure.sql (2.45ms)13092026/09/23 13:29:38 OK 2_object_stats_trigger.sql (1.56ms)13102026/09/23 13:29:38 OK 3_commit_push.sql (1.85ms)13112026/09/23 13:29:38 goose: up to current file version: 31312--- PASS: TestReadRedirectKeepsNarinfoProxied (0.96s)1313=== CONT TestService_ReadAuthMiddleware13142026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures13152026/09/23 13:29:38 INFO Received push request method=POST path=/api/pushes1316--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.01s)1317=== CONT TestIsValidCachePath1318=== RUN TestIsValidCachePath/narinfo1319=== PAUSE TestIsValidCachePath/narinfo1320=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1321=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1322=== RUN TestIsValidCachePath/nar_zst1323=== PAUSE TestIsValidCachePath/nar_zst1324=== RUN TestIsValidCachePath/nar_xz1325=== PAUSE TestIsValidCachePath/nar_xz1326=== RUN TestIsValidCachePath/nar_bz21327=== PAUSE TestIsValidCachePath/nar_bz21328=== RUN TestIsValidCachePath/nar_uncompressed1329=== PAUSE TestIsValidCachePath/nar_uncompressed1330=== RUN TestIsValidCachePath/ls1331=== PAUSE TestIsValidCachePath/ls1332=== RUN TestIsValidCachePath/log1333=== PAUSE TestIsValidCachePath/log1334=== RUN TestIsValidCachePath/realisation1335=== PAUSE TestIsValidCachePath/realisation1336=== RUN TestIsValidCachePath/nix-cache-info1337=== PAUSE TestIsValidCachePath/nix-cache-info1338=== RUN TestIsValidCachePath/index.html1339=== PAUSE TestIsValidCachePath/index.html1340=== RUN TestIsValidCachePath/traversal_parent1341=== PAUSE TestIsValidCachePath/traversal_parent1342=== RUN TestIsValidCachePath/traversal_in_middle1343=== PAUSE TestIsValidCachePath/traversal_in_middle1344=== RUN TestIsValidCachePath/invalid_char_e1345=== PAUSE TestIsValidCachePath/invalid_char_e1346=== RUN TestIsValidCachePath/invalid_char_u1347=== PAUSE TestIsValidCachePath/invalid_char_u1348=== RUN TestIsValidCachePath/random_path1349=== PAUSE TestIsValidCachePath/random_path1350=== RUN TestIsValidCachePath/empty1351=== PAUSE TestIsValidCachePath/empty1352=== RUN TestIsValidCachePath/leading_slash1353=== PAUSE TestIsValidCachePath/leading_slash1354=== RUN TestIsValidCachePath/wrong_extension1355=== PAUSE TestIsValidCachePath/wrong_extension1356=== RUN TestIsValidCachePath/short_hash1357=== PAUSE TestIsValidCachePath/short_hash1358=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13592026-09-23 13:29:38.364 UTC [517] ERROR: relation "goose_db_version" does not exist at character 3613602026-09-23 13:29:38.364 UTC [517] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13612026-09-23 13:29:38.364 UTC [518] ERROR: relation "goose_db_version" does not exist at character 3613622026-09-23 13:29:38.364 UTC [518] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13632026/09/23 13:29:38 OK 20241026095416_initial_model.sql (11.38ms)13642026/09/23 13:29:38 OK 20241026095416_initial_model.sql (10.58ms)13652026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)1366--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.03s)1367=== CONT TestProxyHeadersOnlyTrustedOnSocket13682026-09-23 13:29:38.385 UTC [523] ERROR: relation "goose_db_version" does not exist at character 3613692026-09-23 13:29:38.385 UTC [523] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13702026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (4.34ms)13712026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.29ms)13722026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.14ms)13732026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (3.43ms)1374--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.04s)1375=== CONT TestParseSingleRange1376=== RUN TestParseSingleRange/none1377=== PAUSE TestParseSingleRange/none1378=== RUN TestParseSingleRange/unknown_unit13792026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)1380=== PAUSE TestParseSingleRange/unknown_unit1381=== RUN TestParseSingleRange/multi-range_ignored1382=== PAUSE TestParseSingleRange/multi-range_ignored1383=== RUN TestParseSingleRange/malformed_no_dash1384=== PAUSE TestParseSingleRange/malformed_no_dash1385=== RUN TestParseSingleRange/malformed_both_empty1386=== PAUSE TestParseSingleRange/malformed_both_empty1387=== RUN TestParseSingleRange/malformed_end_before_start1388=== PAUSE TestParseSingleRange/malformed_end_before_start1389=== RUN TestParseSingleRange/closed1390=== PAUSE TestParseSingleRange/closed1391=== RUN TestParseSingleRange/open-ended1392=== PAUSE TestParseSingleRange/open-ended1393=== RUN TestParseSingleRange/end_clamped_to_size1394=== PAUSE TestParseSingleRange/end_clamped_to_size1395=== RUN TestParseSingleRange/suffix1396=== PAUSE TestParseSingleRange/suffix1397=== RUN TestParseSingleRange/suffix_exceeds_size1398=== PAUSE TestParseSingleRange/suffix_exceeds_size1399=== RUN TestParseSingleRange/single_byte1400=== PAUSE TestParseSingleRange/single_byte1401=== RUN TestParseSingleRange/start_past_EOF1402=== PAUSE TestParseSingleRange/start_past_EOF1403=== RUN TestParseSingleRange/start_far_past_EOF1404=== PAUSE TestParseSingleRange/start_far_past_EOF1405=== CONT TestService_AuthMiddleware_MTLSProxyHeader14062026/09/23 13:29:38 OK 20260905000000_add_claims.sql (3.51ms)14072026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (2.76ms)14082026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.8ms)14092026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (2.61ms)14102026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000014112026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (4.37ms)14122026/09/23 13:29:38 OK 20241026095416_initial_model.sql (12.25ms)14132026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.26ms)14142026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)14152026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.61ms)14162026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.88ms)14172026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000014182026/09/23 13:29:38 OK 3_commit_push.sql (2.27ms)14192026/09/23 13:29:38 goose: up to current file version: 314202026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.34ms)14212026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.77ms)14222026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.72ms)14232026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)14242026/09/23 13:29:38 OK 3_commit_push.sql (3.54ms)14252026/09/23 13:29:38 goose: up to current file version: 314262026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.44ms)14272026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.97ms)14282026/09/23 13:29:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14292026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.44ms)14302026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000014312026/09/23 13:29:38 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1432--- PASS: TestCompleteMultipartUnregistered (1.08s)1433=== CONT TestCreatePin_ReservedPins14342026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.37ms)14352026-09-23 13:29:38.434 UTC [528] ERROR: relation "goose_db_version" does not exist at character 3614362026-09-23 13:29:38.434 UTC [528] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.08ms)14382026/09/23 13:29:38 OK 3_commit_push.sql (1.98ms)14392026/09/23 13:29:38 goose: up to current file version: 314402026/09/23 13:29:38 OK 20241026095416_initial_model.sql (20.19ms)14412026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)1442--- PASS: TestReadProxyHead (1.04s)1443=== CONT TestLeadElectsOneAndHandsOver14442026/09/23 13:29:38 OK 20251218171726_add_pins.sql (3.81ms)14452026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)14462026-09-23 13:29:38.473 UTC [529] ERROR: relation "goose_db_version" does not exist at character 3614472026-09-23 13:29:38.473 UTC [529] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14482026-09-23 13:29:38.475 UTC [531] ERROR: relation "goose_db_version" does not exist at character 3614492026-09-23 13:29:38.475 UTC [531] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14502026/09/23 13:29:38 OK 20260905000000_add_claims.sql (3.89ms)14512026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (2.16ms)14522026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (2.42ms)14532026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000014542026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.84ms)14552026/09/23 13:29:38 OK 2_object_stats_trigger.sql (3.61ms)14562026/09/23 13:29:38 OK 20241026095416_initial_model.sql (12.68ms)14572026/09/23 13:29:38 OK 3_commit_push.sql (2.8ms)14582026/09/23 13:29:38 goose: up to current file version: 314592026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.87ms)14602026/09/23 13:29:38 OK 20241026095416_initial_model.sql (13.3ms)14612026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)14622026/09/23 13:29:38 OK 20251218171726_add_pins.sql (3.42ms)14632026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.34ms)14642026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (5.41ms)1465--- PASS: TestReadRedirectUsesPublicS3URL (1.15s)1466=== CONT TestResurrectedObjectNotDeleted14672026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)14682026/09/23 13:29:38 OK 20260905000000_add_claims.sql (5.4ms)14692026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.43ms)14702026/09/23 13:29:38 OK 20260905000000_add_claims.sql (5.34ms)14712026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (2.83ms)14722026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000014732026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (4.24ms)14742026/09/23 13:29:38 OK 1_commit_pending_closure.sql (2.87ms)14752026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (2.18ms)14762026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000014772026/09/23 13:29:38 OK 2_object_stats_trigger.sql (1.96ms)14782026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures14792026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures14802026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures14812026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.82ms)14822026/09/23 13:29:38 OK 3_commit_push.sql (2.87ms)14832026/09/23 13:29:38 goose: up to current file version: 314842026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.28ms)14852026/09/23 13:29:38 OK 3_commit_push.sql (2.34ms)14862026/09/23 13:29:38 goose: up to current file version: 314872026-09-23 13:29:38.528 UTC [535] ERROR: relation "goose_db_version" does not exist at character 3614882026-09-23 13:29:38.528 UTC [535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14892026/09/23 13:29:38 OK 20241026095416_initial_model.sql (10.25ms)14902026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)14912026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.03ms)14922026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (4.89ms)14932026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.26ms)14942026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.06ms)14952026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (1.93ms)14962026/09/23 13:29:38 goose: successfully migrated database to version: 202609231200001497--- PASS: TestReadProxyConditionalGet (1.21s)1498=== CONT TestResolveDBConnectionString14992026/09/23 13:29:38 OK 1_commit_pending_closure.sql (2.08ms)1500=== RUN TestResolveDBConnectionString/flag_wins1501=== PAUSE TestResolveDBConnectionString/flag_wins1502=== RUN TestResolveDBConnectionString/file_when_flag_empty1503=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1504=== RUN TestResolveDBConnectionString/missing_file_is_an_error1505=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1506=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1507=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1508=== RUN TestResolveDBConnectionString/nothing_configured1509=== PAUSE TestResolveDBConnectionString/nothing_configured1510=== CONT TestOrphanedObjectsGCStressTest15112026/09/23 13:29:38 OK 2_object_stats_trigger.sql (962.19µs)15122026/09/23 13:29:38 OK 3_commit_push.sql (830.65µs)15132026/09/23 13:29:38 goose: up to current file version: 315142026-09-23 13:29:38.577 UTC [537] ERROR: relation "goose_db_version" does not exist at character 3615152026-09-23 13:29:38.577 UTC [537] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15162026/09/23 13:29:38 OK 20241026095416_initial_model.sql (11.84ms)15172026/09/23 13:29:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38487/oidc15182026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (3ms)15192026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4ms)15202026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)15212026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.85ms)15222026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3ms)15232026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.27ms)15242026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000015252026/09/23 13:29:38 INFO Aborted multipart uploads count=015262026/09/23 13:29:38 WARN Force mode enabled - objects will be deleted immediately without grace period1527=== NAME TestClientMultipleUploads1528 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4192947695/001/store/jy3i2h80mk8hai8krwhlv8vc9xrhfr4b-test-file-0.txt15292026/09/23 13:29:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015302026/09/23 13:29:38 INFO Vacuumed table table=pending_closures15312026/09/23 13:29:38 OK 1_commit_pending_closure.sql (9.72ms)15322026/09/23 13:29:38 INFO Vacuumed table table=pending_objects15332026/09/23 13:29:38 INFO Vacuumed table table=multipart_uploads15342026/09/23 13:29:38 INFO Vacuumed table table=closures15352026/09/23 13:29:38 INFO Vacuumed table table=objects15362026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.98ms)15372026/09/23 13:29:38 OK 3_commit_push.sql (1.86ms)15382026/09/23 13:29:38 goose: up to current file version: 31539--- PASS: TestGCMetrics (0.72s)1540=== CONT TestService_AuthMiddleware_OIDC15412026-09-23 13:29:38.645 UTC [560] ERROR: relation "goose_db_version" does not exist at character 3615422026-09-23 13:29:38.645 UTC [560] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15432026/09/23 13:29:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15442026/09/23 13:29:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15452026/09/23 13:29:38 OK 20241026095416_initial_model.sql (10.01ms)1546=== NAME TestClientMultipleUploads1547 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4192947695/001/store/zw8j8ck9ajlvm21xvm27yx4f8cwsy22v-test-file-1.txt15482026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)15492026/09/23 13:29:38 OK 20251218171726_add_pins.sql (3.37ms)15502026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)15512026/09/23 13:29:38 OK 20260905000000_add_claims.sql (2.91ms)15522026/09/23 13:29:38 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTk5ODFmMzYtNGMyZS00OWY2LWE4YWItZDIwNTYxOTFiZTBjLmFjZjJiZDZkLTg5NDktNDYyZC04YzhiLTAxNTBmYTc5MDY0M3gxNzkwMTcwMTc4MDY1NzQ2NTAy parts=1215532026/09/23 13:29:38 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTk5ODFmMzYtNGMyZS00OWY2LWE4YWItZDIwNTYxOTFiZTBjLjNlZDJmMmVlLWU0NTktNGFkNC1iZmFkLThkYmI3ODUxMjFiNHgxNzkwMTcwMTc4MDM3NjE5ODMx parts=1215542026-09-23 13:29:38.676 UTC [597] ERROR: relation "goose_db_version" does not exist at character 3615552026-09-23 13:29:38.676 UTC [597] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15562026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (2.14ms)15572026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures1558--- PASS: TestRedundantMultipartUpload (1.33s)1559=== CONT TestMetricsInventory15602026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (1.68ms)15612026/09/23 13:29:38 goose: successfully migrated database to version: 202609231200001562--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.33s)1563=== CONT TestCacheConfigHandler1564=== RUN TestCacheConfigHandler/full_config,_no_issuer1565=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1566=== RUN TestCacheConfigHandler/no_cache_url_configured1567=== PAUSE TestCacheConfigHandler/no_cache_url_configured1568=== RUN TestCacheConfigHandler/no_signing_keys1569=== PAUSE TestCacheConfigHandler/no_signing_keys1570=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1571=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1572=== CONT TestService_ReadScope_PublicByDefault15732026/09/23 13:29:38 OK 1_commit_pending_closure.sql (1.92ms)15742026/09/23 13:29:38 OK 2_object_stats_trigger.sql (834.77µs)15752026/09/23 13:29:38 OK 3_commit_push.sql (1.33ms)15762026/09/23 13:29:38 goose: up to current file version: 31577=== NAME TestClientIntegration1578 client_integration_test.go:286: Created store path: /build/TestClientIntegration792880673/002/store/l8xkl9223kbhl342xc3ghqclvzk4v3pb-test-file.txt15792026/09/23 13:29:38 OK 20241026095416_initial_model.sql (9.09ms)15802026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)1581=== NAME TestClientMultipleUploads1582 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4192947695/001/store/0hc29nfxwwfb5rc5p7l3dpf9qnpx0srs-test-file-2.txt15832026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.05ms)15842026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)15852026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.84ms)15862026/09/23 13:29:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15872026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.4ms)15882026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.18ms)15892026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000015902026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.2ms)15912026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.23ms)15922026/09/23 13:29:38 OK 3_commit_push.sql (1.94ms)15932026/09/23 13:29:38 goose: up to current file version: 315942026/09/23 13:29:38 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTk5ODFmMzYtNGMyZS00OWY2LWE4YWItZDIwNTYxOTFiZTBjLjUzODE0MjlmLWIyYjctNDQ3OS05YjI4LTlmMzUyNDE5YzkzMXgxNzkwMTcwMTc4MjEyMTI2OTg3 parts=1015952026/09/23 13:29:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1596--- PASS: TestReadProxyInvalidPath (0.75s)1597=== CONT TestService_RequireScope_OIDC15982026/09/23 13:29:38 INFO Completed upload id=115992026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures16002026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures16012026/09/23 13:29:38 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16022026/09/23 13:29:38 WARN Found objects in DB but missing from S3, will re-upload count=11603--- PASS: TestService_verifyS3Integrity (1.39s)1604=== CONT TestOrphanedObjectsGC16052026-09-23 13:29:38.760 UTC [692] ERROR: relation "goose_db_version" does not exist at character 3616062026-09-23 13:29:38.760 UTC [692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16072026-09-23 13:29:38.761 UTC [693] ERROR: relation "goose_db_version" does not exist at character 3616082026-09-23 13:29:38.761 UTC [693] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1609--- PASS: TestReadProxy404 (0.66s)1610=== CONT TestObjectStatsTrigger16112026/09/23 13:29:38 OK 20241026095416_initial_model.sql (12.36ms)16122026/09/23 13:29:38 OK 20241026095416_initial_model.sql (13.43ms)16132026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures16142026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures16152026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)16162026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2ms)1617=== NAME TestClientCADerivations1618 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2012390629/001/store/32xh09gcf2v9w6ccn1gfxmiamfhxmysh-ca-test16192026/09/23 13:29:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36095/oidc16202026/09/23 13:29:38 OK 20251218171726_add_pins.sql (12.66ms)16212026/09/23 13:29:38 OK 20251218171726_add_pins.sql (15.24ms)16222026/09/23 13:29:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16232026/09/23 13:29:38 INFO Uploading l8xkl9223kbhl342xc3ghqclvzk4v3pb-test-file.txt (152B)16242026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures16252026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (6.17ms)16262026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures16272026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (5.58ms)16282026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.92ms)16292026/09/23 13:29:38 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16302026/09/23 13:29:38 INFO Uploading jy3i2h80mk8hai8krwhlv8vc9xrhfr4b-test-file-0.txt (160B)16312026/09/23 13:29:38 INFO Uploading zw8j8ck9ajlvm21xvm27yx4f8cwsy22v-test-file-1.txt (160B)16322026/09/23 13:29:38 INFO Uploading 0hc29nfxwwfb5rc5p7l3dpf9qnpx0srs-test-file-2.txt (160B)16332026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.6ms)16342026/09/23 13:29:38 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16352026/09/23 13:29:38 WARN Failed to register uploaded object key=l8xkl9223kbhl342xc3ghqclvzk4v3pb.ls error="server returned 404: 404 page not found\n"16362026/09/23 13:29:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16372026/09/23 13:29:38 INFO Signed narinfos id=1 count=116382026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (5.21ms)16392026/09/23 13:29:38 INFO Uploading 1 narinfos16402026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (4.27ms)16412026/09/23 13:29:38 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16422026/09/23 13:29:38 WARN Failed to register uploaded object key=zw8j8ck9ajlvm21xvm27yx4f8cwsy22v.ls error="server returned 404: 404 page not found\n"16432026/09/23 13:29:38 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16442026/09/23 13:29:38 WARN Failed to register uploaded object key=jy3i2h80mk8hai8krwhlv8vc9xrhfr4b.ls error="server returned 404: 404 page not found\n"1645--- PASS: TestCacheStatsHandler (0.69s)16462026/09/23 13:29:38 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1647=== CONT TestGenerateLandingPage16482026/09/23 13:29:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16492026/09/23 13:29:38 WARN Failed to register uploaded object key=0hc29nfxwwfb5rc5p7l3dpf9qnpx0srs.ls error="server returned 404: 404 page not found\n"16502026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.78ms)16512026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000016522026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (5.31ms)16532026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000016542026/09/23 13:29:38 INFO Signed narinfos id=3 count=116552026/09/23 13:29:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16562026/09/23 13:29:38 WARN Failed to register uploaded object key=l8xkl9223kbhl342xc3ghqclvzk4v3pb.narinfo error="server returned 404: 404 page not found\n"16572026/09/23 13:29:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16582026-09-23 13:29:38.819 UTC [752] ERROR: relation "goose_db_version" does not exist at character 3616592026-09-23 13:29:38.819 UTC [752] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1660--- PASS: TestGenerateLandingPage (0.00s)1661=== CONT TestMultipartCleanup16622026/09/23 13:29:38 INFO Signed narinfos id=1 count=116632026/09/23 13:29:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16642026/09/23 13:29:38 INFO Signed narinfos id=2 count=116652026/09/23 13:29:38 INFO Uploading 3 narinfos16662026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.4ms)16672026/09/23 13:29:38 OK 1_commit_pending_closure.sql (4.69ms)16682026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.78ms)16692026/09/23 13:29:38 WARN Failed to register uploaded object key=jy3i2h80mk8hai8krwhlv8vc9xrhfr4b.narinfo error="server returned 404: 404 page not found\n"16702026/09/23 13:29:38 WARN Failed to register uploaded object key=zw8j8ck9ajlvm21xvm27yx4f8cwsy22v.narinfo error="server returned 404: 404 page not found\n"16712026/09/23 13:29:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16722026/09/23 13:29:38 WARN Failed to register uploaded object key=0hc29nfxwwfb5rc5p7l3dpf9qnpx0srs.narinfo error="server returned 404: 404 page not found\n"16732026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.88ms)16742026/09/23 13:29:38 OK 3_commit_push.sql (2.57ms)16752026/09/23 13:29:38 goose: up to current file version: 316762026/09/23 13:29:38 INFO Completed upload id=116772026/09/23 13:29:38 INFO Upload complete. (96ms)16782026/09/23 13:29:38 OK 3_commit_push.sql (3.38ms)16792026/09/23 13:29:38 goose: up to current file version: 31680=== NAME TestClientCADerivations1681 client_ca_test.go:139: Found 1 dependencies (including self)16822026/09/23 13:29:38 INFO Completed upload id=116832026/09/23 13:29:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16842026/09/23 13:29:38 INFO Completed upload id=216852026/09/23 13:29:38 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16862026/09/23 13:29:38 INFO Completed upload id=316872026/09/23 13:29:38 OK 20241026095416_initial_model.sql (10.19ms)16882026/09/23 13:29:38 INFO Upload complete. (104ms)1689=== NAME TestClientMultipleUploads1690 client_integration_test.go:369: Uploaded 3 paths in 138.814137ms16912026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)16922026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.72ms)1693--- PASS: TestReadProxyNarStreaming (0.68s)1694=== CONT TestNARDeduplicationMetadataUploadBug16952026-09-23 13:29:38.846 UTC [773] ERROR: relation "goose_db_version" does not exist at character 3616962026-09-23 13:29:38.846 UTC [773] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1697--- PASS: TestClientMultipleUploads (0.97s)1698=== CONT TestCreatePendingClosureRejectsOversizedNAR16992026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures1700--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1701=== CONT TestServerTLSConfig1702=== RUN TestServerTLSConfig/no_client_CA1703=== PAUSE TestServerTLSConfig/no_client_CA1704=== RUN TestServerTLSConfig/missing_CA_file1705=== PAUSE TestServerTLSConfig/missing_CA_file1706=== RUN TestServerTLSConfig/not_a_PEM_file1707=== PAUSE TestServerTLSConfig/not_a_PEM_file1708=== CONT TestCacheConfigHandlerMaxNarSize1709--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1710=== CONT TestService_NativeMTLS17112026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)17122026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.28ms)17132026/09/23 13:29:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44467/oidc17142026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.31ms)17152026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.27ms)17162026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000017172026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.9ms)17182026/09/23 13:29:38 OK 20241026095416_initial_model.sql (12.91ms)17192026/09/23 13:29:38 INFO All 1 paths already cached17202026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.65ms)1721=== NAME TestClientIntegration1722 client_integration_test.go:312: Retrieved narinfo from S3:1723 StorePath: /build/TestClientIntegration792880673/002/store/l8xkl9223kbhl342xc3ghqclvzk4v3pb-test-file.txt1724 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1725 Compression: zstd1726 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11727 NarSize: 1521728 References: 1729 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117302026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)17312026/09/23 13:29:38 OK 3_commit_push.sql (1.78ms)17322026/09/23 13:29:38 goose: up to current file version: 317332026/09/23 13:29:38 INFO lead: acquired remote=192.0.2.1:123417342026/09/23 13:29:38 INFO lead: released remote=192.0.2.1:12341735--- PASS: TestLeadEndsOnShutdown (0.68s)1736=== CONT TestPinProtectsFromGC1737=== NAME TestClientIntegration1738 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1739 client_integration_test.go:313: Decompressed .ls content (64 bytes):1740 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1741 client_integration_test.go:316: Testing garbage collection...17422026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.78ms)17432026-09-23 13:29:38.874 UTC [814] ERROR: relation "goose_db_version" does not exist at character 3617442026-09-23 13:29:38.874 UTC [814] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17452026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (12.65ms)17462026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.68ms)17472026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.89ms)17482026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.58ms)17492026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000017502026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.42ms)17512026/09/23 13:29:38 OK 20241026095416_initial_model.sql (13.97ms)17522026-09-23 13:29:38.904 UTC [836] ERROR: relation "goose_db_version" does not exist at character 3617532026-09-23 13:29:38.904 UTC [836] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17542026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.28ms)17552026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)17562026/09/23 13:29:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures17572026/09/23 13:29:38 OK 3_commit_push.sql (2.41ms)17582026/09/23 13:29:38 goose: up to current file version: 317592026/09/23 13:29:38 INFO Garbage collection started17602026/09/23 13:29:38 OK 20251218171726_add_pins.sql (5.84ms)1761--- PASS: TestGCBugBareHashReferences (0.98s)1762=== CONT TestClientPushesUseOnePush17632026/09/23 13:29:38 INFO Aborted multipart uploads count=017642026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (5.28ms)1765--- PASS: TestReadProxyNarinfo (0.65s)1766=== CONT TestClientSharedPathCommittedMidPush17672026/09/23 13:29:38 WARN Force mode enabled - objects will be deleted immediately without grace period17682026/09/23 13:29:38 OK 20260905000000_add_claims.sql (5.45ms)17692026/09/23 13:29:38 OK 20241026095416_initial_model.sql (12.8ms)17702026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (2.8ms)17712026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)17722026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.59ms)17732026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000017742026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.06ms)17752026-09-23 13:29:38.931 UTC [860] ERROR: relation "goose_db_version" does not exist at character 3617762026-09-23 13:29:38.931 UTC [860] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17772026-09-23 13:29:38.932 UTC [861] ERROR: relation "goose_db_version" does not exist at character 3617782026-09-23 13:29:38.932 UTC [861] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17792026/09/23 13:29:38 OK 1_commit_pending_closure.sql (3.54ms)17802026/09/23 13:29:38 INFO Received uploads request method=POST path=/api/pending_closures17812026-09-23 13:29:38.941 UTC [879] ERROR: relation "goose_db_version" does not exist at character 3617822026-09-23 13:29:38.941 UTC [879] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17832026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (11.48ms)17842026/09/23 13:29:38 OK 2_object_stats_trigger.sql (10.94ms)17852026/09/23 13:29:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17862026/09/23 13:29:38 INFO Uploading 32xh09gcf2v9w6ccn1gfxmiamfhxmysh-ca-test (144B)17872026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.57ms)17882026/09/23 13:29:38 OK 3_commit_push.sql (2.44ms)17892026/09/23 13:29:38 goose: up to current file version: 317902026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.59ms)1791--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.68s)1792=== CONT TestClientWithDependencies17932026/09/23 13:29:38 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17942026/09/23 13:29:38 WARN Failed to register uploaded object key=32xh09gcf2v9w6ccn1gfxmiamfhxmysh.ls error="server returned 404: 404 page not found\n"17952026/09/23 13:29:38 WARN Failed to register uploaded object key=log/2wf0c1y352cl10i9v4xw1wqr1m0bniqp-ca-test.drv error="server returned 404: 404 page not found\n"17962026/09/23 13:29:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17972026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.1ms)17982026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000017992026/09/23 13:29:38 INFO Signed narinfos id=1 count=118002026/09/23 13:29:38 INFO Uploading 1 narinfos18012026/09/23 13:29:38 OK 1_commit_pending_closure.sql (2.96ms)18022026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2ms)18032026/09/23 13:29:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18042026/09/23 13:29:38 WARN Failed to register uploaded object key=32xh09gcf2v9w6ccn1gfxmiamfhxmysh.narinfo error="server returned 404: 404 page not found\n"18052026/09/23 13:29:38 OK 20241026095416_initial_model.sql (12.68ms)18062026/09/23 13:29:38 OK 20241026095416_initial_model.sql (15.45ms)18072026/09/23 13:29:38 OK 3_commit_push.sql (2.42ms)18082026/09/23 13:29:38 goose: up to current file version: 318092026/09/23 13:29:38 OK 20241026095416_initial_model.sql (16.3ms)18102026-09-23 13:29:38.962 UTC [881] ERROR: relation "goose_db_version" does not exist at character 3618112026-09-23 13:29:38.962 UTC [881] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18122026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)18132026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)18142026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)18152026/09/23 13:29:38 INFO Completed upload id=118162026/09/23 13:29:38 INFO Upload complete. (105ms)18172026/09/23 13:29:38 OK 20251218171726_add_pins.sql (5.07ms)18182026/09/23 13:29:38 OK 20251218171726_add_pins.sql (6.04ms)18192026/09/23 13:29:38 OK 20251218171726_add_pins.sql (6.62ms)1820=== NAME TestClientCADerivations1821 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2012390629/001/store/32xh09gcf2v9w6ccn1gfxmiamfhxmysh-ca-test1822 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1823 Compression: zstd1824 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1825 NarSize: 1441826 References: 1827 Deriver: /build/TestClientCADerivations2012390629/001/store/2wf0c1y352cl10i9v4xw1wqr1m0bniqp-ca-test.drv1828 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1829 client_ca_test.go:185: Checking for realisation files in S3...1830 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1831 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18322026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (5.89ms)18332026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (6.06ms)18342026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (5.87ms)1835--- PASS: TestService_ReadAuthMiddleware (0.66s)1836=== CONT TestService_readinessHandler18372026/09/23 13:29:38 OK 20260905000000_add_claims.sql (4.94ms)18382026/09/23 13:29:38 OK 20241026095416_initial_model.sql (12.7ms)18392026/09/23 13:29:38 OK 20260905000000_add_claims.sql (6.18ms)18402026/09/23 13:29:38 OK 20260905000000_add_claims.sql (5ms)18412026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.47ms)18422026/09/23 13:29:38 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)18432026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (3.71ms)18442026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.02ms)18452026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000018462026/09/23 13:29:38 OK 20260920000000_drop_claims.sql (4.78ms)18472026/09/23 13:29:38 OK 20251218171726_add_pins.sql (4.29ms)18482026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.12ms)18492026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000018502026/09/23 13:29:38 OK 1_commit_pending_closure.sql (4ms)18512026/09/23 13:29:38 OK 20260923120000_add_pushes.sql (3.29ms)18522026/09/23 13:29:38 goose: successfully migrated database to version: 2026092312000018532026/09/23 13:29:38 OK 2_object_stats_trigger.sql (1.59ms)18542026/09/23 13:29:38 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)18552026/09/23 13:29:38 OK 1_commit_pending_closure.sql (2.72ms)18562026/09/23 13:29:38 OK 1_commit_pending_closure.sql (2.16ms)18572026/09/23 13:29:38 OK 3_commit_push.sql (1.39ms)18582026/09/23 13:29:38 goose: up to current file version: 318592026/09/23 13:29:38 OK 2_object_stats_trigger.sql (2.51ms)18602026/09/23 13:29:38 OK 2_object_stats_trigger.sql (3.19ms)18612026/09/23 13:29:38 OK 3_commit_push.sql (2.14ms)18622026/09/23 13:29:38 goose: up to current file version: 318632026/09/23 13:29:38 OK 20260905000000_add_claims.sql (5.07ms)18642026-09-23 13:29:38.999 UTC [886] ERROR: relation "goose_db_version" does not exist at character 3618652026-09-23 13:29:38.999 UTC [886] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18662026/09/23 13:29:38 OK 3_commit_push.sql (1.92ms)18672026/09/23 13:29:38 goose: up to current file version: 318682026-09-23 13:29:38.999 UTC [887] ERROR: relation "goose_db_version" does not exist at character 3618692026-09-23 13:29:38.999 UTC [887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18702026/09/23 13:29:39 OK 20260920000000_drop_claims.sql (3.73ms)18712026/09/23 13:29:39 OK 20260923120000_add_pushes.sql (2.99ms)18722026/09/23 13:29:39 goose: successfully migrated database to version: 2026092312000018732026/09/23 13:29:39 OK 1_commit_pending_closure.sql (2.89ms)18742026/09/23 13:29:39 OK 2_object_stats_trigger.sql (2.12ms)18752026/09/23 13:29:39 OK 3_commit_push.sql (3.28ms)18762026/09/23 13:29:39 goose: up to current file version: 318772026/09/23 13:29:39 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18782026/09/23 13:29:39 WARN mTLS auth: bound subjects configured but subject DN unavailable18792026/09/23 13:29:39 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1880--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.66s)1881=== CONT TestService_healthCheckHandler18822026/09/23 13:29:39 OK 20241026095416_initial_model.sql (11.69ms)18832026/09/23 13:29:39 OK 20241026095416_initial_model.sql (12.67ms)18842026/09/23 13:29:39 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)18852026/09/23 13:29:39 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)18862026/09/23 13:29:39 OK 20251218171726_add_pins.sql (9.85ms)18872026/09/23 13:29:39 OK 20251218171726_add_pins.sql (10.87ms)18882026/09/23 13:29:39 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)18892026-09-23 13:29:39.036 UTC [908] ERROR: relation "goose_db_version" does not exist at character 3618902026-09-23 13:29:39.036 UTC [908] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18912026/09/23 13:29:39 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)18922026/09/23 13:29:39 OK 20260905000000_add_claims.sql (4.04ms)18932026/09/23 13:29:39 OK 20260905000000_add_claims.sql (4.96ms)18942026/09/23 13:29:39 OK 20260920000000_drop_claims.sql (4.35ms)18952026/09/23 13:29:39 OK 20260920000000_drop_claims.sql (3.02ms)18962026/09/23 13:29:39 OK 20260923120000_add_pushes.sql (2.88ms)18972026/09/23 13:29:39 goose: successfully migrated database to version: 2026092312000018982026/09/23 13:29:39 OK 20260923120000_add_pushes.sql (3.4ms)18992026/09/23 13:29:39 goose: successfully migrated database to version: 2026092312000019002026/09/23 13:29:39 OK 1_commit_pending_closure.sql (2.49ms)19012026/09/23 13:29:39 INFO Starting HTTP server address=127.0.0.1:3509319022026/09/23 13:29:39 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1037701571/001/proxy.sock19032026/09/23 13:29:39 OK 1_commit_pending_closure.sql (3.16ms)19042026/09/23 13:29:39 WARN mTLS auth: subject not in bound subjects subject="CN=someone"19052026-09-23 13:29:39.052 UTC [941] ERROR: relation "goose_db_version" does not exist at character 3619062026-09-23 13:29:39.052 UTC [941] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19072026/09/23 13:29:39 INFO Shutdown signal received, draining in-flight requests timeout=10s19082026/09/23 13:29:39 OK 2_object_stats_trigger.sql (3.43ms)1909--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.67s)1910=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle19112026/09/23 13:29:39 OK 2_object_stats_trigger.sql (2.22ms)19122026/09/23 13:29:39 OK 20241026095416_initial_model.sql (10.42ms)19132026/09/23 13:29:39 OK 3_commit_push.sql (1.99ms)19142026/09/23 13:29:39 goose: up to current file version: 319152026/09/23 13:29:39 OK 3_commit_push.sql (1.59ms)19162026/09/23 13:29:39 goose: up to current file version: 319172026/09/23 13:29:39 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)19182026/09/23 13:29:39 OK 20251218171726_add_pins.sql (3.59ms)19192026/09/23 13:29:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19202026/09/23 13:29:39 OK 20260628120000_add_object_size_and_stats.sql (4.7ms)19212026/09/23 13:29:39 OK 20260905000000_add_claims.sql (3.95ms)19222026/09/23 13:29:39 OK 20260920000000_drop_claims.sql (2.83ms)19232026/09/23 13:29:39 OK 20260923120000_add_pushes.sql (3.12ms)19242026/09/23 13:29:39 goose: successfully migrated database to version: 2026092312000019252026/09/23 13:29:39 OK 1_commit_pending_closure.sql (3.29ms)1926--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.68s)1927=== CONT TestProxyWriteTimeout1928=== RUN TestProxyWriteTimeout/narinfo1929=== PAUSE TestProxyWriteTimeout/narinfo1930=== RUN TestProxyWriteTimeout/1_GiB_nar1931=== PAUSE TestProxyWriteTimeout/1_GiB_nar1932=== RUN TestProxyWriteTimeout/10_GiB_nar1933=== PAUSE TestProxyWriteTimeout/10_GiB_nar1934=== RUN TestProxyWriteTimeout/unknown_size1935=== PAUSE TestProxyWriteTimeout/unknown_size1936=== CONT TestClientFallsBackToClosures19372026/09/23 13:29:39 OK 2_object_stats_trigger.sql (2.53ms)19382026/09/23 13:29:39 OK 20241026095416_initial_model.sql (21.82ms)19392026/09/23 13:29:39 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTk5ODFmMzYtNGMyZS00OWY2LWE4YWItZDIwNTYxOTFiZTBjLjIyYWFmNjZhLTgzNTAtNDg4NC1iMDllLTg3YzZlNzdiYTg1ZXgxNzkwMTcwMTc4NTMxMzE4NTcy parts=1019402026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19412026/09/23 13:29:39 OK 3_commit_push.sql (2.62ms)19422026/09/23 13:29:39 goose: up to current file version: 319432026/09/23 13:29:39 OK 20251210153512_drop_unused_gin_index.sql (4.21ms)19442026/09/23 13:29:39 INFO Completed upload id=119452026/09/23 13:29:39 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000019462026/09/23 13:29:39 OK 20251218171726_add_pins.sql (4.95ms)19472026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures19482026/09/23 13:29:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures19492026-09-23 13:29:39.095 UTC [1011] ERROR: relation "goose_db_version" does not exist at character 3619502026-09-23 13:29:39.095 UTC [1011] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19512026/09/23 13:29:39 OK 20260628120000_add_object_size_and_stats.sql (5.88ms)19522026/09/23 13:29:39 OK 20260905000000_add_claims.sql (5.17ms)19532026/09/23 13:29:39 INFO Aborted multipart uploads count=01954=== NAME TestClientCADerivations1955 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1956 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1957 error: binary cache 's3://bucket31?endpoint=http://localhost:32831®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2012390629/001/store'1958 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 119592026/09/23 13:29:39 OK 20260920000000_drop_claims.sql (5.16ms)19602026/09/23 13:29:39 OK 20260923120000_add_pushes.sql (3.86ms)19612026/09/23 13:29:39 goose: successfully migrated database to version: 202609231200001962--- PASS: TestClientCADerivations (1.12s)1963=== CONT TestIsValidUploadKey/narinfo1964=== CONT TestIsValidUploadKey/realisation_plus_in_output1965=== CONT TestIsValidUploadKey/unknown_type1966=== CONT TestIsValidUploadKey/empty_key1967=== CONT TestIsValidUploadKey/absolute1968=== CONT TestIsValidUploadKey/traversal_nar1969=== CONT TestIsValidUploadKey/traversal1970=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1971=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1972=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1973=== CONT TestIsValidUploadKey/index.html1974=== CONT TestIsValidUploadKey/nix-cache-info1975=== CONT TestIsValidUploadKey/nar_plain1976=== CONT TestIsValidUploadKey/build_log1977=== CONT TestIsValidUploadKey/listing1978=== CONT TestIsValidUploadKey/build_log_equals1979=== CONT TestIsValidUploadKey/realisation1980=== CONT TestIsValidUploadKey/build_log_question_mark1981=== CONT TestIsValidUploadKey/build_log_home-manager_file1982=== CONT TestIsValidUploadKey/build_log_plus_in_name1983=== CONT TestIsValidUploadKey/nar_zst1984=== CONT TestIsValidUploadKey/nar_xz1985--- PASS: TestIsValidUploadKey (0.00s)1986 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1987 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1988 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1989 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1990 --- PASS: TestIsValidUploadKey/absolute (0.00s)1991 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1992 --- PASS: TestIsValidUploadKey/traversal (0.00s)1993 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1994 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1995 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1996 --- PASS: TestIsValidUploadKey/index.html (0.00s)1997 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1998 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1999 --- PASS: TestIsValidUploadKey/build_log (0.00s)2000 --- PASS: TestIsValidUploadKey/listing (0.00s)2001 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2002 --- PASS: TestIsValidUploadKey/realisation (0.00s)2003 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2004 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2005 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2006 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2007 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2008=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20092026/09/23 13:29:39 INFO Received uploads request method=POST path=/20102026/09/23 13:29:39 INFO lead: acquired remote=192.0.2.1:123420112026/09/23 13:29:39 OK 1_commit_pending_closure.sql (3.8ms)20122026/09/23 13:29:39 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=020132026/09/23 13:29:39 OK 20241026095416_initial_model.sql (15.75ms)20142026/09/23 13:29:39 OK 2_object_stats_trigger.sql (3.09ms)20152026/09/23 13:29:39 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)20162026/09/23 13:29:39 INFO Vacuumed table table=pending_closures20172026/09/23 13:29:39 OK 3_commit_push.sql (2.74ms)20182026/09/23 13:29:39 goose: up to current file version: 320192026/09/23 13:29:39 INFO Vacuumed table table=pending_objects20202026/09/23 13:29:39 OK 20251218171726_add_pins.sql (5.02ms)20212026/09/23 13:29:39 INFO Vacuumed table table=multipart_uploads20222026/09/23 13:29:39 INFO Vacuumed table table=closures20232026/09/23 13:29:39 OK 20260628120000_add_object_size_and_stats.sql (5.32ms)20242026/09/23 13:29:39 INFO Vacuumed table table=objects20252026-09-23 13:29:39.132 UTC [1014] ERROR: relation "goose_db_version" does not exist at character 3620262026-09-23 13:29:39.132 UTC [1014] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20272026/09/23 13:29:39 OK 20260905000000_add_claims.sql (4.56ms)20282026/09/23 13:29:39 OK 20260920000000_drop_claims.sql (4.46ms)20292026/09/23 13:29:39 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002030--- PASS: TestService_createPendingClosureHandler (1.79s)2031=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20322026/09/23 13:29:39 INFO Received request for more parts method=POST path=/20332026/09/23 13:29:39 OK 20260923120000_add_pushes.sql (9.62ms)20342026/09/23 13:29:39 goose: successfully migrated database to version: 2026092312000020352026/09/23 13:29:39 OK 20241026095416_initial_model.sql (12.37ms)20362026/09/23 13:29:39 OK 1_commit_pending_closure.sql (2.3ms)20372026/09/23 13:29:39 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)20382026/09/23 13:29:39 OK 2_object_stats_trigger.sql (1.09ms)20392026/09/23 13:29:39 OK 3_commit_push.sql (942.41µs)20402026/09/23 13:29:39 goose: up to current file version: 320412026/09/23 13:29:39 OK 20251218171726_add_pins.sql (2.85ms)20422026/09/23 13:29:39 OK 20260628120000_add_object_size_and_stats.sql (3.45ms)20432026-09-23 13:29:39.160 UTC [1015] ERROR: relation "goose_db_version" does not exist at character 3620442026-09-23 13:29:39.160 UTC [1015] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20452026/09/23 13:29:39 OK 20260905000000_add_claims.sql (2.57ms)20462026/09/23 13:29:39 OK 20260920000000_drop_claims.sql (1.88ms)20472026/09/23 13:29:39 OK 20260923120000_add_pushes.sql (2.52ms)20482026/09/23 13:29:39 goose: successfully migrated database to version: 2026092312000020492026/09/23 13:29:39 OK 1_commit_pending_closure.sql (1.78ms)20502026/09/23 13:29:39 OK 2_object_stats_trigger.sql (895.63µs)20512026/09/23 13:29:39 OK 3_commit_push.sql (1.08ms)20522026/09/23 13:29:39 goose: up to current file version: 320532026/09/23 13:29:39 OK 20241026095416_initial_model.sql (9.07ms)20542026/09/23 13:29:39 OK 20251210153512_drop_unused_gin_index.sql (1.23ms)20552026/09/23 13:29:39 OK 20251218171726_add_pins.sql (3.34ms)20562026/09/23 13:29:39 OK 20260628120000_add_object_size_and_stats.sql (2.68ms)20572026/09/23 13:29:39 OK 20260905000000_add_claims.sql (2.79ms)20582026/09/23 13:29:39 OK 20260920000000_drop_claims.sql (1.77ms)20592026/09/23 13:29:39 OK 20260923120000_add_pushes.sql (1.34ms)20602026/09/23 13:29:39 goose: successfully migrated database to version: 2026092312000020612026/09/23 13:29:39 OK 1_commit_pending_closure.sql (1.84ms)2062--- PASS: TestResurrectedObjectNotDeleted (0.69s)2063=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20642026/09/23 13:29:39 INFO Received complete multipart upload request method=POST path=/20652026/09/23 13:29:39 OK 2_object_stats_trigger.sql (1.03ms)20662026/09/23 13:29:39 OK 3_commit_push.sql (1.21ms)20672026/09/23 13:29:39 goose: up to current file version: 320682026/09/23 13:29:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20692026/09/23 13:29:39 WARN Refused reserved pin name=worker-x86_64-linux20702026/09/23 13:29:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20712026/09/23 13:29:39 INFO Received create pin request method=POST path=/api/pins/my-app20722026/09/23 13:29:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2073--- PASS: TestCreatePin_ReservedPins (0.78s)2074=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20752026/09/23 13:29:39 INFO Received uploads request method=POST path=/2076=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20772026/09/23 13:29:39 INFO Received complete multipart upload request method=POST path=/2078=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20792026/09/23 13:29:39 INFO Received request for more parts method=POST path=/2080=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20812026/09/23 13:29:39 INFO Received uploads request method=POST path=/2082--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2083 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2084 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2085 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2086 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2087=== CONT TestClientErrorHandling/InvalidStorePath2088--- PASS: TestMetricsInventory (0.56s)2089=== CONT TestClientErrorHandling/InvalidAuthToken2090=== CONT TestClientErrorHandling/ServerNotAvailable2091--- PASS: TestService_ReadScope_PublicByDefault (0.57s)2092=== CONT TestPush_RejectsBadRequests/no_roots20932026/09/23 13:29:39 INFO Received push request method=POST path=/api/pushes2094=== CONT TestPush_RejectsBadRequests/bad_root20952026/09/23 13:29:39 INFO Received push request method=POST path=/api/pushes2096=== CONT TestPush_RejectsBadRequests/root_not_in_objects20972026/09/23 13:29:39 INFO Received push request method=POST path=/api/pushes2098=== CONT TestPush_RejectsBadRequests/no_objects20992026/09/23 13:29:39 INFO Received push request method=POST path=/api/pushes2100=== CONT TestIsValidCachePath/narinfo2101=== CONT TestIsValidCachePath/index.html2102=== CONT TestIsValidCachePath/short_hash2103=== CONT TestIsValidCachePath/wrong_extension2104=== CONT TestIsValidCachePath/leading_slash2105=== CONT TestIsValidCachePath/invalid_char_e2106--- PASS: TestPush_RejectsBadRequests (0.82s)2107 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2108 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2109 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2110 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2111=== CONT TestIsValidCachePath/traversal_in_middle2112=== CONT TestIsValidCachePath/traversal_parent2113=== CONT TestIsValidCachePath/empty2114=== CONT TestIsValidCachePath/random_path2115=== CONT TestIsValidCachePath/nar_uncompressed2116=== CONT TestIsValidCachePath/nix-cache-info2117=== CONT TestIsValidCachePath/invalid_char_u2118=== CONT TestIsValidCachePath/realisation2119=== CONT TestIsValidCachePath/ls2120=== CONT TestIsValidCachePath/log2121=== CONT TestIsValidCachePath/nar_xz2122=== CONT TestIsValidCachePath/nar_bz22123=== CONT TestIsValidCachePath/nar_zst2124=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2125--- PASS: TestIsValidCachePath (0.00s)2126 --- PASS: TestIsValidCachePath/narinfo (0.00s)2127 --- PASS: TestIsValidCachePath/index.html (0.00s)2128 --- PASS: TestIsValidCachePath/short_hash (0.00s)2129 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2130 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2131 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2132 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2133 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2134 --- PASS: TestIsValidCachePath/empty (0.00s)2135 --- PASS: TestIsValidCachePath/random_path (0.00s)2136 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2137 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2138 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2139 --- PASS: TestIsValidCachePath/realisation (0.00s)2140 --- PASS: TestIsValidCachePath/ls (0.00s)2141 --- PASS: TestIsValidCachePath/log (0.00s)2142 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2143 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2144 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2145 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2146=== CONT TestParseSingleRange/none2147=== CONT TestParseSingleRange/start_past_EOF2148=== CONT TestParseSingleRange/single_byte2149=== CONT TestParseSingleRange/suffix_exceeds_size2150=== CONT TestParseSingleRange/suffix2151=== CONT TestParseSingleRange/end_clamped_to_size2152=== CONT TestParseSingleRange/start_far_past_EOF2153=== CONT TestParseSingleRange/open-ended2154=== CONT TestParseSingleRange/malformed_no_dash2155=== CONT TestParseSingleRange/multi-range_ignored2156=== CONT TestParseSingleRange/unknown_unit2157=== CONT TestParseSingleRange/closed2158=== CONT TestParseSingleRange/malformed_end_before_start2159=== CONT TestParseSingleRange/malformed_both_empty2160--- PASS: TestParseSingleRange (0.00s)2161 --- PASS: TestParseSingleRange/none (0.00s)2162 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2163 --- PASS: TestParseSingleRange/single_byte (0.00s)2164 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2165 --- PASS: TestParseSingleRange/suffix (0.00s)2166 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2167 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2168 --- PASS: TestParseSingleRange/open-ended (0.00s)2169 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2170 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2171 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2172 --- PASS: TestParseSingleRange/closed (0.00s)2173 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2174 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2175=== CONT TestResolveDBConnectionString/flag_wins2176=== CONT TestResolveDBConnectionString/missing_file_is_an_error2177=== CONT TestResolveDBConnectionString/file_when_flag_empty2178=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2179=== CONT TestResolveDBConnectionString/nothing_configured2180=== CONT TestCacheConfigHandler/full_config,_no_issuer2181=== CONT TestCacheConfigHandler/no_signing_keys2182=== CONT TestCacheConfigHandler/no_cache_url_configured2183=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2184--- PASS: TestCacheConfigHandler (0.00s)2185 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2186 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2187 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2188 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2189=== CONT TestServerTLSConfig/no_client_CA2190=== CONT TestServerTLSConfig/missing_CA_file2191=== CONT TestServerTLSConfig/not_a_PEM_file2192--- PASS: TestResolveDBConnectionString (0.00s)2193 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2194 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2195 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2196 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2197 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2198=== CONT TestProxyWriteTimeout/narinfo2199=== CONT TestProxyWriteTimeout/10_GiB_nar2200=== CONT TestProxyWriteTimeout/unknown_size2201=== CONT TestProxyWriteTimeout/1_GiB_nar2202--- PASS: TestServerTLSConfig (0.00s)2203 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2204 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2205 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2206--- PASS: TestProxyWriteTimeout (0.00s)2207 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2208 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2209 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2210 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)22112026/09/23 13:29:39 INFO lead: released remote=192.0.2.1:123422122026-09-23 13:29:39.298 UTC [1038] ERROR: relation "goose_db_version" does not exist at character 3622132026-09-23 13:29:39.298 UTC [1038] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22142026/09/23 13:29:39 INFO lead: acquired remote=192.0.2.1:123422152026/09/23 13:29:39 OK 20241026095416_initial_model.sql (11.12ms)22162026/09/23 13:29:39 INFO lead: released remote=192.0.2.1:12342217--- PASS: TestLeadElectsOneAndHandsOver (0.85s)22182026/09/23 13:29:39 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)22192026/09/23 13:29:39 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22202026-09-23 13:29:39.325 UTC [1057] ERROR: relation "goose_db_version" does not exist at character 3622212026-09-23 13:29:39.325 UTC [1057] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22222026/09/23 13:29:39 OK 20251218171726_add_pins.sql (7.5ms)22232026/09/23 13:29:39 OK 20260628120000_add_object_size_and_stats.sql (3.51ms)2224--- PASS: TestObjectStatsTrigger (0.57s)22252026/09/23 13:29:39 OK 20260905000000_add_claims.sql (3.93ms)22262026/09/23 13:29:39 OK 20260920000000_drop_claims.sql (2.82ms)22272026/09/23 13:29:39 OK 20260923120000_add_pushes.sql (2.64ms)22282026/09/23 13:29:39 goose: successfully migrated database to version: 2026092312000022292026/09/23 13:29:39 OK 20241026095416_initial_model.sql (9.68ms)22302026/09/23 13:29:39 OK 20251210153512_drop_unused_gin_index.sql (1.42ms)22312026/09/23 13:29:39 OK 1_commit_pending_closure.sql (1.87ms)2232=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2233=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2234=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2235=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2236=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2237=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2238=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2239=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2240=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2241=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2242=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2243=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured22442026/09/23 13:29:39 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]22452026/09/23 13:29:39 OK 2_object_stats_trigger.sql (1.4ms)22462026/09/23 13:29:39 OK 3_commit_push.sql (906.09µs)22472026/09/23 13:29:39 goose: up to current file version: 322482026/09/23 13:29:39 OK 20251218171726_add_pins.sql (2.87ms)22492026/09/23 13:29:39 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)22502026/09/23 13:29:39 WARN Authentication failed token_preview=eyJhbGciOi...Nhxo6QfhIw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2251--- PASS: TestService_AuthMiddleware_OIDC (0.70s)2252 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2253 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2254 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2255 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)22562026/09/23 13:29:39 OK 20260905000000_add_claims.sql (3.38ms)22572026/09/23 13:29:39 OK 20260920000000_drop_claims.sql (1.69ms)22582026/09/23 13:29:39 OK 20260923120000_add_pushes.sql (1.32ms)22592026/09/23 13:29:39 goose: successfully migrated database to version: 2026092312000022602026/09/23 13:29:39 OK 1_commit_pending_closure.sql (1.67ms)22612026/09/23 13:29:39 OK 2_object_stats_trigger.sql (718.37µs)22622026/09/23 13:29:39 OK 3_commit_push.sql (788.71µs)22632026/09/23 13:29:39 goose: up to current file version: 322642026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures22652026/09/23 13:29:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.53913ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2266=== RUN TestService_RequireScope_OIDC/builder_may_write2267=== PAUSE TestService_RequireScope_OIDC/builder_may_write2268=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2269=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2270=== RUN TestService_RequireScope_OIDC/ops_may_admin2271=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2272=== RUN TestService_RequireScope_OIDC/ops_may_not_write2273=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2274=== RUN TestService_RequireScope_OIDC/reader_may_not_write2275=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2276=== RUN TestService_RequireScope_OIDC/static_token_may_admin2277=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2278=== RUN TestService_RequireScope_OIDC/static_token_may_write2279=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2280=== RUN TestService_RequireScope_OIDC/reader_may_read2281=== PAUSE TestService_RequireScope_OIDC/reader_may_read2282=== RUN TestService_RequireScope_OIDC/writer_implies_read2283=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2284=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2285=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2286=== CONT TestService_RequireScope_OIDC/builder_may_write2287=== CONT TestService_RequireScope_OIDC/reader_may_read2288=== CONT TestService_RequireScope_OIDC/writer_implies_read2289=== CONT TestService_RequireScope_OIDC/ops_may_admin2290=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2291=== CONT TestService_RequireScope_OIDC/reader_may_not_write2292=== CONT TestService_RequireScope_OIDC/ops_may_not_write2293=== CONT TestService_RequireScope_OIDC/static_token_may_write2294=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2295=== CONT TestService_RequireScope_OIDC/static_token_may_admin2296--- PASS: TestService_RequireScope_OIDC (0.70s)2297 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2298 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2299 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2300 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2301 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2302 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2303 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2304 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2305 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2306 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)23072026/09/23 13:29:39 WARN mTLS auth: subject not in bound subjects subject="CN=reader"23082026/09/23 13:29:39 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2309--- PASS: TestService_NativeMTLS (0.60s)2310=== NAME TestNARDeduplicationMetadataUploadBug2311 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2452284733/001/store/fs25dap5q3iqb0y2d1ac2pnj7wcdn615-file1.txt23122026/09/23 13:29:39 INFO Received cleanup request method=DELETE path=/api/pending_closures23132026/09/23 13:29:39 INFO Aborted multipart uploads count=12314--- PASS: TestMultipartCleanup (0.68s)23152026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures23162026/09/23 13:29:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23172026/09/23 13:29:39 INFO Uploading fs25dap5q3iqb0y2d1ac2pnj7wcdn615-file1.txt (160B)23182026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"23192026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23202026/09/23 13:29:39 WARN Failed to register uploaded object key=fs25dap5q3iqb0y2d1ac2pnj7wcdn615.ls error="server returned 404: 404 page not found\n"23212026/09/23 13:29:39 INFO Signed narinfos id=1 count=123222026/09/23 13:29:39 INFO Uploading 1 narinfos2323=== NAME TestPinProtectsFromGC2324 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2232695748/001/store/ycwkjs0ajynqj436m6sfcn91d6jr8pwg-pinned-file.txt2325 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2232695748/001/store/y3j9lh8bmb41c76044yd54dd64jx270g-unpinned-file.txt23262026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23272026/09/23 13:29:39 WARN Failed to register uploaded object key=fs25dap5q3iqb0y2d1ac2pnj7wcdn615.narinfo error="server returned 404: 404 page not found\n"23282026/09/23 13:29:39 INFO Completed upload id=123292026/09/23 13:29:39 INFO Upload complete. (64ms)2330=== NAME TestNARDeduplicationMetadataUploadBug2331 metadata_upload_test.go:54: Retrieved narinfo from S3:2332 StorePath: /build/TestNARDeduplicationMetadataUploadBug2452284733/001/store/fs25dap5q3iqb0y2d1ac2pnj7wcdn615-file1.txt2333 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2334 Compression: zstd2335 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2336 NarSize: 1602337 References: 2338 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2339 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2340 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2341 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}23422026/09/23 13:29:39 WARN readiness check failed error="closed pool"2343--- PASS: TestService_readinessHandler (0.60s)2344=== NAME TestNARDeduplicationMetadataUploadBug2345 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2452284733/001/store/zknmhicss9awh9vip2m66l6zd65jf55w-file2.txt2346--- PASS: TestService_healthCheckHandler (0.59s)23472026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures23482026/09/23 13:29:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23492026/09/23 13:29:39 INFO Uploading ycwkjs0ajynqj436m6sfcn91d6jr8pwg-pinned-file.txt (128B)23502026/09/23 13:29:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.595266ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2351=== NAME TestOrphanedObjectsGC2352 orphaned_objects_gc_test.go:290: GC Test Summary:2353 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2354 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2355 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2356 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2357 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2358--- PASS: TestOrphanedObjectsGC (0.88s)23592026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"23602026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23612026/09/23 13:29:39 WARN Failed to register uploaded object key=ycwkjs0ajynqj436m6sfcn91d6jr8pwg.ls error="server returned 404: 404 page not found\n"23622026/09/23 13:29:39 INFO Signed narinfos id=1 count=123632026/09/23 13:29:39 INFO Uploading 1 narinfos23642026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures23652026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23662026/09/23 13:29:39 WARN Failed to register uploaded object key=ycwkjs0ajynqj436m6sfcn91d6jr8pwg.narinfo error="server returned 404: 404 page not found\n"2367=== NAME TestClientWithDependencies2368 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies4038484331/001/store/184s22ar94gqyag56a2qz13xql38sklp-test-script23692026/09/23 13:29:39 INFO Completed upload id=123702026/09/23 13:29:39 INFO Upload complete. (58ms)23712026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures23722026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures23732026/09/23 13:29:39 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)2374 client_integration_test.go:615: Found 1 dependencies (including self)23752026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures23762026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures23772026/09/23 13:29:39 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)23782026/09/23 13:29:39 INFO Uploading 39ir2fl3f3p9a9wzdravr4yc8jy8dawf-shared-dep (136B)23792026/09/23 13:29:39 INFO Uploading iqvj7ra3kjqkz8zqy43pjscn88v5r102-a (208B)23802026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign23812026/09/23 13:29:39 WARN Failed to register uploaded object key=zknmhicss9awh9vip2m66l6zd65jf55w.ls error="server returned 404: 404 page not found\n"23822026/09/23 13:29:39 INFO Signed narinfos id=2 count=123832026/09/23 13:29:39 INFO Uploading 1 narinfos23842026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/0dvgi7nc11fs06v3k41j7kw73k1j575361srx2ssvz154jylqhqp.nar.zst error="server returned 404: 404 page not found\n"23852026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23862026/09/23 13:29:39 WARN Failed to register uploaded object key=8b7hmhfx8kafmgknrxav6n80vlfbi02z.ls error="server returned 404: 404 page not found\n"23872026/09/23 13:29:39 WARN Failed to register uploaded object key=39ir2fl3f3p9a9wzdravr4yc8jy8dawf.ls error="server returned 404: 404 page not found\n"23882026/09/23 13:29:39 WARN Failed to register uploaded object key=zknmhicss9awh9vip2m66l6zd65jf55w.narinfo error="server returned 404: 404 page not found\n"23892026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23902026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23912026/09/23 13:29:39 WARN Failed to register uploaded object key=iqvj7ra3kjqkz8zqy43pjscn88v5r102.ls error="server returned 404: 404 page not found\n"23922026/09/23 13:29:39 INFO Signed narinfos id=1 count=223932026/09/23 13:29:39 INFO Completed upload id=223942026/09/23 13:29:39 INFO Upload complete. (54ms)23952026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign23962026/09/23 13:29:39 INFO Signed narinfos id=2 count=223972026/09/23 13:29:39 INFO Uploading 4 narinfos2398=== NAME TestNARDeduplicationMetadataUploadBug2399 metadata_upload_test.go:76: Retrieved narinfo from S3:2400 StorePath: /build/TestNARDeduplicationMetadataUploadBug2452284733/001/store/zknmhicss9awh9vip2m66l6zd65jf55w-file2.txt2401 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2402 Compression: zstd2403 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2404 NarSize: 1602405 References: 2406 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2407 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2408 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2409 {"version":1,"root":{"type":"regular","size":44}}24102026/09/23 13:29:39 WARN Failed to register uploaded object key=39ir2fl3f3p9a9wzdravr4yc8jy8dawf.narinfo error="server returned 404: 404 page not found\n"24112026/09/23 13:29:39 WARN Failed to register uploaded object key=8b7hmhfx8kafmgknrxav6n80vlfbi02z.narinfo error="server returned 404: 404 page not found\n"24122026/09/23 13:29:39 WARN Failed to register uploaded object key=iqvj7ra3kjqkz8zqy43pjscn88v5r102.narinfo error="server returned 404: 404 page not found\n"24132026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24142026/09/23 13:29:39 WARN Failed to register uploaded object key=39ir2fl3f3p9a9wzdravr4yc8jy8dawf.narinfo error="server returned 404: 404 page not found\n"2415--- PASS: TestNARDeduplicationMetadataUploadBug (0.86s)24162026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures24172026/09/23 13:29:39 INFO Completed upload id=124182026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24192026/09/23 13:29:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24202026/09/23 13:29:39 INFO Uploading y3j9lh8bmb41c76044yd54dd64jx270g-unpinned-file.txt (128B)24212026/09/23 13:29:39 INFO Completed upload id=224222026/09/23 13:29:39 INFO Upload complete. (72ms)2423=== NAME TestClientPushesUseOnePush2424 client_pushes_test.go:97: Retrieved narinfo from S3:2425 StorePath: /build/TestClientPushesUseOnePush389427748/001/store/39ir2fl3f3p9a9wzdravr4yc8jy8dawf-shared-dep2426 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2427 Compression: zstd2428 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822429 NarSize: 1362430 References: 2431 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2432 client_pushes_test.go:97: Retrieved narinfo from S3:2433 StorePath: /build/TestClientPushesUseOnePush389427748/001/store/iqvj7ra3kjqkz8zqy43pjscn88v5r102-a2434 URL: nar/0dvgi7nc11fs06v3k41j7kw73k1j575361srx2ssvz154jylqhqp.nar.zst2435 Compression: zstd2436 NarHash: sha256:0dvgi7nc11fs06v3k41j7kw73k1j575361srx2ssvz154jylqhqp2437 NarSize: 2082438 References: /build/TestClientPushesUseOnePush389427748/001/store/39ir2fl3f3p9a9wzdravr4yc8jy8dawf-shared-dep2439 CA: text:sha256:17n4wksqabj4iqc212gg21ch9jxk57ym7723wx381h3mlfrmj3aq24402026/09/23 13:29:39 WARN Failed to register uploaded object key=y3j9lh8bmb41c76044yd54dd64jx270g.ls error="server returned 404: 404 page not found\n"24412026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"24422026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign24432026/09/23 13:29:39 INFO Signed narinfos id=2 count=124442026/09/23 13:29:39 INFO Uploading 1 narinfos2445 client_pushes_test.go:97: Retrieved narinfo from S3:2446 StorePath: /build/TestClientPushesUseOnePush389427748/001/store/8b7hmhfx8kafmgknrxav6n80vlfbi02z-b2447 URL: nar/0dvgi7nc11fs06v3k41j7kw73k1j575361srx2ssvz154jylqhqp.nar.zst2448 Compression: zstd2449 NarHash: sha256:0dvgi7nc11fs06v3k41j7kw73k1j575361srx2ssvz154jylqhqp2450 NarSize: 2082451 References: /build/TestClientPushesUseOnePush389427748/001/store/39ir2fl3f3p9a9wzdravr4yc8jy8dawf-shared-dep2452 CA: text:sha256:17n4wksqabj4iqc212gg21ch9jxk57ym7723wx381h3mlfrmj3aq2453 client_pushes_test.go:100: POST /api/pushes calls = 0, want 12454 client_pushes_test.go:104: POST /api/pending_closures calls = 2, want 024552026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24562026/09/23 13:29:39 WARN Failed to register uploaded object key=y3j9lh8bmb41c76044yd54dd64jx270g.narinfo error="server returned 404: 404 page not found\n"24572026/09/23 13:29:39 INFO Completed upload id=224582026/09/23 13:29:39 INFO Upload complete. (51ms)2459--- FAIL: TestClientPushesUseOnePush (0.81s)24602026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures24612026/09/23 13:29:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24622026/09/23 13:29:39 INFO Uploading 184s22ar94gqyag56a2qz13xql38sklp-test-script (136B)24632026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures24642026/09/23 13:29:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24652026/09/23 13:29:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24662026/09/23 13:29:39 INFO Uploading 2f20bqgcyblwhp5vqgbrhn6vpldv92q5-shared-dep (136B)24672026/09/23 13:29:39 WARN Failed to register uploaded object key=log/fr4zq9sd12drwd2jyx7z0dcfpb885zmk-test-script.drv error="server returned 404: 404 page not found\n"24682026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"24692026/09/23 13:29:39 WARN Failed to register uploaded object key=184s22ar94gqyag56a2qz13xql38sklp.ls error="server returned 404: 404 page not found\n"24702026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign24712026/09/23 13:29:39 INFO Signed narinfos id=1 count=124722026/09/23 13:29:39 INFO Uploading 1 narinfos24732026/09/23 13:29:39 INFO Received create pin request method=POST path=/api/pins/myapp24742026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"24752026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24762026/09/23 13:29:39 WARN Failed to register uploaded object key=2f20bqgcyblwhp5vqgbrhn6vpldv92q5.ls error="server returned 404: 404 page not found\n"24772026/09/23 13:29:39 WARN Failed to register uploaded object key=184s22ar94gqyag56a2qz13xql38sklp.narinfo error="server returned 404: 404 page not found\n"24782026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign24792026/09/23 13:29:39 INFO Signed narinfos id=2 count=124802026/09/23 13:29:39 INFO Uploading 1 narinfos24812026/09/23 13:29:39 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2232695748/001/store/ycwkjs0ajynqj436m6sfcn91d6jr8pwg-pinned-file.txt narinfo_key=ycwkjs0ajynqj436m6sfcn91d6jr8pwg.narinfo24822026/09/23 13:29:39 INFO Completed upload id=124832026/09/23 13:29:39 INFO Upload complete. (53ms)24842026/09/23 13:29:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures24852026/09/23 13:29:39 INFO Garbage collection started24862026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24872026/09/23 13:29:39 WARN Failed to register uploaded object key=2f20bqgcyblwhp5vqgbrhn6vpldv92q5.narinfo error="server returned 404: 404 page not found\n"2488=== NAME TestClientWithDependencies2489 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4038484331/001/store) requires matching store prefix24902026/09/23 13:29:39 INFO Completed upload id=224912026/09/23 13:29:39 INFO Upload complete. (54ms)24922026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures24932026/09/23 13:29:39 INFO Aborted multipart uploads count=02494--- PASS: TestClientWithDependencies (0.82s)24952026/09/23 13:29:39 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)24962026/09/23 13:29:39 INFO Uploading 86d44j6ksljvgjymac0m2vy75alpdk9v-top (224B)24972026/09/23 13:29:39 INFO Uploading 2f20bqgcyblwhp5vqgbrhn6vpldv92q5-shared-dep (136B)24982026/09/23 13:29:39 WARN Force mode enabled - objects will be deleted immediately without grace period24992026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"25002026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/0kd6y1hjwprn8nd0z546zf5ypdlnwg6jr1rgs487nzq3xapgw1ks.nar.zst error="server returned 404: 404 page not found\n"25012026/09/23 13:29:39 WARN Failed to register uploaded object key=2f20bqgcyblwhp5vqgbrhn6vpldv92q5.ls error="server returned 404: 404 page not found\n"25022026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25032026/09/23 13:29:39 WARN Failed to register uploaded object key=86d44j6ksljvgjymac0m2vy75alpdk9v.ls error="server returned 404: 404 page not found\n"25042026/09/23 13:29:39 INFO Signed narinfos id=1 count=125052026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign25062026/09/23 13:29:39 INFO Signed narinfos id=3 count=125072026/09/23 13:29:39 INFO Uploading 2 narinfos25082026/09/23 13:29:39 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25092026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25102026/09/23 13:29:39 WARN Failed to register uploaded object key=86d44j6ksljvgjymac0m2vy75alpdk9v.narinfo error="server returned 404: 404 page not found\n"25112026/09/23 13:29:39 WARN Failed to register uploaded object key=2f20bqgcyblwhp5vqgbrhn6vpldv92q5.narinfo error="server returned 404: 404 page not found\n"25122026/09/23 13:29:39 INFO Completed upload id=125132026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete25142026/09/23 13:29:39 INFO Completed upload id=325152026/09/23 13:29:39 INFO Upload complete. (150ms)2516=== NAME TestClientSharedPathCommittedMidPush2517 client_integration_test.go:680: Retrieved narinfo from S3:2518 StorePath: /build/TestClientSharedPathCommittedMidPush1538228366/001/store/2f20bqgcyblwhp5vqgbrhn6vpldv92q5-shared-dep2519 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2520 Compression: zstd2521 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822522 NarSize: 1362523 References: 2524 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2525 client_integration_test.go:680: Retrieved narinfo from S3:2526 StorePath: /build/TestClientSharedPathCommittedMidPush1538228366/001/store/86d44j6ksljvgjymac0m2vy75alpdk9v-top2527 URL: nar/0kd6y1hjwprn8nd0z546zf5ypdlnwg6jr1rgs487nzq3xapgw1ks.nar.zst2528 Compression: zstd2529 NarHash: sha256:0kd6y1hjwprn8nd0z546zf5ypdlnwg6jr1rgs487nzq3xapgw1ks2530 NarSize: 2242531 References: /build/TestClientSharedPathCommittedMidPush1538228366/001/store/2f20bqgcyblwhp5vqgbrhn6vpldv92q5-shared-dep2532 CA: text:sha256:1lrd924ik81sbz82q521jmg2bz46zs9kaggq1ixhxh4xfc0amhf32533--- PASS: TestClientSharedPathCommittedMidPush (0.88s)25342026/09/23 13:29:39 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25352026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures25362026/09/23 13:29:39 INFO Received uploads request method=POST path=/api/pending_closures25372026/09/23 13:29:39 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)25382026/09/23 13:29:39 INFO Uploading j6bfyx61xia35gm7fzkav9jjqhci5acd-shared-dep (136B)25392026/09/23 13:29:39 INFO Uploading 6imszgqkbn8kdpgvm7gvskn5cfxlpi7f-a (216B)25402026/09/23 13:29:39 WARN Failed to register uploaded object key=6wnnbf8rwpfkw6b6jgf1sby2n68sjic2.ls error="server returned 404: 404 page not found\n"25412026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"25422026/09/23 13:29:39 WARN Failed to register uploaded object key=6imszgqkbn8kdpgvm7gvskn5cfxlpi7f.ls error="server returned 404: 404 page not found\n"25432026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign25442026/09/23 13:29:39 WARN Failed to register uploaded object key=j6bfyx61xia35gm7fzkav9jjqhci5acd.ls error="server returned 404: 404 page not found\n"25452026/09/23 13:29:39 INFO Signed narinfos id=2 count=225462026/09/23 13:29:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25472026/09/23 13:29:39 WARN Failed to register uploaded object key=nar/0csfx3zznsmsxk4agk2hkqjpaz7mcfd8w3c6zmjff5smf0y9vhk5.nar.zst error="server returned 404: 404 page not found\n"25482026/09/23 13:29:39 INFO Signed narinfos id=1 count=225492026/09/23 13:29:39 INFO Uploading 4 narinfos25502026/09/23 13:29:39 WARN Failed to register uploaded object key=6wnnbf8rwpfkw6b6jgf1sby2n68sjic2.narinfo error="server returned 404: 404 page not found\n"25512026/09/23 13:29:39 WARN Failed to register uploaded object key=6imszgqkbn8kdpgvm7gvskn5cfxlpi7f.narinfo error="server returned 404: 404 page not found\n"25522026/09/23 13:29:39 WARN Failed to register uploaded object key=j6bfyx61xia35gm7fzkav9jjqhci5acd.narinfo error="server returned 404: 404 page not found\n"25532026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25542026/09/23 13:29:39 WARN Failed to register uploaded object key=j6bfyx61xia35gm7fzkav9jjqhci5acd.narinfo error="server returned 404: 404 page not found\n"25552026/09/23 13:29:39 INFO Completed upload id=125562026/09/23 13:29:39 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete25572026/09/23 13:29:39 INFO Completed upload id=225582026/09/23 13:29:39 INFO Upload complete. (63ms)2559=== NAME TestClientFallsBackToClosures2560 client_pushes_test.go:112: Retrieved narinfo from S3:2561 StorePath: /build/TestClientFallsBackToClosures2311359265/001/store/j6bfyx61xia35gm7fzkav9jjqhci5acd-shared-dep2562 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2563 Compression: zstd2564 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822565 NarSize: 1362566 References: 2567 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2568 client_pushes_test.go:112: Retrieved narinfo from S3:2569 StorePath: /build/TestClientFallsBackToClosures2311359265/001/store/6imszgqkbn8kdpgvm7gvskn5cfxlpi7f-a2570 URL: nar/0csfx3zznsmsxk4agk2hkqjpaz7mcfd8w3c6zmjff5smf0y9vhk5.nar.zst2571 Compression: zstd2572 NarHash: sha256:0csfx3zznsmsxk4agk2hkqjpaz7mcfd8w3c6zmjff5smf0y9vhk52573 NarSize: 2162574 References: /build/TestClientFallsBackToClosures2311359265/001/store/j6bfyx61xia35gm7fzkav9jjqhci5acd-shared-dep2575 CA: text:sha256:09m1w26040v2ny8ha6lfbhpshaj1n2yhk8sxm6k7mxydwgnxfia12576 client_pushes_test.go:112: Retrieved narinfo from S3:2577 StorePath: /build/TestClientFallsBackToClosures2311359265/001/store/6wnnbf8rwpfkw6b6jgf1sby2n68sjic2-b2578 URL: nar/0csfx3zznsmsxk4agk2hkqjpaz7mcfd8w3c6zmjff5smf0y9vhk5.nar.zst2579 Compression: zstd2580 NarHash: sha256:0csfx3zznsmsxk4agk2hkqjpaz7mcfd8w3c6zmjff5smf0y9vhk52581 NarSize: 2162582 References: /build/TestClientFallsBackToClosures2311359265/001/store/j6bfyx61xia35gm7fzkav9jjqhci5acd-shared-dep2583 CA: text:sha256:09m1w26040v2ny8ha6lfbhpshaj1n2yhk8sxm6k7mxydwgnxfia12584--- PASS: TestClientFallsBackToClosures (0.81s)25852026/09/23 13:29:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=811.200941ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25862026/09/23 13:29:40 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=025872026/09/23 13:29:40 INFO Vacuumed table table=pending_closures25882026/09/23 13:29:40 INFO Vacuumed table table=pending_objects25892026/09/23 13:29:40 INFO Vacuumed table table=multipart_uploads25902026/09/23 13:29:40 INFO Vacuumed table table=closures25912026/09/23 13:29:40 INFO Vacuumed table table=objects2592--- PASS: TestUploadHandlersRejectOversizedBody (0.21s)2593 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.10s)2594 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.08s)2595 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.32s)2596=== NAME TestOrphanedObjectsGCStressTest2597 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2598 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion25992026/09/23 13:29:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.748074568s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26002026/09/23 13:29:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02601=== NAME TestClientIntegration2602 client_integration_test.go:323: Objects in database after GC:2603 client_integration_test.go:323: Successfully deleted all objects with GC --force2604--- PASS: TestClientIntegration (3.00s)26052026/09/23 13:29:41 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=026062026/09/23 13:29:41 INFO Vacuumed table table=pending_closures26072026/09/23 13:29:41 INFO Vacuumed table table=pending_objects26082026/09/23 13:29:41 INFO Vacuumed table table=multipart_uploads26092026/09/23 13:29:41 INFO Vacuumed table table=closures26102026/09/23 13:29:41 INFO Vacuumed table table=objects2611=== NAME TestOrphanedObjectsGCStressTest2612 orphaned_objects_gc_test.go:509: Stress test completed successfully:2613 orphaned_objects_gc_test.go:510: - Active objects preserved: 202614 orphaned_objects_gc_test.go:511: - Objects deleted: 2102615 orphaned_objects_gc_test.go:512: - Total GC'd: 2102616--- PASS: TestOrphanedObjectsGCStressTest (2.59s)26172026/09/23 13:29:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02618=== NAME TestPinProtectsFromGC2619 client_integration_test.go:794: Pin successfully protected closure from garbage collection2620--- PASS: TestPinProtectsFromGC (2.90s)26212026/09/23 13:29:42 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26222026/09/23 13:29:42 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.27605ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26232026/09/23 13:29:42 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.640948ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26242026/09/23 13:29:43 WARN Rate limiter enabled after throttle name=s3-test rate=526252026/09/23 13:29:43 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2626=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2627 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102628 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002629--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.98s)26302026/09/23 13:29:43 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=787.469556ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26312026/09/23 13:29:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.554939771s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26322026/09/23 13:29:45 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"26332026/09/23 13:29:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26342026/09/23 13:29:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.315077ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26352026/09/23 13:29:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.188135ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26362026/09/23 13:29:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=764.577886ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26372026/09/23 13:29:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.72050224s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2638--- PASS: TestClientErrorHandling (0.00s)2639 --- PASS: TestClientErrorHandling/InvalidStorePath (0.52s)2640 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.58s)2641 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.62s)2642FAIL2643{"timestamp":"2026-09-23T13:29:48.867473031Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53842","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(200)"}26442026-09-23 13:29:49.152 UTC [128] LOG: received smart shutdown request26452026-09-23 13:29:49.159 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 126462026-09-23 13:29:49.177 UTC [133] LOG: shutting down26472026-09-23 13:29:49.178 UTC [133] LOG: checkpoint starting: shutdown immediate26482026-09-23 13:29:50.461 UTC [133] LOG: checkpoint complete: wrote 11520 buffers (70.3%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.222 s, sync=1.026 s, total=1.285 s; sync files=21875, longest=0.002 s, average=0.001 s; distance=297524 kB, estimate=297524 kB; lsn=0/139F2D18, redo lsn=0/139F2D1826492026-09-23 13:29:50.569 UTC [128] LOG: database system is shut down