nixbot

builds
sign in

niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #344 · 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 TestScriptTokenEmptyToken97=== CONT TestScriptTokenScriptFails98=== CONT TestScriptTokenBadJSON99=== CONT TestScriptTokenEmptyCommand100--- PASS: TestScriptTokenEmptyCommand (0.00s)101=== CONT TestStreamPushRequestLine102=== CONT TestEncodeNixBase32WithRealHash103--- PASS: TestEncodeNixBase32WithRealHash (0.00s)104=== CONT TestStreamPushGivesUpOnDeadServer105=== CONT TestResolveStorePath106=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess107--- PASS: TestScriptTokenScriptFails (0.00s)108=== CONT TestStreamPushReportsEveryPath109=== CONT TestRateLimiterFeedback110=== CONT TestPathInfoCACompatibility111=== CONT TestParsePathInfoJSONMultiplePaths112=== CONT TestParsePathInfoJSON113=== CONT TestPathInfoHashCompatibility114=== CONT TestGetStorePathHash115=== CONT TestSetClientTLS116=== CONT TestConvertHashToNix32117=== CONT TestScriptTokenCachesUntilRefresh118=== CONT TestStreamPushIsolatesFailures119=== CONT TestScriptTokenNoExpiryRerunsEveryCall120=== CONT TestClientSignaturesByStorePath121=== CONT TestFileTokenEmpty122=== CONT TestStreamPushReportsSignatures1232026/10/01 10:45:40 ERROR Upload failed error="connection refused" count=201242026/10/01 10:45:40 ERROR Server seems unavailable, giving up on batch untried=171252026/10/01 10:45:40 WARN Rate limiter enabled after throttle name=server-test rate=51262026/10/01 10:45:40 ERROR Upload failed error="bad path" count=31272026/10/01 10:45:40 ERROR Upload failed error=boom count=11282026/10/01 10:45:40 ERROR Upload failed error=boom count=1129=== CONT TestFileTokenMissing130=== CONT TestDoWithRetry_BodyReplayedViaGetBody131=== RUN TestParsePathInfoJSON/Nix_format132=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)133=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)134=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon135=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon136=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths137=== RUN TestRateLimiterFeedback/429_enables_limiter138=== RUN TestPathInfoCACompatibility/null_ca_field139=== RUN TestGetStorePathHash/valid_store_path140=== RUN TestConvertHashToNix32/SRI_format_to_Nix32141--- PASS: TestStreamPushIsolatesFailures (0.00s)142=== CONT TestFileTokenReadsAndCaches143=== CONT TestStreamPushBatchesUnderLoad144=== CONT TestStaticToken145=== CONT TestSetClientTLSErrors146=== CONT TestSetClientTLSDoesNotMutateDefaultTransport147=== CONT TestShellSplitErrors148=== PAUSE TestParsePathInfoJSON/Nix_format149=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI150=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI151=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512152=== RUN TestParsePathInfoJSON/Lix_format153=== PAUSE TestParsePathInfoJSON/Lix_format154=== RUN TestParsePathInfoJSON/empty_input155=== PAUSE TestPathInfoCACompatibility/null_ca_field156=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths157=== CONT TestEncodeNixBase32158=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths159=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32160=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths161=== PAUSE TestGetStorePathHash/valid_store_path162=== CONT TestCaseHackSuffix163--- PASS: TestStreamPushReportsEveryPath (0.00s)164--- PASS: TestResolveStorePath (0.00s)165--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)166--- PASS: TestClientSignaturesByStorePath (0.00s)167=== CONT TestPartSizeForNAR168=== CONT TestRegisterUploadedObjectReusesConnections169=== RUN TestGetStorePathHash/basename_without_hyphen_should_error170=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error171=== CONT TestDumpPathWriterError172=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error1732026/10/01 10:45:40 WARN Rate limiter enabled after throttle name=server-test rate=5174=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error175=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error1762026/10/01 10:45:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40221177=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error178=== CONT TestDumpPathSingleFile179=== CONT TestDumpPathMatchesNix180=== CONT TestUploadMultipart_PartsInParallel181=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512182=== CONT TestShellSplit183=== CONT TestFilterOversizedClosures184=== PAUSE TestParsePathInfoJSON/empty_input185=== RUN TestPathInfoCACompatibility/old_string_format_-_text186=== RUN TestEncodeNixBase32/test_string_hash187=== RUN TestConvertHashToNix32/already_Nix32_format188--- PASS: TestStreamPushReportsSignatures (0.00s)189=== RUN TestPartSizeForNAR/zero_stays_at_minimum190=== PAUSE TestRateLimiterFeedback/429_enables_limiter191=== RUN TestParsePathInfoJSON/whitespace_only192=== PAUSE TestEncodeNixBase32/test_string_hash193--- PASS: TestScriptTokenEmptyToken (0.00s)194--- PASS: TestFileTokenMissing (0.00s)195--- PASS: TestFileTokenEmpty (0.00s)196--- PASS: TestStaticToken (0.00s)197--- PASS: TestShellSplitErrors (0.00s)198--- PASS: TestScriptTokenBadJSON (0.00s)199--- PASS: TestFileTokenReadsAndCaches (0.00s)200--- PASS: TestDoServerRequestAttachesToken (0.01s)201=== RUN TestEncodeNixBase32/empty_input202=== PAUSE TestEncodeNixBase32/empty_input203=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text204=== RUN TestFilterOversizedClosures/no_limit_keeps_everything205=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything206=== CONT TestUploadMultipart_SupersededByPeer207=== PAUSE TestConvertHashToNix32/already_Nix32_format208=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths209--- PASS: TestShellSplit (0.00s)210=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths211=== PAUSE TestParsePathInfoJSON/whitespace_only212=== RUN TestRateLimiterFeedback/503_enables_limiter213=== PAUSE TestRateLimiterFeedback/503_enables_limiter214=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter215=== CONT TestGetStorePathHash/valid_store_path216=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error217=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error2182026/10/01 10:45:40 WARN Rate limiter backed off name=server-test rate=5219=== CONT TestGetStorePathHash/basename_without_hyphen_should_error2202026/10/01 10:45:40 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40221221--- PASS: TestGetStorePathHash (0.00s)222 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)223 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)224 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)225 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)226=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)227=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512228=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI229=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon230=== RUN TestParsePathInfoJSON/invalid_JSON231--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)232--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.04s)233--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)234=== CONT TestEncodeNixBase32/test_string_hash235=== CONT TestEncodeNixBase32/empty_input236=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum237=== RUN TestPartSizeForNAR/small_stays_at_minimum238=== PAUSE TestPartSizeForNAR/small_stays_at_minimum239=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum240=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum241=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts242=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts243=== RUN TestPartSizeForNAR/1_TiB244=== PAUSE TestPartSizeForNAR/1_TiB245=== RUN TestPartSizeForNAR/5_TiB_S3_max_object246=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object247=== RUN TestPartSizeForNAR/capped_at_5_GiB248=== PAUSE TestPartSizeForNAR/capped_at_5_GiB249=== CONT TestPartSizeForNAR/zero_stays_at_minimum250=== CONT TestPartSizeForNAR/5_TiB_S3_max_object251=== CONT TestPartSizeForNAR/1_TiB252=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive253=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive254=== RUN TestSetClientTLSErrors/missing_cert_file255--- PASS: TestPathInfoHashCompatibility (0.01s)256 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)257 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)258 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)259 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)260=== PAUSE TestSetClientTLSErrors/missing_cert_file261=== RUN TestConvertHashToNix32/invalid_format262=== RUN TestSetClientTLS/rejects_connection_without_client_cert263=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert264=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA265=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA266=== RUN TestSetClientTLS/preserves_debug_logging_transport267=== PAUSE TestSetClientTLS/preserves_debug_logging_transport268=== CONT TestSetClientTLS/rejects_connection_without_client_cert269--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)270 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)271 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)272--- PASS: TestEncodeNixBase32 (0.00s)273 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)274 --- PASS: TestEncodeNixBase32/empty_input (0.00s)275=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA276=== RUN TestSetClientTLSErrors/missing_key_file277=== PAUSE TestSetClientTLSErrors/missing_key_file278=== RUN TestSetClientTLSErrors/missing_ca_file279=== PAUSE TestSetClientTLSErrors/missing_ca_file280=== RUN TestSetClientTLSErrors/invalid_ca_file281=== PAUSE TestSetClientTLSErrors/invalid_ca_file282=== CONT TestSetClientTLSErrors/missing_cert_file283=== PAUSE TestConvertHashToNix32/invalid_format284=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter285=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter286=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter287=== CONT TestPartSizeForNAR/capped_at_5_GiB288=== CONT TestConvertHashToNix32/SRI_format_to_Nix32289=== CONT TestSetClientTLSErrors/missing_ca_file290=== CONT TestSetClientTLSErrors/missing_key_file291=== CONT TestConvertHashToNix32/invalid_format292=== CONT TestConvertHashToNix32/already_Nix32_format293--- PASS: TestConvertHashToNix32 (0.04s)294 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)295 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)296 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)297=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts298=== CONT TestRateLimiterFeedback/503_enables_limiter299=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter300=== RUN TestUploadMultipart_SupersededByPeer/exists301=== PAUSE TestUploadMultipart_SupersededByPeer/exists302=== RUN TestUploadMultipart_SupersededByPeer/missing303=== PAUSE TestUploadMultipart_SupersededByPeer/missing304=== CONT TestUploadMultipart_SupersededByPeer/exists305=== CONT TestPartSizeForNAR/small_stays_at_minimum306=== PAUSE TestParsePathInfoJSON/invalid_JSON307=== CONT TestParsePathInfoJSON/Nix_format308=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum309--- PASS: TestPartSizeForNAR (0.03s)310 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)311 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)312 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)313 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)314 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)315 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)316 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)317=== RUN TestPathInfoCACompatibility/new_structured_format_-_text318=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped319=== CONT TestRateLimiterFeedback/429_enables_limiter320=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text321=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method322=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method323=== CONT TestParsePathInfoJSON/Lix_format3242026/10/01 10:45:40 WARN Rate limiter enabled after throttle name=server-test rate=53252026/10/01 10:45:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43253326=== CONT TestUploadMultipart_SupersededByPeer/missing327=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped328=== RUN TestFilterOversizedClosures/all_closures_skipped329=== PAUSE TestFilterOversizedClosures/all_closures_skipped330=== CONT TestParsePathInfoJSON/invalid_JSON331=== CONT TestPathInfoCACompatibility/new_structured_format_-_text3322026/10/01 10:45:40 WARN Rate limiter enabled after throttle name=server-test rate=53332026/10/01 10:45:40 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:412173342026/10/01 10:45:40 WARN Rate limiter backed off name=server-test rate=5335=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive336=== CONT TestPathInfoCACompatibility/old_string_format_-_text337=== CONT TestFilterOversizedClosures/no_limit_keeps_everything338=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3392026/10/01 10:45:40 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=2000340=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method341--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)342=== CONT TestParsePathInfoJSON/empty_input3432026/10/01 10:45:40 WARN Rate limiter backed off name=server-test rate=5344=== CONT TestParsePathInfoJSON/whitespace_only345--- PASS: TestParsePathInfoJSON (0.04s)346 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)347 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)348 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)349 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)350 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)351=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter352--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)353 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)354 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)355=== CONT TestSetClientTLSErrors/invalid_ca_file356=== CONT TestSetClientTLS/preserves_debug_logging_transport357=== CONT TestFilterOversizedClosures/all_closures_skipped3582026/10/01 10:45:40 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=50359--- PASS: TestFilterOversizedClosures (0.03s)360 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)361 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)362 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)363=== CONT TestPathInfoCACompatibility/null_ca_field364--- PASS: TestPathInfoCACompatibility (0.04s)365 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)366 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)367 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)368 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)369 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)370--- PASS: TestSetClientTLSErrors (0.04s)371 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)372 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)373 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)374 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.01s)375--- PASS: TestRateLimiterFeedback (0.04s)376 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)377 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)3802026/10/01 10:45:40 http: TLS handshake error from 127.0.0.1:36570: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.04s)382 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)385--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)386--- PASS: TestDumpPathSingleFile (0.06s)387--- PASS: TestCaseHackSuffix (0.07s)388--- PASS: TestStreamPushRequestLine (0.07s)389--- PASS: TestDumpPathWriterError (0.08s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.11s)392--- PASS: TestUploadMultipart_PartsInParallel (0.66s)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/postgres3558957698/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/postgres3558957698/data -l logfile start422423/build/postgres3558957698:5432 - no response4242026-10-01 10:45:41.895 UTC [130] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 10:45:41.896 UTC [130] LOG: listening on Unix socket "/build/postgres3558957698/.s.PGSQL.5432"4262026-10-01 10:45:41.900 UTC [137] LOG: database system was shut down at 2026-10-01 10:45:41 UTC4272026-10-01 10:45:41.903 UTC [130] LOG: database system is ready to accept connections428/build/postgres3558957698: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 TestConcurrentCommitsSharingObjectsDoNotDeadlock466=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== RUN TestResolveDBConnectionString468=== PAUSE TestResolveDBConnectionString469=== RUN TestConnectWaitsForAPeerMigration470=== PAUSE TestConnectWaitsForAPeerMigration471=== RUN TestLeadElectsOneAndHandsOver472=== PAUSE TestLeadElectsOneAndHandsOver473=== RUN TestLeadIncumbentWinsAfterRestart4742026/10/01 10:45:42 INFO lead: acquired remote=192.0.2.1:12344752026/10/01 10:45:42 INFO lead: released remote=192.0.2.1:12344762026/10/01 10:45:42 INFO lead: acquired remote=192.0.2.1:12344772026/10/01 10:45:43 INFO lead: released remote=192.0.2.1:1234478--- PASS: TestLeadIncumbentWinsAfterRestart (0.83s)479=== RUN TestLeadEndsOnShutdown480=== PAUSE TestLeadEndsOnShutdown481=== RUN TestGCAdvisoryLockBlocksConcurrentRun482=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun483=== RUN TestGCBugBareHashReferences484=== PAUSE TestGCBugBareHashReferences485=== RUN TestGCMetrics486=== PAUSE TestGCMetrics487=== RUN TestPushDedupSurvivesConcurrentGC488=== PAUSE TestPushDedupSurvivesConcurrentGC489=== RUN TestDeduplicatedObjectsRecordedAsPending490=== PAUSE TestDeduplicatedObjectsRecordedAsPending491=== RUN TestGCSweepSkipsPendingObjects492=== PAUSE TestGCSweepSkipsPendingObjects493=== RUN TestTombstonedObjectOfferedWithoutWaiting494=== PAUSE TestTombstonedObjectOfferedWithoutWaiting495=== RUN TestGCSweepDeliversEachKeyOnce496=== PAUSE TestGCSweepDeliversEachKeyOnce497=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection498=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection499=== RUN TestForceGCDuringPushOffersSweptObject500=== PAUSE TestForceGCDuringPushOffersSweptObject501=== RUN TestFailedS3DeleteKeepsTombstone502=== PAUSE TestFailedS3DeleteKeepsTombstone503=== RUN TestSweepSkipsRowsLockedByPush504=== PAUSE TestSweepSkipsRowsLockedByPush505=== RUN TestRegisterCompletedObjectNeedsPendingRow506=== PAUSE TestRegisterCompletedObjectNeedsPendingRow507=== RUN TestGetExistingObjectsLocksRows508=== PAUSE TestGetExistingObjectsLocksRows509=== RUN TestSweepRechecksPendingAfterLocking510=== PAUSE TestSweepRechecksPendingAfterLocking511=== RUN TestPushWaitsForSweepHoldingRow512=== PAUSE TestPushWaitsForSweepHoldingRow513=== RUN TestCommitRacingPendingCleanupKeepsObjects514=== PAUSE TestCommitRacingPendingCleanupKeepsObjects515=== RUN TestGCEndsOnShutdown516=== PAUSE TestGCEndsOnShutdown517=== RUN TestGCTaskStore_StartNew518=== PAUSE TestGCTaskStore_StartNew519=== RUN TestGCTaskStore_DeduplicateSameParams520=== PAUSE TestGCTaskStore_DeduplicateSameParams521=== RUN TestGCTaskStore_ConflictDifferentParams522=== PAUSE TestGCTaskStore_ConflictDifferentParams523=== RUN TestGCTaskStore_GetEmpty524=== PAUSE TestGCTaskStore_GetEmpty525=== RUN TestGCTaskStore_GetReturnsLatest526=== PAUSE TestGCTaskStore_GetReturnsLatest527=== RUN TestGCTaskStore_CompletedAllowsNewTask528=== PAUSE TestGCTaskStore_CompletedAllowsNewTask529=== RUN TestGCTaskStore_PhaseUpdates530=== PAUSE TestGCTaskStore_PhaseUpdates531=== RUN TestGCTaskStore_Fail532=== PAUSE TestGCTaskStore_Fail533=== RUN TestGracefulShutdownDrainsInflight534=== PAUSE TestGracefulShutdownDrainsInflight535=== RUN TestService_healthCheckHandler536=== PAUSE TestService_healthCheckHandler537=== RUN TestService_readinessHandler538=== PAUSE TestService_readinessHandler539=== RUN TestGenerateLandingPage540=== PAUSE TestGenerateLandingPage541=== RUN TestCacheConfigHandlerMaxNarSize542=== PAUSE TestCacheConfigHandlerMaxNarSize543=== RUN TestCreatePendingClosureRejectsOversizedNAR544=== PAUSE TestCreatePendingClosureRejectsOversizedNAR545=== RUN TestNARDeduplicationMetadataUploadBug546=== PAUSE TestNARDeduplicationMetadataUploadBug547=== RUN TestMetricsInventory548=== PAUSE TestMetricsInventory549=== RUN TestService_NativeMTLS550=== PAUSE TestService_NativeMTLS551=== RUN TestServerTLSConfig552=== PAUSE TestServerTLSConfig553=== RUN TestMultipartCleanup554=== PAUSE TestMultipartCleanup555=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded556=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded557=== RUN TestPendingCleanupUsesOneCutoff558=== PAUSE TestPendingCleanupUsesOneCutoff559=== RUN TestObjectStatsTrigger560=== PAUSE TestObjectStatsTrigger561=== RUN TestOrphanedObjectsGC562=== PAUSE TestOrphanedObjectsGC563=== RUN TestOrphanedObjectsGCStressTest564=== PAUSE TestOrphanedObjectsGCStressTest565=== RUN TestCreatePin_ReservedPins566=== PAUSE TestCreatePin_ReservedPins567=== RUN TestPresentReportsOnlyClosureRoots568=== PAUSE TestPresentReportsOnlyClosureRoots569=== RUN TestPresentNotReportedWhileGCDeletesClosure570=== PAUSE TestPresentNotReportedWhileGCDeletesClosure571=== RUN TestParseSingleRange572=== PAUSE TestParseSingleRange573=== RUN TestProxyHeadersOnlyTrustedOnSocket574=== PAUSE TestProxyHeadersOnlyTrustedOnSocket575=== RUN TestIsValidCachePath576=== PAUSE TestIsValidCachePath577=== RUN TestReadProxyNarinfo578=== PAUSE TestReadProxyNarinfo579=== RUN TestReadProxyNarinfoAlreadyDecompressed580=== PAUSE TestReadProxyNarinfoAlreadyDecompressed581=== RUN TestReadProxyNarStreaming582=== PAUSE TestReadProxyNarStreaming583=== RUN TestReadProxy404584=== PAUSE TestReadProxy404585=== RUN TestReadProxyInvalidPath586=== PAUSE TestReadProxyInvalidPath587=== RUN TestReadProxyHead588=== PAUSE TestReadProxyHead589=== RUN TestReadProxyOutlastsServerWriteTimeout590=== PAUSE TestReadProxyOutlastsServerWriteTimeout591=== RUN TestReadProxyConditionalGet592=== PAUSE TestReadProxyConditionalGet593=== RUN TestReadProxyRootRedirectsToIndexHTML594=== PAUSE TestReadProxyRootRedirectsToIndexHTML595=== RUN TestReadProxyDisabled596=== PAUSE TestReadProxyDisabled597=== RUN TestReadRedirectNar598=== PAUSE TestReadRedirectNar599=== RUN TestReadRedirectKeepsNarinfoProxied600=== PAUSE TestReadRedirectKeepsNarinfoProxied601=== RUN TestReadProxyRangeRequest602=== PAUSE TestReadProxyRangeRequest603=== RUN TestReadRedirectUsesPublicS3URL604=== PAUSE TestReadRedirectUsesPublicS3URL605=== RUN TestPush_OverlappingRootsStoreOneRowPerKey606=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey607=== RUN TestPush_CompleteCommitsEveryRoot608=== PAUSE TestPush_CompleteCommitsEveryRoot609=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit610=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit611=== RUN TestPush_RejectsBadRequests612=== PAUSE TestPush_RejectsBadRequests613=== RUN TestPush_SignsNarinfosOfItsPendingObjects614=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects615=== RUN TestRedundantMultipartUpload616=== PAUSE TestRedundantMultipartUpload617=== RUN TestCompleteMultipartUpload_ErrorButObjectExists618=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists619=== RUN TestCompletedNarNotReofferedAcrossClosures620=== PAUSE TestCompletedNarNotReofferedAcrossClosures621=== RUN TestPresignedUploadRegisteredBeforeCommit622=== PAUSE TestPresignedUploadRegisteredBeforeCommit623=== RUN TestService_Rustfstest624=== PAUSE TestService_Rustfstest625=== RUN TestParseSize626=== PAUSE TestParseSize627=== RUN TestSkippedUploadsHandler628=== PAUSE TestSkippedUploadsHandler629=== RUN TestSystemdListenerNotActivated630--- PASS: TestSystemdListenerNotActivated (0.00s)631=== RUN TestWatchdogBeatsWhenHealthy632--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)633=== RUN TestWatchdogSkipsWhenUnhealthy6342026/10/01 10:45:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6352026/10/01 10:45:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 10:45:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 10:45:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 10:45:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 10:45:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 10:45:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 10:45:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 10:45:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 10:45:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"644--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)645=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle646=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle647=== RUN TestProxyWriteTimeout648=== PAUSE TestProxyWriteTimeout649=== RUN TestPendingClosureWriteTimeout650=== PAUSE TestPendingClosureWriteTimeout651=== RUN TestIsValidUploadKey652=== PAUSE TestIsValidUploadKey653=== RUN TestUploadHandlersRejectInvalidKeys654=== PAUSE TestUploadHandlersRejectInvalidKeys655=== RUN TestUploadHandlersRejectOversizedBody656=== PAUSE TestUploadHandlersRejectOversizedBody657=== RUN TestService_cleanupPendingClosuresHandler658=== PAUSE TestService_cleanupPendingClosuresHandler659=== RUN TestService_createPendingClosureHandler660=== PAUSE TestService_createPendingClosureHandler661=== RUN TestService_verifyS3Integrity662=== PAUSE TestService_verifyS3Integrity663=== RUN TestCompleteMultipartUnregistered664=== PAUSE TestCompleteMultipartUnregistered665=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT666=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT667=== CONT TestPendingClosureWriteTimeout668=== RUN TestPendingClosureWriteTimeout/empty669=== CONT TestService_AuthMiddleware670=== PAUSE TestPendingClosureWriteTimeout/empty671=== RUN TestPendingClosureWriteTimeout/400_objects672=== PAUSE TestPendingClosureWriteTimeout/400_objects673=== CONT TestProxyWriteTimeout674=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle675=== CONT TestSkippedUploadsHandler676=== CONT TestParseSize677--- PASS: TestParseSize (0.00s)678=== CONT TestReadProxyDisabled679=== CONT TestService_Rustfstest680=== CONT TestPresignedUploadRegisteredBeforeCommit681=== CONT TestCompletedNarNotReofferedAcrossClosures682=== CONT TestCompleteMultipartUpload_ErrorButObjectExists6832026/10/01 10:45:43 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000684=== CONT TestRedundantMultipartUpload685=== CONT TestPush_SignsNarinfosOfItsPendingObjects686=== CONT TestPush_RejectsBadRequests687=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit688=== CONT TestPush_CompleteCommitsEveryRoot689=== CONT TestPush_OverlappingRootsStoreOneRowPerKey690=== CONT TestReadRedirectUsesPublicS3URL691=== CONT TestService_createPendingClosureHandler692=== CONT TestReadProxyRangeRequest693=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT694=== CONT TestReadRedirectKeepsNarinfoProxied695=== CONT TestCompleteMultipartUnregistered696=== CONT TestReadRedirectNar697=== CONT TestService_verifyS3Integrity698=== RUN TestPendingClosureWriteTimeout/670k_objects699=== RUN TestProxyWriteTimeout/narinfo700=== PAUSE TestProxyWriteTimeout/narinfo701=== PAUSE TestPendingClosureWriteTimeout/670k_objects702=== RUN TestProxyWriteTimeout/1_GiB_nar703=== PAUSE TestProxyWriteTimeout/1_GiB_nar704=== RUN TestProxyWriteTimeout/10_GiB_nar705=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline706=== PAUSE TestProxyWriteTimeout/10_GiB_nar707=== RUN TestProxyWriteTimeout/unknown_size708=== PAUSE TestProxyWriteTimeout/unknown_size709=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline710=== CONT TestReadProxyRootRedirectsToIndexHTML711=== CONT TestGCEndsOnShutdown712--- PASS: TestSkippedUploadsHandler (0.00s)713=== CONT TestCommitRacingPendingCleanupKeepsObjects714--- PASS: TestReadProxyDisabled (0.28s)715=== CONT TestReadProxyConditionalGet7162026/10/01 10:45:43 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"717--- PASS: TestService_AuthMiddleware (0.30s)718=== CONT TestPushWaitsForSweepHoldingRow719--- PASS: TestService_Rustfstest (0.32s)720=== CONT TestReadProxyOutlastsServerWriteTimeout7212026/10/01 10:45:43 INFO Received uploads request method=POST path=/api/pending_closures7222026/10/01 10:45:43 INFO Received uploads request method=POST path=/api/pending_closures7232026/10/01 10:45:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7242026/10/01 10:45:43 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzgzYmQ5N2UtYjVmMS00NGU0LTllY2EtM2M2ZmFjMTIyYjMzLjcyMzkyNzlmLWJlNjYtNDZhZC05MGYzLTZiOWFjYzZiNTQ0NXgxNzkwODUxNTQzNTk4MTkzNTY37252026/10/01 10:45:43 INFO Received uploads request method=POST path=/api/pending_closures7262026/10/01 10:45:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzgzYmQ5N2UtYjVmMS00NGU0LTllY2EtM2M2ZmFjMTIyYjMzLjcyMzkyNzlmLWJlNjYtNDZhZC05MGYzLTZiOWFjYzZiNTQ0NXgxNzkwODUxNTQzNTk4MTkzNTY3 parts=1727--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.38s)728=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock7292026/10/01 10:45:43 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7302026/10/01 10:45:43 INFO Received uploads request method=POST path=/api/pending_closures731--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.39s)732=== CONT TestReadProxyHead7332026/10/01 10:45:43 INFO Received uploads request method=POST path=/api/pending_closures7342026/10/01 10:45:43 INFO Received push request method=POST path=/api/pushes7352026/10/01 10:45:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete736--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.43s)737=== CONT TestReadProxyInvalidPath7382026/10/01 10:45:43 INFO Received push request method=POST path=/api/pushes7392026/10/01 10:45:43 INFO Received complete push request method=POST path=/api/pushes/1/complete7402026/10/01 10:45:43 INFO Received push request method=POST path=/api/pushes7412026/10/01 10:45:43 INFO Received push request method=POST path=/api/pushes7422026/10/01 10:45:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7432026/10/01 10:45:43 INFO Signed narinfos id=1 count=1744--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.47s)745=== CONT TestClientFallsBackToClosures746--- PASS: TestReadRedirectNar (0.48s)747=== CONT TestReadProxy4047482026/10/01 10:45:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7492026/10/01 10:45:43 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst750--- PASS: TestCompleteMultipartUnregistered (0.50s)751=== CONT TestClientPushesUseOnePush7522026/10/01 10:45:43 INFO Received uploads request method=POST path=/api/pending_closures7532026/10/01 10:45:43 INFO Aborted multipart uploads count=0 kept=07542026/10/01 10:45:43 WARN Force mode enabled - objects will be deleted immediately without grace period755--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.53s)756=== CONT TestReadProxyNarStreaming7572026/10/01 10:45:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=07582026/10/01 10:45:43 INFO Vacuumed table table=pending_closures7592026/10/01 10:45:43 INFO Vacuumed table table=pending_objects7602026/10/01 10:45:43 INFO Vacuumed table table=multipart_uploads7612026/10/01 10:45:43 INFO Vacuumed table table=closures7622026/10/01 10:45:43 INFO Vacuumed table table=objects7632026/10/01 10:45:43 INFO Received complete push request method=POST path=/api/pushes/2/complete764--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.55s)765=== CONT TestPinProtectsFromGC766--- PASS: TestReadRedirectUsesPublicS3URL (0.56s)767=== CONT TestClientSharedPathCommittedMidPush768--- PASS: TestReadProxyRangeRequest (0.57s)769=== CONT TestReadProxyNarinfo770--- PASS: TestReadRedirectKeepsNarinfoProxied (0.83s)771=== CONT TestClientWithDependencies772--- PASS: TestGCEndsOnShutdown (0.86s)773=== CONT TestResolveDBConnectionString774=== RUN TestResolveDBConnectionString/flag_wins775=== PAUSE TestResolveDBConnectionString/flag_wins776=== RUN TestResolveDBConnectionString/file_when_flag_empty777=== PAUSE TestResolveDBConnectionString/file_when_flag_empty778=== RUN TestResolveDBConnectionString/missing_file_is_an_error779=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error780=== RUN TestResolveDBConnectionString/PGHOST_allows_empty781=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty782=== RUN TestResolveDBConnectionString/nothing_configured783=== PAUSE TestResolveDBConnectionString/nothing_configured784=== CONT TestIsValidCachePath785=== RUN TestIsValidCachePath/narinfo786=== PAUSE TestIsValidCachePath/narinfo787=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars788=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars789=== RUN TestIsValidCachePath/nar_zst790=== PAUSE TestIsValidCachePath/nar_zst791=== RUN TestIsValidCachePath/nar_xz792=== PAUSE TestIsValidCachePath/nar_xz793=== RUN TestIsValidCachePath/nar_bz2794=== PAUSE TestIsValidCachePath/nar_bz2795=== RUN TestIsValidCachePath/nar_uncompressed796=== PAUSE TestIsValidCachePath/nar_uncompressed797=== RUN TestIsValidCachePath/ls798=== PAUSE TestIsValidCachePath/ls799=== RUN TestIsValidCachePath/log800=== PAUSE TestIsValidCachePath/log801=== RUN TestIsValidCachePath/realisation802=== PAUSE TestIsValidCachePath/realisation803=== RUN TestIsValidCachePath/nix-cache-info804=== PAUSE TestIsValidCachePath/nix-cache-info805=== RUN TestIsValidCachePath/index.html806=== PAUSE TestIsValidCachePath/index.html807=== RUN TestIsValidCachePath/traversal_parent808=== PAUSE TestIsValidCachePath/traversal_parent809=== RUN TestIsValidCachePath/traversal_in_middle810=== PAUSE TestIsValidCachePath/traversal_in_middle811=== RUN TestIsValidCachePath/invalid_char_e812=== PAUSE TestIsValidCachePath/invalid_char_e813=== RUN TestIsValidCachePath/invalid_char_u814=== PAUSE TestIsValidCachePath/invalid_char_u815=== RUN TestIsValidCachePath/random_path816=== PAUSE TestIsValidCachePath/random_path817=== RUN TestIsValidCachePath/empty818=== PAUSE TestIsValidCachePath/empty819=== RUN TestIsValidCachePath/leading_slash820=== PAUSE TestIsValidCachePath/leading_slash821=== RUN TestIsValidCachePath/wrong_extension822=== PAUSE TestIsValidCachePath/wrong_extension823=== RUN TestIsValidCachePath/short_hash824=== PAUSE TestIsValidCachePath/short_hash825=== CONT TestReadProxyNarinfoAlreadyDecompressed8262026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures8272026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures8282026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures829=== RUN TestPush_RejectsBadRequests/no_roots830=== PAUSE TestPush_RejectsBadRequests/no_roots831=== RUN TestPush_RejectsBadRequests/no_objects832=== PAUSE TestPush_RejectsBadRequests/no_objects833=== RUN TestPush_RejectsBadRequests/bad_root834=== PAUSE TestPush_RejectsBadRequests/bad_root835=== RUN TestPush_RejectsBadRequests/root_not_in_objects836=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects837=== CONT TestProxyHeadersOnlyTrustedOnSocket838--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.95s)839=== CONT TestClientMultipleUploads8402026/10/01 10:45:44 INFO Aborted multipart uploads count=0 kept=08412026/10/01 10:45:44 WARN Force mode enabled - objects will be deleted immediately without grace period8422026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures8432026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures8442026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures8452026/10/01 10:45:44 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=08462026/10/01 10:45:44 INFO Vacuumed table table=pending_closures8472026/10/01 10:45:44 INFO Vacuumed table table=pending_objects8482026/10/01 10:45:44 INFO Vacuumed table table=multipart_uploads8492026/10/01 10:45:44 INFO Vacuumed table table=closures8502026/10/01 10:45:44 INFO Vacuumed table table=objects851--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.99s)852=== CONT TestSweepRechecksPendingAfterLocking8532026/10/01 10:45:44 INFO Received push request method=POST path=/api/pushes8542026/10/01 10:45:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8552026/10/01 10:45:44 INFO Received complete push request method=POST path=/api/pushes/1/complete8562026/10/01 10:45:44 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MzgzYmQ5N2UtYjVmMS00NGU0LTllY2EtM2M2ZmFjMTIyYjMzLjQyMDI0Mjc3LTYxZWEtNGNmZC1iOWVhLWUxYmI1ODZhNTI0YngxNzkwODUxNTQzNjU0ODYxOTUy parts=128572026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures8582026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures859--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.05s)860=== CONT TestGetExistingObjectsLocksRows861--- PASS: TestPush_CompleteCommitsEveryRoot (1.05s)862=== CONT TestClientIntegration863--- PASS: TestReadProxyConditionalGet (0.79s)864=== CONT TestParseSingleRange865=== RUN TestParseSingleRange/none866=== PAUSE TestParseSingleRange/none867=== RUN TestParseSingleRange/unknown_unit868=== PAUSE TestParseSingleRange/unknown_unit869=== RUN TestParseSingleRange/multi-range_ignored870=== PAUSE TestParseSingleRange/multi-range_ignored871=== RUN TestParseSingleRange/malformed_no_dash872=== PAUSE TestParseSingleRange/malformed_no_dash873=== RUN TestParseSingleRange/malformed_both_empty874=== PAUSE TestParseSingleRange/malformed_both_empty875=== RUN TestParseSingleRange/malformed_end_before_start876=== PAUSE TestParseSingleRange/malformed_end_before_start877=== RUN TestParseSingleRange/closed878=== PAUSE TestParseSingleRange/closed879=== RUN TestParseSingleRange/open-ended880=== PAUSE TestParseSingleRange/open-ended881=== RUN TestParseSingleRange/end_clamped_to_size882=== PAUSE TestParseSingleRange/end_clamped_to_size883=== RUN TestParseSingleRange/suffix884=== PAUSE TestParseSingleRange/suffix885=== RUN TestParseSingleRange/suffix_exceeds_size886=== PAUSE TestParseSingleRange/suffix_exceeds_size887=== RUN TestParseSingleRange/single_byte888=== PAUSE TestParseSingleRange/single_byte889=== RUN TestParseSingleRange/start_past_EOF890=== PAUSE TestParseSingleRange/start_past_EOF891=== RUN TestParseSingleRange/start_far_past_EOF892=== PAUSE TestParseSingleRange/start_far_past_EOF893=== CONT TestRegisterCompletedObjectNeedsPendingRow894=== NAME TestClientMultipleUploads895 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1316157225/001/store/92yi61fa1f69vck45yjhss89kgk484pf-test-file-0.txt896--- PASS: TestReadProxyHead (0.76s)897=== CONT TestSweepSkipsRowsLockedByPush898=== NAME TestClientMultipleUploads899 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1316157225/001/store/h37jzph9vlvms017mvkcslbs4rrb0d0d-test-file-1.txt900--- PASS: TestReadProxyInvalidPath (0.81s)901=== CONT TestPresentNotReportedWhileGCDeletesClosure9022026/10/01 10:45:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete903=== NAME TestClientMultipleUploads904 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1316157225/001/store/z3lkv90p0k073z9gqyjf6h4fhclhbl1c-test-file-2.txt9052026/10/01 10:45:44 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MzgzYmQ5N2UtYjVmMS00NGU0LTllY2EtM2M2ZmFjMTIyYjMzLjI1ZWE3ZjEwLTQ2MzQtNGM1Ni1hZWRmLTU0ZTkzMjJjZjYzOXgxNzkwODUxNTQ0MTU4NDkwNzYw parts=109062026/10/01 10:45:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9072026/10/01 10:45:44 INFO Completed upload id=19082026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures9092026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures9102026/10/01 10:45:44 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9112026/10/01 10:45:44 WARN Found objects in DB but missing from S3, will re-upload count=1912--- PASS: TestService_verifyS3Integrity (1.30s)913=== CONT TestFailedS3DeleteKeepsTombstone914--- PASS: TestReadProxy404 (0.83s)915=== CONT TestClientCADerivations9162026/10/01 10:45:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete917--- PASS: TestReadProxyNarStreaming (0.81s)918=== CONT TestClientErrorHandling919=== RUN TestClientErrorHandling/InvalidStorePath920=== PAUSE TestClientErrorHandling/InvalidStorePath921=== RUN TestClientErrorHandling/InvalidAuthToken922=== PAUSE TestClientErrorHandling/InvalidAuthToken923=== RUN TestClientErrorHandling/ServerNotAvailable924=== PAUSE TestClientErrorHandling/ServerNotAvailable925=== CONT TestGCMetrics9262026/10/01 10:45:44 INFO Received push request method=POST path=/api/pushes9272026/10/01 10:45:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MzgzYmQ5N2UtYjVmMS00NGU0LTllY2EtM2M2ZmFjMTIyYjMzLmJjNTU4MmZhLTZkNzAtNDcxMy05YzcxLTk5ZDgyYWU1OTRmNngxNzkwODUxNTQ0MTQwMTA1NDE2 parts=129282026/10/01 10:45:44 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)9292026/10/01 10:45:44 INFO Uploading z3lkv90p0k073z9gqyjf6h4fhclhbl1c-test-file-2.txt (160B)9302026/10/01 10:45:44 INFO Uploading 92yi61fa1f69vck45yjhss89kgk484pf-test-file-0.txt (160B)9312026/10/01 10:45:44 INFO Uploading h37jzph9vlvms017mvkcslbs4rrb0d0d-test-file-1.txt (160B)9322026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures9332026/10/01 10:45:44 WARN Failed to register uploaded object key=92yi61fa1f69vck45yjhss89kgk484pf.ls error="server returned 404: 404 page not found\n"9342026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"9352026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"9362026/10/01 10:45:44 WARN Failed to register uploaded object key=z3lkv90p0k073z9gqyjf6h4fhclhbl1c.ls error="server returned 404: 404 page not found\n"9372026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"9382026/10/01 10:45:44 WARN Failed to register uploaded object key=h37jzph9vlvms017mvkcslbs4rrb0d0d.ls error="server returned 404: 404 page not found\n"9392026/10/01 10:45:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9402026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/01 10:45:44 INFO Signed narinfos id=1 count=39422026/10/01 10:45:44 INFO Uploading 3 narinfos9432026/10/01 10:45:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9442026/10/01 10:45:44 WARN Failed to register uploaded object key=z3lkv90p0k073z9gqyjf6h4fhclhbl1c.narinfo error="server returned 404: 404 page not found\n"9452026/10/01 10:45:44 INFO Received complete push request method=POST path=/api/pushes/1/complete9462026/10/01 10:45:44 WARN Failed to register uploaded object key=h37jzph9vlvms017mvkcslbs4rrb0d0d.narinfo error="server returned 404: 404 page not found\n"9472026/10/01 10:45:44 WARN Failed to register uploaded object key=92yi61fa1f69vck45yjhss89kgk484pf.narinfo error="server returned 404: 404 page not found\n"9482026/10/01 10:45:44 INFO Upload complete. (62ms)949=== NAME TestClientMultipleUploads950 client_integration_test.go:369: Uploaded 3 paths in 96.794963ms9512026/10/01 10:45:44 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MzgzYmQ5N2UtYjVmMS00NGU0LTllY2EtM2M2ZmFjMTIyYjMzLjAxNTEwNDVjLTlkOGMtNDg5NS04ODY0LTZhZjc1M2RiOTc1NHgxNzkwODUxNTQ0MjM2NjQwMDk2 parts=109522026/10/01 10:45:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9532026/10/01 10:45:44 INFO Completed upload id=1954--- PASS: TestClientMultipleUploads (0.42s)955=== CONT TestCacheStatsHandler9562026/10/01 10:45:44 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009572026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures9582026/10/01 10:45:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures9592026/10/01 10:45:44 INFO Aborted multipart uploads count=0 kept=09602026/10/01 10:45:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09612026/10/01 10:45:44 INFO Vacuumed table table=pending_closures9622026/10/01 10:45:44 INFO Vacuumed table table=pending_objects9632026/10/01 10:45:44 INFO Vacuumed table table=multipart_uploads9642026/10/01 10:45:44 INFO Vacuumed table table=closures9652026/10/01 10:45:44 INFO Vacuumed table table=objects9662026/10/01 10:45:44 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009672026/10/01 10:45:44 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"968--- PASS: TestService_createPendingClosureHandler (1.43s)969=== CONT TestPresentReportsOnlyClosureRoots970--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.58s)971=== CONT TestGCBugBareHashReferences9722026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures973=== NAME TestPinProtectsFromGC974 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3623122829/001/store/hafk8j8ajpkhd7vjdcavdqg1vyvh9j92-pinned-file.txt975 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3623122829/001/store/xzhl1f5jimg4sl6wfbw33mi2sb7gjdp7-unpinned-file.txt9762026/10/01 10:45:44 INFO Received uploads request method=POST path=/api/pending_closures9772026/10/01 10:45:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9782026/10/01 10:45:44 INFO Uploading 0a5kbm0w0si77rdrdaalrzw1fg6fwggp-shared-dep (136B)9792026/10/01 10:45:44 INFO Uploading r8j5qs5i4v2m68nnqci62i7sgcylxmc9-a (216B)9802026/10/01 10:45:44 INFO Starting HTTP server address=127.0.0.1:345599812026/10/01 10:45:44 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1669846351/001/proxy.sock9822026/10/01 10:45:44 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9832026/10/01 10:45:44 INFO Shutdown signal received, draining in-flight requests timeout=10s9842026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/14zcrz1wl9ngd5cqsi6ldb0lf6rpnbchzgc0zv4pir88j42i0dhf.nar.zst error="server returned 404: 404 page not found\n"9852026/10/01 10:45:44 WARN Failed to register uploaded object key=lac5nil9r8dx8xr463s42wmw6z18rhs4.ls error="server returned 404: 404 page not found\n"986--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.55s)987=== CONT TestCacheConfigHandler9882026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"989=== RUN TestCacheConfigHandler/full_config,_no_issuer990=== PAUSE TestCacheConfigHandler/full_config,_no_issuer991=== RUN TestCacheConfigHandler/no_cache_url_configured992=== PAUSE TestCacheConfigHandler/no_cache_url_configured993=== RUN TestCacheConfigHandler/no_signing_keys994=== PAUSE TestCacheConfigHandler/no_signing_keys995=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator996=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator9972026/10/01 10:45:44 WARN Failed to register uploaded object key=0a5kbm0w0si77rdrdaalrzw1fg6fwggp.ls error="server returned 404: 404 page not found\n"998=== CONT TestCreatePin_ReservedPins9992026/10/01 10:45:44 WARN Failed to register uploaded object key=r8j5qs5i4v2m68nnqci62i7sgcylxmc9.ls error="server returned 404: 404 page not found\n"10002026/10/01 10:45:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10012026/10/01 10:45:44 INFO Signed narinfos id=1 count=210022026/10/01 10:45:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10032026/10/01 10:45:44 INFO Signed narinfos id=2 count=210042026/10/01 10:45:44 INFO Uploading 4 narinfos10052026/10/01 10:45:44 WARN Failed to register uploaded object key=0a5kbm0w0si77rdrdaalrzw1fg6fwggp.narinfo error="server returned 404: 404 page not found\n"10062026/10/01 10:45:44 WARN Failed to register uploaded object key=r8j5qs5i4v2m68nnqci62i7sgcylxmc9.narinfo error="server returned 404: 404 page not found\n"10072026/10/01 10:45:44 WARN Failed to register uploaded object key=lac5nil9r8dx8xr463s42wmw6z18rhs4.narinfo error="server returned 404: 404 page not found\n"10082026/10/01 10:45:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10092026/10/01 10:45:44 WARN Failed to register uploaded object key=0a5kbm0w0si77rdrdaalrzw1fg6fwggp.narinfo error="server returned 404: 404 page not found\n"10102026/10/01 10:45:44 INFO Completed upload id=110112026/10/01 10:45:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10122026/10/01 10:45:44 INFO Completed upload id=210132026/10/01 10:45:44 INFO Upload complete. (72ms)1014=== NAME TestClientFallsBackToClosures1015 client_pushes_test.go:112: Retrieved narinfo from S3:1016 StorePath: /build/TestClientFallsBackToClosures3215875446/001/store/0a5kbm0w0si77rdrdaalrzw1fg6fwggp-shared-dep1017 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1018 Compression: zstd1019 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821020 NarSize: 1361021 References: 1022 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1023 client_pushes_test.go:112: Retrieved narinfo from S3:1024 StorePath: /build/TestClientFallsBackToClosures3215875446/001/store/r8j5qs5i4v2m68nnqci62i7sgcylxmc9-a1025 URL: nar/14zcrz1wl9ngd5cqsi6ldb0lf6rpnbchzgc0zv4pir88j42i0dhf.nar.zst1026 Compression: zstd1027 NarHash: sha256:14zcrz1wl9ngd5cqsi6ldb0lf6rpnbchzgc0zv4pir88j42i0dhf1028 NarSize: 2161029 References: /build/TestClientFallsBackToClosures3215875446/001/store/0a5kbm0w0si77rdrdaalrzw1fg6fwggp-shared-dep1030 CA: text:sha256:1kvsiwzr15rpnwi653mjdskcxazgbgcxp7whgpxw57gb8r9p0p131031 client_pushes_test.go:112: Retrieved narinfo from S3:1032 StorePath: /build/TestClientFallsBackToClosures3215875446/001/store/lac5nil9r8dx8xr463s42wmw6z18rhs4-b1033 URL: nar/14zcrz1wl9ngd5cqsi6ldb0lf6rpnbchzgc0zv4pir88j42i0dhf.nar.zst1034 Compression: zstd1035 NarHash: sha256:14zcrz1wl9ngd5cqsi6ldb0lf6rpnbchzgc0zv4pir88j42i0dhf1036 NarSize: 2161037 References: /build/TestClientFallsBackToClosures3215875446/001/store/0a5kbm0w0si77rdrdaalrzw1fg6fwggp-shared-dep1038 CA: text:sha256:1kvsiwzr15rpnwi653mjdskcxazgbgcxp7whgpxw57gb8r9p0p131039--- PASS: TestClientFallsBackToClosures (1.03s)1040=== CONT TestGCAdvisoryLockBlocksConcurrentRun10412026/10/01 10:45:44 INFO Aborted multipart uploads count=0 kept=01042=== NAME TestClientWithDependencies1043 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies4059969769/001/store/vvwpy7khgl17d7dmvap55xdfmbhrna5v-test-script10442026/10/01 10:45:44 INFO Received push request method=POST path=/api/pushes10452026/10/01 10:45:44 WARN Force mode enabled - objects will be deleted immediately without grace period10462026/10/01 10:45:44 INFO Received push request method=POST path=/api/pushes10472026/10/01 10:45:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33865/oidc10482026/10/01 10:45:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10492026/10/01 10:45:44 INFO Uploading wcrianicvw9ia5kkx868ivp0dx87dk8x-shared-dep (136B)10502026/10/01 10:45:44 INFO Uploading bjaw6qz4fszmwi6yms4bl4by7b1rr5sm-b (216B)10512026/10/01 10:45:44 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10522026/10/01 10:45:44 INFO Uploading 0kxg4wyj1gnwg0m15d89l5i8f58mpng9-shared-dep (136B)10532026/10/01 10:45:44 INFO Uploading gkbags08lgib9w5zqi684fqybp4lbj3a-top (224B)10542026/10/01 10:45:44 WARN Failed to register uploaded object key=0kxg4wyj1gnwg0m15d89l5i8f58mpng9.ls error="server returned 404: 404 page not found\n"10552026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/12jzy40x56lfj2xzv96v6q83639n69h47j9p94ij119h4mgrgx74.nar.zst error="server returned 404: 404 page not found\n"10562026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10572026/10/01 10:45:44 WARN Failed to register uploaded object key=wcrianicvw9ia5kkx868ivp0dx87dk8x.ls error="server returned 404: 404 page not found\n"10582026/10/01 10:45:44 WARN Failed to register uploaded object key=gkbags08lgib9w5zqi684fqybp4lbj3a.ls error="server returned 404: 404 page not found\n"10592026/10/01 10:45:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10602026/10/01 10:45:44 WARN Failed to register uploaded object key=30zjv972wdn6m4nm9as0ydn4vpylbkhz.ls error="server returned 404: 404 page not found\n"10612026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/1i1vngf41npz2jznjr74cir6m034x2ci97wmaf2w7nabb4h37a4l.nar.zst error="server returned 404: 404 page not found\n"10622026/10/01 10:45:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10632026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10642026/10/01 10:45:44 WARN Failed to register uploaded object key=bjaw6qz4fszmwi6yms4bl4by7b1rr5sm.ls error="server returned 404: 404 page not found\n"10652026/10/01 10:45:44 INFO Signed narinfos id=1 count=210662026/10/01 10:45:44 INFO Signed narinfos id=1 count=310672026/10/01 10:45:44 INFO Uploading 2 narinfos10682026/10/01 10:45:44 INFO Uploading 3 narinfos10692026/10/01 10:45:44 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=010702026/10/01 10:45:44 INFO Received complete push request method=POST path=/api/pushes/1/complete10712026/10/01 10:45:44 WARN Failed to register uploaded object key=30zjv972wdn6m4nm9as0ydn4vpylbkhz.narinfo error="server returned 404: 404 page not found\n"10722026/10/01 10:45:44 WARN Failed to register uploaded object key=gkbags08lgib9w5zqi684fqybp4lbj3a.narinfo error="server returned 404: 404 page not found\n"10732026/10/01 10:45:44 WARN Failed to register uploaded object key=0kxg4wyj1gnwg0m15d89l5i8f58mpng9.narinfo error="server returned 404: 404 page not found\n"10742026/10/01 10:45:44 WARN Failed to register uploaded object key=bjaw6qz4fszmwi6yms4bl4by7b1rr5sm.narinfo error="server returned 404: 404 page not found\n"10752026/10/01 10:45:44 INFO Received complete push request method=POST path=/api/pushes/1/complete10762026/10/01 10:45:44 WARN Failed to register uploaded object key=wcrianicvw9ia5kkx868ivp0dx87dk8x.narinfo error="server returned 404: 404 page not found\n"1077--- PASS: TestGetExistingObjectsLocksRows (0.48s)1078=== CONT TestOrphanedObjectsGCStressTest10792026/10/01 10:45:44 INFO Vacuumed table table=pending_closures10802026/10/01 10:45:44 INFO Received push request method=POST path=/api/pushes10812026/10/01 10:45:44 INFO Vacuumed table table=pending_objects10822026/10/01 10:45:44 INFO Vacuumed table table=multipart_uploads10832026/10/01 10:45:44 INFO Vacuumed table table=closures10842026/10/01 10:45:44 INFO Upload complete. (63ms)10852026/10/01 10:45:44 INFO Upload complete. (64ms)10862026/10/01 10:45:44 INFO Vacuumed table table=objects1087=== NAME TestClientSharedPathCommittedMidPush1088 client_integration_test.go:680: Retrieved narinfo from S3:1089 StorePath: /build/TestClientSharedPathCommittedMidPush1898278762/001/store/0kxg4wyj1gnwg0m15d89l5i8f58mpng9-shared-dep1090 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1091 Compression: zstd1092 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821093 NarSize: 1361094 References: 1095 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1096=== NAME TestClientPushesUseOnePush1097 client_pushes_test.go:97: Retrieved narinfo from S3:1098 StorePath: /build/TestClientPushesUseOnePush1176304693/001/store/wcrianicvw9ia5kkx868ivp0dx87dk8x-shared-dep1099 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1100 Compression: zstd1101 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821102 NarSize: 1361103 References: 1104 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1105--- PASS: TestSweepRechecksPendingAfterLocking (0.54s)1106=== CONT TestService_ReadScope_PublicByDefault11072026/10/01 10:45:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11082026/10/01 10:45:44 INFO Uploading hafk8j8ajpkhd7vjdcavdqg1vyvh9j92-pinned-file.txt (128B)1109=== NAME TestClientSharedPathCommittedMidPush1110 client_integration_test.go:680: Retrieved narinfo from S3:1111 StorePath: /build/TestClientSharedPathCommittedMidPush1898278762/001/store/gkbags08lgib9w5zqi684fqybp4lbj3a-top1112 URL: nar/1i1vngf41npz2jznjr74cir6m034x2ci97wmaf2w7nabb4h37a4l.nar.zst1113 Compression: zstd1114 NarHash: sha256:1i1vngf41npz2jznjr74cir6m034x2ci97wmaf2w7nabb4h37a4l1115 NarSize: 2241116 References: /build/TestClientSharedPathCommittedMidPush1898278762/001/store/0kxg4wyj1gnwg0m15d89l5i8f58mpng9-shared-dep1117 CA: text:sha256:121wda6g9s9fnzij1f34f7lkyh14yb4yj5byzws43j5208ki9m611118=== NAME TestClientPushesUseOnePush1119 client_pushes_test.go:97: Retrieved narinfo from S3:1120 StorePath: /build/TestClientPushesUseOnePush1176304693/001/store/30zjv972wdn6m4nm9as0ydn4vpylbkhz-a1121 URL: nar/12jzy40x56lfj2xzv96v6q83639n69h47j9p94ij119h4mgrgx74.nar.zst1122 Compression: zstd1123 NarHash: sha256:12jzy40x56lfj2xzv96v6q83639n69h47j9p94ij119h4mgrgx741124 NarSize: 2161125 References: /build/TestClientPushesUseOnePush1176304693/001/store/wcrianicvw9ia5kkx868ivp0dx87dk8x-shared-dep1126 CA: text:sha256:0wlq5bz9smids21jwx83290vrksm44gj847l2kk4429llrva3cpp1127=== NAME TestClientWithDependencies1128 client_integration_test.go:615: Found 1 dependencies (including self)1129=== NAME TestClientPushesUseOnePush1130 client_pushes_test.go:97: Retrieved narinfo from S3:1131 StorePath: /build/TestClientPushesUseOnePush1176304693/001/store/bjaw6qz4fszmwi6yms4bl4by7b1rr5sm-b1132 URL: nar/12jzy40x56lfj2xzv96v6q83639n69h47j9p94ij119h4mgrgx74.nar.zst1133 Compression: zstd1134 NarHash: sha256:12jzy40x56lfj2xzv96v6q83639n69h47j9p94ij119h4mgrgx741135 NarSize: 2161136 References: /build/TestClientPushesUseOnePush1176304693/001/store/wcrianicvw9ia5kkx868ivp0dx87dk8x-shared-dep1137 CA: text:sha256:0wlq5bz9smids21jwx83290vrksm44gj847l2kk4429llrva3cpp11382026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11392026/10/01 10:45:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11402026/10/01 10:45:44 WARN Failed to register uploaded object key=hafk8j8ajpkhd7vjdcavdqg1vyvh9j92.ls error="server returned 404: 404 page not found\n"1141--- PASS: TestClientSharedPathCommittedMidPush (0.98s)1142=== CONT TestLeadEndsOnShutdown11432026/10/01 10:45:44 INFO Signed narinfos id=1 count=111442026/10/01 10:45:44 INFO Uploading 1 narinfos1145--- PASS: TestClientPushesUseOnePush (1.04s)1146=== CONT TestOrphanedObjectsGC11472026/10/01 10:45:44 INFO Received complete push request method=POST path=/api/pushes/1/complete11482026/10/01 10:45:44 WARN Failed to register uploaded object key=hafk8j8ajpkhd7vjdcavdqg1vyvh9j92.narinfo error="server returned 404: 404 page not found\n"11492026/10/01 10:45:44 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161150--- PASS: TestReadProxyNarinfo (1.02s)1151=== CONT TestService_RequireScope_OIDC11522026/10/01 10:45:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36023/oidc11532026/10/01 10:45:44 INFO Upload complete. (181ms)1154--- PASS: TestPushWaitsForSweepHoldingRow (1.37s)1155=== CONT TestLeadElectsOneAndHandsOver1156=== NAME TestClientIntegration1157 client_integration_test.go:286: Created store path: /build/TestClientIntegration1540643473/002/store/vhf6gslbvc2idqp7nw9b8y4zydfbpv37-test-file.txt1158--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.63s)1159=== CONT TestObjectStatsTrigger11602026/10/01 10:45:44 INFO Received push request method=POST path=/api/pushes11612026/10/01 10:45:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11622026/10/01 10:45:44 INFO Uploading vvwpy7khgl17d7dmvap55xdfmbhrna5v-test-script (136B)11632026/10/01 10:45:44 WARN Failed to register uploaded object key=vvwpy7khgl17d7dmvap55xdfmbhrna5v.ls error="server returned 404: 404 page not found\n"11642026/10/01 10:45:44 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11652026/10/01 10:45:44 WARN Failed to register uploaded object key=log/cffiwm3m887grn67dfbyscighjh1gr8a-test-script.drv error="server returned 404: 404 page not found\n"11662026/10/01 10:45:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11672026/10/01 10:45:44 INFO Signed narinfos id=1 count=111682026/10/01 10:45:44 INFO Uploading 1 narinfos11692026/10/01 10:45:44 INFO Received complete push request method=POST path=/api/pushes/1/complete11702026/10/01 10:45:44 WARN Failed to register uploaded object key=vvwpy7khgl17d7dmvap55xdfmbhrna5v.narinfo error="server returned 404: 404 page not found\n"11712026/10/01 10:45:44 INFO Upload complete. (68ms)11722026/10/01 10:45:44 INFO Received push request method=POST path=/api/pushes1173=== NAME TestClientWithDependencies1174 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4059969769/001/store) requires matching store prefix11752026/10/01 10:45:44 INFO Aborted multipart uploads count=0 kept=011762026/10/01 10:45:44 INFO Received push request method=POST path=/api/pushes11772026/10/01 10:45:44 WARN Force mode enabled - objects will be deleted immediately without grace period1178--- PASS: TestClientWithDependencies (0.91s)1179=== CONT TestService_AuthMiddleware_OIDC11802026/10/01 10:45:45 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=011812026/10/01 10:45:45 INFO Vacuumed table table=pending_closures11822026/10/01 10:45:45 INFO Vacuumed table table=pending_objects11832026/10/01 10:45:45 INFO Vacuumed table table=multipart_uploads11842026/10/01 10:45:45 INFO Vacuumed table table=closures1185--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.37s)1186=== CONT TestConnectWaitsForAPeerMigration11872026/10/01 10:45:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11882026/10/01 10:45:45 INFO Uploading xzhl1f5jimg4sl6wfbw33mi2sb7gjdp7-unpinned-file.txt (128B)11892026/10/01 10:45:45 INFO Vacuumed table table=objects11902026/10/01 10:45:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11912026/10/01 10:45:45 INFO Uploading vhf6gslbvc2idqp7nw9b8y4zydfbpv37-test-file.txt (152B)11922026/10/01 10:45:45 INFO Aborted multipart uploads count=0 kept=011932026/10/01 10:45:45 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11942026/10/01 10:45:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11952026/10/01 10:45:45 WARN Failed to register uploaded object key=xzhl1f5jimg4sl6wfbw33mi2sb7gjdp7.ls error="server returned 404: 404 page not found\n"11962026/10/01 10:45:45 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11972026/10/01 10:45:45 INFO Signed narinfos id=2 count=111982026/10/01 10:45:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11992026/10/01 10:45:45 INFO Uploading 1 narinfos12002026/10/01 10:45:45 WARN Failed to register uploaded object key=vhf6gslbvc2idqp7nw9b8y4zydfbpv37.ls error="server returned 404: 404 page not found\n"12012026/10/01 10:45:45 INFO Signed narinfos id=1 count=112022026/10/01 10:45:45 INFO Uploading 1 narinfos12032026/10/01 10:45:45 WARN Force mode enabled - objects will be deleted immediately without grace period12042026/10/01 10:45:45 INFO Received complete push request method=POST path=/api/pushes/1/complete12052026/10/01 10:45:45 WARN Failed to register uploaded object key=vhf6gslbvc2idqp7nw9b8y4zydfbpv37.narinfo error="server returned 404: 404 page not found\n"12062026/10/01 10:45:45 INFO Received complete push request method=POST path=/api/pushes/2/complete12072026/10/01 10:45:45 WARN Failed to register uploaded object key=xzhl1f5jimg4sl6wfbw33mi2sb7gjdp7.narinfo error="server returned 404: 404 page not found\n"12082026/10/01 10:45:45 INFO Upload complete. (62ms)12092026/10/01 10:45:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=012102026/10/01 10:45:45 INFO Vacuumed table table=pending_closures12112026/10/01 10:45:45 INFO Upload complete. (65ms)12122026/10/01 10:45:45 INFO Vacuumed table table=pending_objects12132026/10/01 10:45:45 INFO Vacuumed table table=multipart_uploads12142026/10/01 10:45:45 INFO Vacuumed table table=closures12152026/10/01 10:45:45 INFO Vacuumed table table=objects12162026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures1217--- PASS: TestSweepSkipsRowsLockedByPush (0.62s)1218=== CONT TestService_ReadAuthMiddleware12192026/10/01 10:45:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures12202026/10/01 10:45:45 INFO Garbage collection started12212026/10/01 10:45:45 INFO All 1 paths already cached1222=== NAME TestClientIntegration1223 client_integration_test.go:312: Retrieved narinfo from S3:1224 StorePath: /build/TestClientIntegration1540643473/002/store/vhf6gslbvc2idqp7nw9b8y4zydfbpv37-test-file.txt1225 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1226 Compression: zstd1227 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11228 NarSize: 1521229 References: 1230 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11231 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1232 client_integration_test.go:313: Decompressed .ls content (64 bytes):1233 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1234 client_integration_test.go:316: Testing garbage collection...12352026/10/01 10:45:45 INFO Aborted multipart uploads count=0 kept=012362026/10/01 10:45:45 WARN Force mode enabled - objects will be deleted immediately without grace period12372026/10/01 10:45:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38653/oidc12382026/10/01 10:45:45 INFO Aborted multipart uploads count=0 kept=012392026/10/01 10:45:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=012402026/10/01 10:45:45 WARN Force mode enabled - objects will be deleted immediately without grace period12412026/10/01 10:45:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures12422026/10/01 10:45:45 INFO Garbage collection started12432026/10/01 10:45:45 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=012442026/10/01 10:45:45 INFO Vacuumed table table=pending_closures12452026/10/01 10:45:45 INFO Vacuumed table table=pending_objects12462026/10/01 10:45:45 INFO Vacuumed table table=multipart_uploads12472026/10/01 10:45:45 INFO Vacuumed table table=closures12482026/10/01 10:45:45 INFO Vacuumed table table=objects12492026/10/01 10:45:45 INFO Vacuumed table table=pending_closures1250--- PASS: TestGCMetrics (0.51s)1251=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12522026/10/01 10:45:45 INFO Aborted multipart uploads count=0 kept=012532026/10/01 10:45:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12542026/10/01 10:45:45 INFO Vacuumed table table=pending_objects12552026/10/01 10:45:45 INFO Vacuumed table table=multipart_uploads12562026/10/01 10:45:45 WARN Force mode enabled - objects will be deleted immediately without grace period12572026/10/01 10:45:45 INFO Vacuumed table table=closures12582026/10/01 10:45:45 INFO Aborted multipart uploads count=0 kept=012592026/10/01 10:45:45 INFO Vacuumed table table=objects1260--- PASS: TestCacheStatsHandler (0.47s)1261=== CONT TestService_AuthMiddleware_MTLSProxyHeader12622026/10/01 10:45:45 WARN Force mode enabled - objects will be deleted immediately without grace period12632026/10/01 10:45:45 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MzgzYmQ5N2UtYjVmMS00NGU0LTllY2EtM2M2ZmFjMTIyYjMzLmQwZTUyY2ExLWUyODUtNDMzYi1iYzM5LTAwZTU2YTdmYTczNngxNzkwODUxNTQ0NjE3OTgzOTU0 error="Get \"http://127.0.0.1:1/bucket20/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12642026/10/01 10:45:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MzgzYmQ5N2UtYjVmMS00NGU0LTllY2EtM2M2ZmFjMTIyYjMzLmJjMmEyMTBlLTNjMWUtNGY3MC1iMGQ0LTg1MTA1N2E5MGUyN3gxNzkwODUxNTQ0NjExMTk3MDUz parts=1212652026/10/01 10:45:45 INFO Received cleanup request method=DELETE path=/api/pending_closures12662026/10/01 10:45:45 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12672026/10/01 10:45:45 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12682026/10/01 10:45:45 INFO Aborted multipart uploads count=1 kept=012692026/10/01 10:45:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=01270--- PASS: TestFailedS3DeleteKeepsTombstone (0.56s)1271=== CONT TestGCSweepDeliversEachKeyOnce1272--- PASS: TestRedundantMultipartUpload (1.87s)1273=== CONT TestPendingCleanupUsesOneCutoff12742026/10/01 10:45:45 INFO Vacuumed table table=pending_closures12752026/10/01 10:45:45 INFO Vacuumed table table=pending_objects1276--- PASS: TestPresentReportsOnlyClosureRoots (0.44s)1277=== CONT TestGCSweepSkipsPendingObjects12782026/10/01 10:45:45 INFO Vacuumed table table=multipart_uploads12792026/10/01 10:45:45 INFO Vacuumed table table=closures12802026/10/01 10:45:45 INFO Vacuumed table table=objects1281=== NAME TestClientCADerivations1282 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2821666896/001/store/nb9wll38dlndvsr1kgx7mq9z1pfb38g9-ca-test1283 client_ca_test.go:139: Found 1 dependencies (including self)1284--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.44s)1285=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded12862026/10/01 10:45:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12872026/10/01 10:45:45 WARN Refused reserved pin name=worker-x86_64-linux12882026/10/01 10:45:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12892026/10/01 10:45:45 INFO Received create pin request method=POST path=/api/pins/my-app12902026/10/01 10:45:45 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1291--- PASS: TestCreatePin_ReservedPins (0.50s)1292=== CONT TestTombstonedObjectOfferedWithoutWaiting1293=== RUN TestService_RequireScope_OIDC/builder_may_write1294=== PAUSE TestService_RequireScope_OIDC/builder_may_write1295=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1296=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1297=== RUN TestService_RequireScope_OIDC/ops_may_admin1298=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1299=== RUN TestService_RequireScope_OIDC/ops_may_not_write1300=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1301=== RUN TestService_RequireScope_OIDC/reader_may_not_write1302=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1303=== RUN TestService_RequireScope_OIDC/static_token_may_admin1304=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1305=== RUN TestService_RequireScope_OIDC/static_token_may_write1306=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1307=== RUN TestService_RequireScope_OIDC/reader_may_read1308=== PAUSE TestService_RequireScope_OIDC/reader_may_read1309=== RUN TestService_RequireScope_OIDC/writer_implies_read1310=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1311=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1312=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1313=== CONT TestForceGCDuringPushOffersSweptObject1314=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1315=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1316=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1317=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1318=== CONT TestUploadHandlersRejectOversizedBody13192026/10/01 10:45:45 INFO Received push request method=POST path=/api/pushes13202026/10/01 10:45:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13212026/10/01 10:45:45 INFO Uploading nb9wll38dlndvsr1kgx7mq9z1pfb38g9-ca-test (144B)13222026/10/01 10:45:45 INFO lead: acquired remote=192.0.2.1:123413232026/10/01 10:45:45 WARN Failed to register uploaded object key=nb9wll38dlndvsr1kgx7mq9z1pfb38g9.ls error="server returned 404: 404 page not found\n"13242026/10/01 10:45:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13252026/10/01 10:45:45 WARN Failed to register uploaded object key=log/qlihivs0vpcyaak3lzijyabkwvcz2z98-ca-test.drv error="server returned 404: 404 page not found\n"13262026/10/01 10:45:45 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13272026/10/01 10:45:45 INFO Signed narinfos id=1 count=113282026/10/01 10:45:45 INFO Uploading 1 narinfos1329--- PASS: TestService_ReadScope_PublicByDefault (0.56s)1330=== CONT TestService_cleanupPendingClosuresHandler13312026/10/01 10:45:45 INFO lead: released remote=192.0.2.1:12341332--- PASS: TestLeadEndsOnShutdown (0.55s)1333=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection13342026/10/01 10:45:45 INFO Received complete push request method=POST path=/api/pushes/1/complete13352026/10/01 10:45:45 WARN Failed to register uploaded object key=nb9wll38dlndvsr1kgx7mq9z1pfb38g9.narinfo error="server returned 404: 404 page not found\n"13362026/10/01 10:45:45 INFO Upload complete. (138ms)1337=== NAME TestClientCADerivations1338 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2821666896/001/store/nb9wll38dlndvsr1kgx7mq9z1pfb38g9-ca-test1339 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1340 Compression: zstd1341 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1342 NarSize: 1441343 References: 1344 Deriver: /build/TestClientCADerivations2821666896/001/store/qlihivs0vpcyaak3lzijyabkwvcz2z98-ca-test.drv1345 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1346 client_ca_test.go:185: Checking for realisation files in S3...1347 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1348 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13492026/10/01 10:45:45 INFO lead: acquired remote=192.0.2.1:12341350--- PASS: TestObjectStatsTrigger (0.44s)1351=== CONT TestIsValidUploadKey1352=== RUN TestIsValidUploadKey/narinfo1353=== PAUSE TestIsValidUploadKey/narinfo1354=== RUN TestIsValidUploadKey/nar_zst1355=== PAUSE TestIsValidUploadKey/nar_zst1356=== RUN TestIsValidUploadKey/nar_xz1357=== PAUSE TestIsValidUploadKey/nar_xz1358=== RUN TestIsValidUploadKey/nar_plain1359=== PAUSE TestIsValidUploadKey/nar_plain1360=== RUN TestIsValidUploadKey/listing1361=== PAUSE TestIsValidUploadKey/listing1362=== RUN TestIsValidUploadKey/build_log1363=== PAUSE TestIsValidUploadKey/build_log1364=== RUN TestIsValidUploadKey/build_log_home-manager_file1365=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1366=== RUN TestIsValidUploadKey/build_log_plus_in_name1367=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1368=== RUN TestIsValidUploadKey/build_log_question_mark1369=== PAUSE TestIsValidUploadKey/build_log_question_mark1370=== RUN TestIsValidUploadKey/build_log_equals1371=== PAUSE TestIsValidUploadKey/build_log_equals1372=== RUN TestIsValidUploadKey/realisation1373=== PAUSE TestIsValidUploadKey/realisation1374=== RUN TestIsValidUploadKey/realisation_plus_in_output1375=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1376=== RUN TestIsValidUploadKey/nix-cache-info1377=== PAUSE TestIsValidUploadKey/nix-cache-info1378=== RUN TestIsValidUploadKey/index.html1379=== PAUSE TestIsValidUploadKey/index.html1380=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1381=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1382=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1383=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1384=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1385=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1386=== RUN TestIsValidUploadKey/traversal1387=== PAUSE TestIsValidUploadKey/traversal1388=== RUN TestIsValidUploadKey/traversal_nar1389=== PAUSE TestIsValidUploadKey/traversal_nar1390=== RUN TestIsValidUploadKey/absolute1391=== PAUSE TestIsValidUploadKey/absolute1392=== RUN TestIsValidUploadKey/empty_key1393=== PAUSE TestIsValidUploadKey/empty_key1394=== RUN TestIsValidUploadKey/unknown_type1395=== PAUSE TestIsValidUploadKey/unknown_type1396=== CONT TestDeduplicatedObjectsRecordedAsPending1397--- PASS: TestService_ReadAuthMiddleware (0.37s)1398=== CONT TestService_healthCheckHandler1399--- PASS: TestGCBugBareHashReferences (0.70s)1400=== CONT TestServerTLSConfig1401=== RUN TestServerTLSConfig/no_client_CA1402=== PAUSE TestServerTLSConfig/no_client_CA1403=== RUN TestServerTLSConfig/missing_CA_file1404=== PAUSE TestServerTLSConfig/missing_CA_file1405=== RUN TestServerTLSConfig/not_a_PEM_file1406=== PAUSE TestServerTLSConfig/not_a_PEM_file1407=== CONT TestGCTaskStore_GetReturnsLatest1408--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1409=== CONT TestMultipartCleanup1410=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1411=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1412=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1413=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1414=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1415=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1416=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1417=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1418=== CONT TestService_NativeMTLS1419=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1420=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1421=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1422=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1423=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1424=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1425=== CONT TestGracefulShutdownDrainsInflight14262026/10/01 10:45:45 INFO Starting HTTP server address=127.0.0.1:3376714272026/10/01 10:45:45 INFO Shutdown signal received, draining in-flight requests timeout=10s14282026/10/01 10:45:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14292026/10/01 10:45:45 WARN mTLS auth: bound subjects configured but subject DN unavailable14302026/10/01 10:45:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1431--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.34s)1432=== CONT TestMetricsInventory1433=== NAME TestClientCADerivations1434 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1435 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1436 error: binary cache 's3://bucket50?endpoint=http://localhost:35289&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2821666896/001/store'1437 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11438--- PASS: TestClientCADerivations (0.88s)1439=== CONT TestGCTaskStore_Fail1440--- PASS: TestGCTaskStore_Fail (0.00s)1441=== CONT TestUploadHandlersRejectInvalidKeys1442=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1443=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1444=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1445=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1446=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1447=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1448=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1449=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1450=== CONT TestGCTaskStore_GetEmpty1451--- PASS: TestGCTaskStore_GetEmpty (0.00s)1452=== CONT TestGCTaskStore_PhaseUpdates1453--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1454=== CONT TestNARDeduplicationMetadataUploadBug1455--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.35s)1456=== CONT TestGCTaskStore_ConflictDifferentParams1457--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1458=== CONT TestPushDedupSurvivesConcurrentGC14592026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures1460--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1461=== CONT TestGCTaskStore_StartNew1462--- PASS: TestGCTaskStore_StartNew (0.00s)1463=== CONT TestGCTaskStore_DeduplicateSameParams1464--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1465=== CONT TestService_readinessHandler1466--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.01s)1467=== CONT TestGenerateLandingPage14682026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures1469--- PASS: TestGenerateLandingPage (0.00s)1470=== CONT TestCacheConfigHandlerMaxNarSize14712026/10/01 10:45:45 INFO Aborted multipart uploads count=0 kept=01472--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1473=== CONT TestCreatePendingClosureRejectsOversizedNAR14742026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures1475--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1476=== CONT TestGCTaskStore_CompletedAllowsNewTask1477--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1478=== CONT TestProxyWriteTimeout/narinfo1479=== CONT TestProxyWriteTimeout/10_GiB_nar1480=== CONT TestProxyWriteTimeout/1_GiB_nar1481=== CONT TestPendingClosureWriteTimeout/empty1482=== CONT TestProxyWriteTimeout/unknown_size1483=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1484--- PASS: TestProxyWriteTimeout (0.00s)1485 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1486 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1487 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1488 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)14892026/10/01 10:45:45 WARN Force mode enabled - objects will be deleted immediately without grace period14902026/10/01 10:45:45 INFO Received cleanup request method=DELETE path=/api/pending_closures14912026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures14922026/10/01 10:45:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=014932026/10/01 10:45:45 INFO Vacuumed table table=pending_closures14942026/10/01 10:45:45 INFO Vacuumed table table=pending_objects14952026/10/01 10:45:45 INFO Vacuumed table table=multipart_uploads14962026/10/01 10:45:45 INFO Vacuumed table table=closures14972026/10/01 10:45:45 INFO Vacuumed table table=objects1498--- PASS: TestGCSweepDeliversEachKeyOnce (0.42s)1499=== CONT TestPendingClosureWriteTimeout/670k_objects1500=== CONT TestPendingClosureWriteTimeout/400_objects1501=== CONT TestResolveDBConnectionString/flag_wins1502=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1503=== CONT TestResolveDBConnectionString/nothing_configured1504=== CONT TestResolveDBConnectionString/missing_file_is_an_error1505=== CONT TestResolveDBConnectionString/file_when_flag_empty1506=== CONT TestIsValidCachePath/narinfo1507=== CONT TestIsValidCachePath/short_hash1508=== CONT TestIsValidCachePath/wrong_extension1509=== CONT TestIsValidCachePath/leading_slash1510=== CONT TestIsValidCachePath/empty1511=== CONT TestIsValidCachePath/random_path1512=== CONT TestIsValidCachePath/invalid_char_u1513=== CONT TestIsValidCachePath/invalid_char_e1514=== CONT TestIsValidCachePath/traversal_in_middle1515=== CONT TestIsValidCachePath/traversal_parent1516=== CONT TestIsValidCachePath/index.html1517=== CONT TestIsValidCachePath/nix-cache-info1518=== CONT TestIsValidCachePath/realisation1519=== CONT TestIsValidCachePath/log1520=== CONT TestIsValidCachePath/ls1521=== CONT TestIsValidCachePath/nar_zst1522=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1523=== CONT TestIsValidCachePath/nar_uncompressed1524=== CONT TestIsValidCachePath/nar_bz21525=== CONT TestIsValidCachePath/nar_xz1526=== CONT TestPush_RejectsBadRequests/no_roots1527--- PASS: TestResolveDBConnectionString (0.00s)1528 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1529 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1530 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1531 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1532 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)15332026/10/01 10:45:45 INFO Received push request method=POST path=/api/pushes1534--- PASS: TestIsValidCachePath (0.00s)1535 --- PASS: TestIsValidCachePath/narinfo (0.00s)1536 --- PASS: TestIsValidCachePath/short_hash (0.00s)1537 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1538 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1539 --- PASS: TestIsValidCachePath/empty (0.00s)1540 --- PASS: TestIsValidCachePath/random_path (0.00s)1541 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1542 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1543 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1544 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1545 --- PASS: TestIsValidCachePath/index.html (0.00s)1546 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1547 --- PASS: TestIsValidCachePath/realisation (0.00s)1548 --- PASS: TestIsValidCachePath/log (0.00s)1549 --- PASS: TestIsValidCachePath/ls (0.00s)1550 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1551 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1552 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1553 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1554 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1555=== CONT TestPush_RejectsBadRequests/root_not_in_objects15562026/10/01 10:45:45 INFO Received push request method=POST path=/api/pushes1557=== CONT TestPush_RejectsBadRequests/bad_root15582026/10/01 10:45:45 INFO Received push request method=POST path=/api/pushes1559=== CONT TestPush_RejectsBadRequests/no_objects15602026/10/01 10:45:45 INFO Received push request method=POST path=/api/pushes1561=== CONT TestParseSingleRange/none1562=== CONT TestParseSingleRange/open-ended1563=== CONT TestParseSingleRange/start_far_past_EOF1564=== CONT TestParseSingleRange/start_past_EOF1565=== CONT TestParseSingleRange/single_byte1566=== CONT TestParseSingleRange/suffix_exceeds_size1567--- PASS: TestPush_RejectsBadRequests (0.92s)1568 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1569 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1570 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1571 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1572=== CONT TestParseSingleRange/suffix1573=== CONT TestParseSingleRange/end_clamped_to_size1574=== CONT TestParseSingleRange/multi-range_ignored1575=== CONT TestParseSingleRange/malformed_no_dash1576=== CONT TestParseSingleRange/closed1577=== CONT TestParseSingleRange/unknown_unit1578=== CONT TestParseSingleRange/malformed_both_empty1579=== CONT TestParseSingleRange/malformed_end_before_start1580--- PASS: TestParseSingleRange (0.00s)1581 --- PASS: TestParseSingleRange/none (0.00s)1582 --- PASS: TestParseSingleRange/open-ended (0.00s)1583 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1584 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1585 --- PASS: TestParseSingleRange/single_byte (0.00s)1586 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1587 --- PASS: TestParseSingleRange/suffix (0.00s)1588 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1589 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1590 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1591 --- PASS: TestParseSingleRange/closed (0.00s)1592 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1593 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1594 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1595=== CONT TestClientErrorHandling/InvalidStorePath15962026/10/01 10:45:45 INFO Aborted multipart uploads count=0 kept=015972026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures15982026/10/01 10:45:45 WARN Force mode enabled - objects will be deleted immediately without grace period15992026/10/01 10:45:45 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=016002026/10/01 10:45:45 INFO Vacuumed table table=pending_closures1601--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.36s)1602=== CONT TestClientErrorHandling/InvalidAuthToken16032026/10/01 10:45:45 INFO Vacuumed table table=pending_objects16042026/10/01 10:45:45 INFO Vacuumed table table=multipart_uploads16052026/10/01 10:45:45 INFO Vacuumed table table=closures16062026/10/01 10:45:45 INFO lead: released remote=192.0.2.1:123416072026/10/01 10:45:45 INFO Vacuumed table table=objects16082026/10/01 10:45:45 INFO lead: acquired remote=192.0.2.1:123416092026/10/01 10:45:45 INFO lead: released remote=192.0.2.1:12341610--- PASS: TestLeadElectsOneAndHandsOver (0.75s)1611=== CONT TestClientErrorHandling/ServerNotAvailable16122026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures1613--- PASS: TestGCSweepSkipsPendingObjects (0.65s)1614=== CONT TestCacheConfigHandler/full_config,_no_issuer1615=== CONT TestCacheConfigHandler/no_signing_keys1616=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1617=== CONT TestCacheConfigHandler/no_cache_url_configured1618--- PASS: TestCacheConfigHandler (0.00s)1619 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1620 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1621 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1622 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1623=== CONT TestService_RequireScope_OIDC/builder_may_write1624=== CONT TestService_RequireScope_OIDC/static_token_may_admin1625=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1626=== CONT TestService_RequireScope_OIDC/writer_implies_read1627=== CONT TestService_RequireScope_OIDC/reader_may_read1628=== CONT TestService_RequireScope_OIDC/static_token_may_write1629=== CONT TestService_RequireScope_OIDC/ops_may_not_write1630=== CONT TestService_RequireScope_OIDC/reader_may_not_write1631=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1632=== CONT TestService_RequireScope_OIDC/ops_may_admin1633=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1634--- PASS: TestService_RequireScope_OIDC (0.43s)1635 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1636 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1637 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1638 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1639 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1640 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1641 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1642 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1643 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1644 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1645--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.57s)1646=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1647=== NAME TestOrphanedObjectsGC1648 orphaned_objects_gc_test.go:290: GC Test Summary:1649 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1650 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1651 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1652 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1653 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1654--- PASS: TestOrphanedObjectsGC (0.99s)1655=== CONT TestIsValidUploadKey/narinfo1656=== CONT TestIsValidUploadKey/absolute1657=== CONT TestIsValidUploadKey/traversal_nar1658=== CONT TestIsValidUploadKey/traversal1659=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1660=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1661=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1662=== CONT TestIsValidUploadKey/empty_key1663=== CONT TestIsValidUploadKey/index.html1664=== CONT TestIsValidUploadKey/nix-cache-info1665=== CONT TestIsValidUploadKey/realisation_plus_in_output1666=== CONT TestIsValidUploadKey/realisation1667=== CONT TestIsValidUploadKey/build_log_equals1668=== CONT TestIsValidUploadKey/build_log_question_mark1669=== CONT TestIsValidUploadKey/build_log_plus_in_name1670=== CONT TestIsValidUploadKey/build_log_home-manager_file1671=== CONT TestIsValidUploadKey/build_log1672=== CONT TestIsValidUploadKey/listing1673=== CONT TestIsValidUploadKey/nar_plain1674=== CONT TestIsValidUploadKey/nar_xz1675=== CONT TestIsValidUploadKey/nar_zst1676=== CONT TestIsValidUploadKey/unknown_type1677=== CONT TestServerTLSConfig/no_client_CA1678=== CONT TestServerTLSConfig/missing_CA_file1679--- PASS: TestIsValidUploadKey (0.00s)1680 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1681 --- PASS: TestIsValidUploadKey/absolute (0.00s)1682 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1683 --- PASS: TestIsValidUploadKey/traversal (0.00s)1684 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1685 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1686 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1687 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1688 --- PASS: TestIsValidUploadKey/index.html (0.00s)1689 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1690 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1691 --- PASS: TestIsValidUploadKey/realisation (0.00s)1692 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1693 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1694 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1695 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1696 --- PASS: TestIsValidUploadKey/build_log (0.00s)1697 --- PASS: TestIsValidUploadKey/listing (0.00s)1698 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1699 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1700 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1701 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1702=== CONT TestServerTLSConfig/not_a_PEM_file1703--- PASS: TestServerTLSConfig (0.00s)1704 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1705 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1706 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1707=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1708=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17092026/10/01 10:45:45 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1710=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured17112026/10/01 10:45:45 INFO Received cleanup request method=DELETE path=/api/pending_closures1712=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17132026/10/01 10:45:45 INFO Aborted multipart uploads count=0 kept=017142026/10/01 10:45:45 WARN Authentication failed token_preview=eyJhbGciOi...sn3TkLGZ7g token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1715=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17162026/10/01 10:45:45 INFO Received uploads request method=POST path=/1717--- PASS: TestService_AuthMiddleware_OIDC (0.42s)1718 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1719 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1720 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1721 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)17222026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures17232026/10/01 10:45:45 INFO Received cleanup request method=DELETE path=/api/pending_closures17242026/10/01 10:45:45 INFO Aborted multipart uploads count=1 kept=017252026/10/01 10:45:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17262026-10-01 10:45:45.814 UTC [1439] ERROR: Closure does not exist: id=117272026-10-01 10:45:45.814 UTC [1439] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE17282026-10-01 10:45:45.814 UTC [1439] STATEMENT: -- name: CommitPendingClosure :exec1729 SELECT commit_pending_closure($1::bigint)1730 1731--- PASS: TestService_cleanupPendingClosuresHandler (0.47s)1732=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17332026/10/01 10:45:45 INFO Received request for more parts method=POST path=/17342026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures17352026/10/01 10:45:45 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/present17362026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures1737--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.45s)1738=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17392026/10/01 10:45:45 INFO Received complete multipart upload request method=POST path=/1740--- PASS: TestService_healthCheckHandler (0.46s)1741=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17422026/10/01 10:45:45 INFO Received uploads request method=POST path=/1743=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17442026/10/01 10:45:45 INFO Received request for more parts method=POST path=/1745=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17462026/10/01 10:45:45 INFO Received complete multipart upload request method=POST path=/1747=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17482026/10/01 10:45:45 INFO Received uploads request method=POST path=/1749--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1750 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1751 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1752 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1753 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)17542026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures17552026/10/01 10:45:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17562026/10/01 10:45:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1757--- PASS: TestService_NativeMTLS (0.48s)1758--- PASS: TestMetricsInventory (0.49s)17592026/10/01 10:45:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.984217ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17602026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures17612026/10/01 10:45:45 WARN readiness check failed error="closed pool"1762--- PASS: TestService_readinessHandler (0.46s)1763=== NAME TestNARDeduplicationMetadataUploadBug1764 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3175730507/001/store/iaip38v0mm03vznq38845xlwdb1j0vyr-file1.txt17652026/10/01 10:45:45 INFO Received uploads request method=POST path=/api/pending_closures17662026/10/01 10:45:45 INFO Received cleanup request method=DELETE path=/api/pending_closures17672026/10/01 10:45:45 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket77/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""17682026/10/01 10:45:45 INFO Aborted multipart uploads count=0 kept=117692026/10/01 10:45:45 INFO Received cleanup request method=DELETE path=/api/pending_closures17702026/10/01 10:45:45 INFO Aborted multipart uploads count=1 kept=01771--- PASS: TestMultipartCleanup (0.60s)17722026/10/01 10:45:46 INFO Aborted multipart uploads count=0 kept=017732026/10/01 10:45:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017742026/10/01 10:45:46 INFO Vacuumed table table=pending_closures17752026/10/01 10:45:46 INFO Vacuumed table table=pending_objects1776--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.69s)17772026/10/01 10:45:46 INFO Vacuumed table table=multipart_uploads17782026/10/01 10:45:46 INFO Received uploads request method=POST path=/api/pending_closures17792026/10/01 10:45:46 INFO Vacuumed table table=closures17802026/10/01 10:45:46 INFO Received push request method=POST path=/api/pushes17812026/10/01 10:45:46 INFO Vacuumed table table=objects17822026/10/01 10:45:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17832026/10/01 10:45:46 INFO Uploading iaip38v0mm03vznq38845xlwdb1j0vyr-file1.txt (160B)17842026/10/01 10:45:46 INFO Aborted multipart uploads count=0 kept=017852026/10/01 10:45:46 INFO Aborted multipart uploads count=0 kept=017862026/10/01 10:45:46 WARN Force mode enabled - objects will be deleted immediately without grace period17872026/10/01 10:45:46 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=017882026/10/01 10:45:46 WARN Force mode enabled - objects will be deleted immediately without grace period17892026/10/01 10:45:46 INFO Vacuumed table table=pending_closures17902026/10/01 10:45:46 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17912026/10/01 10:45:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17922026/10/01 10:45:46 WARN Failed to register uploaded object key=iaip38v0mm03vznq38845xlwdb1j0vyr.ls error="server returned 404: 404 page not found\n"17932026/10/01 10:45:46 INFO Vacuumed table table=pending_objects17942026/10/01 10:45:46 INFO Signed narinfos id=1 count=117952026/10/01 10:45:46 INFO Vacuumed table table=multipart_uploads17962026/10/01 10:45:46 INFO Uploading 1 narinfos17972026/10/01 10:45:46 INFO Vacuumed table table=closures17982026/10/01 10:45:46 INFO Vacuumed table table=objects1799--- PASS: TestPushDedupSurvivesConcurrentGC (0.59s)18002026/10/01 10:45:46 INFO Received complete push request method=POST path=/api/pushes/1/complete18012026/10/01 10:45:46 WARN Failed to register uploaded object key=iaip38v0mm03vznq38845xlwdb1j0vyr.narinfo error="server returned 404: 404 page not found\n"18022026/10/01 10:45:46 INFO Received uploads request method=POST path=/api/pending_closures18032026/10/01 10:45:46 INFO Upload complete. (52ms)18042026/10/01 10:45:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=01805=== NAME TestNARDeduplicationMetadataUploadBug1806 metadata_upload_test.go:54: Retrieved narinfo from S3:1807 StorePath: /build/TestNARDeduplicationMetadataUploadBug3175730507/001/store/iaip38v0mm03vznq38845xlwdb1j0vyr-file1.txt1808 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1809 Compression: zstd1810 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1811 NarSize: 1601812 References: 1813 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf18142026/10/01 10:45:46 INFO Vacuumed table table=pending_closures18152026/10/01 10:45:46 INFO Vacuumed table table=pending_objects18162026/10/01 10:45:46 INFO Vacuumed table table=multipart_uploads18172026/10/01 10:45:46 INFO Vacuumed table table=closures1818 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1819 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1820 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18212026/10/01 10:45:46 INFO Vacuumed table table=objects18222026/10/01 10:45:46 INFO Aborted multipart uploads count=0 kept=018232026/10/01 10:45:46 WARN Force mode enabled - objects will be deleted immediately without grace period18242026/10/01 10:45:46 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=018252026/10/01 10:45:46 INFO Vacuumed table table=pending_closures18262026/10/01 10:45:46 INFO Vacuumed table table=pending_objects18272026/10/01 10:45:46 INFO Vacuumed table table=multipart_uploads18282026/10/01 10:45:46 INFO Vacuumed table table=closures18292026/10/01 10:45:46 INFO Vacuumed table table=objects18302026/10/01 10:45:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1831--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1832 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.29s)1833 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.29s)1834=== NAME TestNARDeduplicationMetadataUploadBug1835 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3175730507/001/store/cbffmdldinng716z5hzz2zcl42nr2nd3-file2.txt18362026/10/01 10:45:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.940701ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18372026/10/01 10:45:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18382026/10/01 10:45:46 INFO Received push request method=POST path=/api/pushes18392026/10/01 10:45:46 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18402026/10/01 10:45:46 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18412026/10/01 10:45:46 WARN Failed to register uploaded object key=cbffmdldinng716z5hzz2zcl42nr2nd3.ls error="server returned 404: 404 page not found\n"18422026/10/01 10:45:46 INFO Signed narinfos id=2 count=118432026/10/01 10:45:46 INFO Uploading 1 narinfos18442026/10/01 10:45:46 INFO Received complete push request method=POST path=/api/pushes/2/complete18452026/10/01 10:45:46 WARN Failed to register uploaded object key=cbffmdldinng716z5hzz2zcl42nr2nd3.narinfo error="server returned 404: 404 page not found\n"18462026/10/01 10:45:46 INFO Upload complete. (47ms)1847 metadata_upload_test.go:76: Retrieved narinfo from S3:1848 StorePath: /build/TestNARDeduplicationMetadataUploadBug3175730507/001/store/cbffmdldinng716z5hzz2zcl42nr2nd3-file2.txt1849 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1850 Compression: zstd1851 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1852 NarSize: 1601853 References: 1854 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1855 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1856 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1857 {"version":1,"root":{"type":"regular","size":44}}1858--- PASS: TestNARDeduplicationMetadataUploadBug (0.73s)18592026/10/01 10:45:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=798.189959ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1860=== NAME TestOrphanedObjectsGCStressTest1861 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1862 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1863--- PASS: TestPendingClosureWriteTimeout (0.01s)1864 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1865 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1866 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1867 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.27s)1868--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)1869 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1870 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1871 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.00s)1872=== NAME TestOrphanedObjectsGCStressTest1873 orphaned_objects_gc_test.go:509: Stress test completed successfully:1874 orphaned_objects_gc_test.go:510: - Active objects preserved: 201875 orphaned_objects_gc_test.go:511: - Objects deleted: 2101876 orphaned_objects_gc_test.go:512: - Total GC'd: 2101877--- PASS: TestOrphanedObjectsGCStressTest (2.08s)18782026/10/01 10:45:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018792026/10/01 10:45:47 INFO Received create pin request method=POST path=/api/pins/myapp18802026/10/01 10:45:47 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3623122829/001/store/hafk8j8ajpkhd7vjdcavdqg1vyvh9j92-pinned-file.txt narinfo_key=hafk8j8ajpkhd7vjdcavdqg1vyvh9j92.narinfo18812026/10/01 10:45:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures18822026/10/01 10:45:47 INFO Garbage collection started18832026/10/01 10:45:47 INFO Aborted multipart uploads count=0 kept=018842026/10/01 10:45:47 WARN Force mode enabled - objects will be deleted immediately without grace period18852026/10/01 10:45:47 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=018862026/10/01 10:45:47 INFO Vacuumed table table=pending_closures18872026/10/01 10:45:47 INFO Vacuumed table table=pending_objects18882026/10/01 10:45:47 INFO Vacuumed table table=multipart_uploads18892026/10/01 10:45:47 INFO Vacuumed table table=closures18902026/10/01 10:45:47 INFO Vacuumed table table=objects18912026/10/01 10:45:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01892=== NAME TestClientIntegration1893 client_integration_test.go:323: Objects in database after GC:1894 client_integration_test.go:323: Successfully deleted all objects with GC --force1895--- PASS: TestClientIntegration (2.79s)18962026/10/01 10:45:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.703692413s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18972026/10/01 10:45:47 WARN Rate limiter enabled after throttle name=s3-test rate=518982026/10/01 10:45:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1899=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1900 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101901 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001902--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.73s)1903--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.98s)1904=== NAME TestPinProtectsFromGC1905 client_integration_test.go:840: Pin successfully protected closure from garbage collection1906--- PASS: TestPinProtectsFromGC (5.27s)19072026/10/01 10:45:49 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-config19082026/10/01 10:45:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.935242ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19092026/10/01 10:45:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.328394ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19102026/10/01 10:45:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=775.429113ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1911--- PASS: TestConnectWaitsForAPeerMigration (5.13s)19122026/10/01 10:45:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.44117405s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19132026/10/01 10:45:51 INFO Aborted multipart uploads count=1 kept=019142026/10/01 10:45:51 INFO Received cleanup request method=DELETE path=/api/pending_closures19152026/10/01 10:45:51 INFO Aborted multipart uploads count=1 kept=01916--- PASS: TestPendingCleanupUsesOneCutoff (6.41s)19172026/10/01 10:45:52 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"19182026/10/01 10:45:52 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-config19192026/10/01 10:45:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.869954ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19202026/10/01 10:45:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.83388ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19212026/10/01 10:45:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=770.835768ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19222026/10/01 10:45:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.49394308s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19232026/10/01 10:45:54 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_closures19242026/10/01 10:45:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.326153ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19252026/10/01 10:45:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.503887ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19262026/10/01 10:45:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=860.246526ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19272026/10/01 10:45:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.70928624s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1928--- PASS: TestClientErrorHandling (0.00s)1929 --- PASS: TestClientErrorHandling/InvalidStorePath (0.49s)1930 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.56s)1931 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.64s)1932PASS1933{"timestamp":"2026-10-01T10:45:58.307671516Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:50708","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(199)"}19342026-10-01 10:45:58.543 UTC [130] LOG: received smart shutdown request19352026-10-01 10:45:58.547 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 119362026-10-01 10:45:58.559 UTC [135] LOG: shutting down19372026-10-01 10:45:58.559 UTC [135] LOG: checkpoint starting: shutdown immediate19382026-10-01 10:45:59.417 UTC [135] LOG: checkpoint complete: wrote 11024 buffers (67.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.188 s, sync=0.642 s, total=0.859 s; sync files=29656, longest=0.002 s, average=0.001 s; distance=410243 kB, estimate=410243 kB; lsn=0/1A806998, redo lsn=0/1A80699819392026-10-01 10:45:59.492 UTC [130] LOG: database system is shut down1940Running OIDC tests...1941=== RUN TestAudienceForIssuer1942=== PAUSE TestAudienceForIssuer1943=== RUN TestGlobMatch1944=== PAUSE TestGlobMatch1945=== RUN TestValidateToken_ValidToken1946=== PAUSE TestValidateToken_ValidToken1947=== RUN TestValidateToken_WrongAudience1948=== PAUSE TestValidateToken_WrongAudience1949=== RUN TestValidateToken_Expired1950=== PAUSE TestValidateToken_Expired1951=== RUN TestValidateToken_BoundClaimsMismatch1952=== PAUSE TestValidateToken_BoundClaimsMismatch1953=== RUN TestValidateToken_BoundSubjectMismatch1954=== PAUSE TestValidateToken_BoundSubjectMismatch1955=== RUN TestValidateToken_MultipleProviders1956=== PAUSE TestValidateToken_MultipleProviders1957=== RUN TestValidateToken_NoMatchingProvider1958=== PAUSE TestValidateToken_NoMatchingProvider1959=== RUN TestValidateToken_KubernetesServiceAccount1960=== PAUSE TestValidateToken_KubernetesServiceAccount1961=== RUN TestNewValidator_KubernetesRequiresCA1962=== PAUSE TestNewValidator_KubernetesRequiresCA1963=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1964=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1965=== RUN TestPins_ReservedForMatchingRule1966=== PAUSE TestPins_ReservedForMatchingRule1967=== RUN TestPins_TopLevelShorthand1968=== PAUSE TestPins_TopLevelShorthand1969=== RUN TestPins_ConfigValidation1970=== PAUSE TestPins_ConfigValidation1971=== RUN TestScopes_LegacyProviderDefaultsToWrite1972=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1973=== RUN TestScopes_Rules1974=== PAUSE TestScopes_Rules1975=== RUN TestScopes_ConfigValidation1976=== PAUSE TestScopes_ConfigValidation1977=== CONT TestAudienceForIssuer1978=== CONT TestValidateToken_BoundClaimsMismatch1979--- PASS: TestAudienceForIssuer (0.00s)1980=== CONT TestValidateToken_ValidToken1981=== CONT TestScopes_LegacyProviderDefaultsToWrite1982=== CONT TestValidateToken_WrongAudience1983=== CONT TestValidateToken_MultipleProviders1984=== CONT TestValidateToken_NoMatchingProvider1985=== CONT TestPins_ReservedForMatchingRule1986=== CONT TestPins_ConfigValidation1987=== CONT TestValidateToken_Expired1988=== CONT TestValidateToken_BoundSubjectMismatch1989=== CONT TestPins_TopLevelShorthand1990=== CONT TestValidateToken_KubernetesIssuerFromOwnToken1991=== CONT TestNewValidator_KubernetesRequiresCA1992=== CONT TestGlobMatch1993=== RUN TestGlobMatch/foo_foo1994=== PAUSE TestGlobMatch/foo_foo1995=== CONT TestValidateToken_KubernetesServiceAccount1996=== CONT TestScopes_ConfigValidation1997--- PASS: TestPins_ConfigValidation (0.00s)1998=== CONT TestScopes_Rules1999=== RUN TestGlobMatch/foo_bar2000=== PAUSE TestGlobMatch/foo_bar2001=== RUN TestGlobMatch/*_2002=== PAUSE TestGlobMatch/*_2003=== RUN TestGlobMatch/*_anything2004=== PAUSE TestGlobMatch/*_anything2005=== RUN TestGlobMatch/foo*_foo2006=== PAUSE TestGlobMatch/foo*_foo2007=== RUN TestGlobMatch/foo*_foobar2008=== PAUSE TestGlobMatch/foo*_foobar2009=== RUN TestGlobMatch/foo*_bar2010=== PAUSE TestGlobMatch/foo*_bar2011=== RUN TestGlobMatch/*bar_bar2012=== PAUSE TestGlobMatch/*bar_bar2013=== RUN TestGlobMatch/*bar_foobar2014=== PAUSE TestGlobMatch/*bar_foobar2015=== RUN TestGlobMatch/*bar_foo2016=== PAUSE TestGlobMatch/*bar_foo2017=== RUN TestGlobMatch/foo*bar_foobar2018=== PAUSE TestGlobMatch/foo*bar_foobar2019=== RUN TestGlobMatch/foo*bar_foo123bar2020=== PAUSE TestGlobMatch/foo*bar_foo123bar2021=== RUN TestGlobMatch/foo*bar_foobarbaz2022=== PAUSE TestGlobMatch/foo*bar_foobarbaz2023=== RUN TestGlobMatch/*/*_foo/bar2024=== PAUSE TestGlobMatch/*/*_foo/bar2025=== RUN TestGlobMatch/*/*_foo2026=== PAUSE TestGlobMatch/*/*_foo2027=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2028=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2029=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02030=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02031=== RUN TestGlobMatch/refs/*/main_refs/heads/main2032=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2033--- PASS: TestScopes_ConfigValidation (0.00s)2034=== RUN TestGlobMatch/fo?_foo2035=== PAUSE TestGlobMatch/fo?_foo2036=== RUN TestGlobMatch/fo?_fo2037=== PAUSE TestGlobMatch/fo?_fo2038=== RUN TestGlobMatch/fo?_fooo2039=== PAUSE TestGlobMatch/fo?_fooo2040=== RUN TestGlobMatch/?oo_foo2041=== PAUSE TestGlobMatch/?oo_foo2042=== RUN TestGlobMatch/?oo_boo2043=== PAUSE TestGlobMatch/?oo_boo2044=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2045=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2046=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2047=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2048=== CONT TestGlobMatch/foo_foo2049=== CONT TestGlobMatch/?oo_boo2050=== CONT TestGlobMatch/?oo_foo2051=== CONT TestGlobMatch/fo?_fooo2052=== CONT TestGlobMatch/fo?_fo2053=== CONT TestGlobMatch/fo?_foo2054=== CONT TestGlobMatch/*bar_foo2055=== CONT TestGlobMatch/foo*bar_foo123bar2056=== CONT TestGlobMatch/foo*bar_foobar2057=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2058=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02059=== CONT TestGlobMatch/*/*_foo2060=== CONT TestGlobMatch/*bar_foobar2061=== CONT TestGlobMatch/*bar_bar2062=== CONT TestGlobMatch/*/*_foo/bar2063=== CONT TestGlobMatch/foo*_bar2064=== CONT TestGlobMatch/foo*_foobar2065=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2066=== CONT TestGlobMatch/foo*bar_foobarbaz2067=== CONT TestGlobMatch/foo*_foo2068=== CONT TestGlobMatch/*_anything2069=== CONT TestGlobMatch/*_2070=== CONT TestGlobMatch/foo_bar2071=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2072=== CONT TestGlobMatch/refs/*/main_refs/heads/main2073--- PASS: TestGlobMatch (0.00s)2074 --- PASS: TestGlobMatch/foo_foo (0.00s)2075 --- PASS: TestGlobMatch/?oo_boo (0.00s)2076 --- PASS: TestGlobMatch/?oo_foo (0.00s)2077 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2078 --- PASS: TestGlobMatch/fo?_fo (0.00s)2079 --- PASS: TestGlobMatch/fo?_foo (0.00s)2080 --- PASS: TestGlobMatch/*bar_foo (0.00s)2081 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2082 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2083 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2084 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2085 --- PASS: TestGlobMatch/*/*_foo (0.00s)2086 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2087 --- PASS: TestGlobMatch/*bar_bar (0.00s)2088 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2089 --- PASS: TestGlobMatch/foo*_bar (0.00s)2090 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2091 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2092 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2093 --- PASS: TestGlobMatch/foo*_foo (0.00s)2094 --- PASS: TestGlobMatch/*_anything (0.00s)2095 --- PASS: TestGlobMatch/*_ (0.00s)2096 --- PASS: TestGlobMatch/foo_bar (0.00s)2097 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2098 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)20992026/10/01 10:46:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41697/oidc2100--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.05s)21012026/10/01 10:46:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42897/oidc21022026/10/01 10:46:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46071/oidc2103--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)2104--- PASS: TestScopes_Rules (0.07s)21052026/10/01 10:46:00 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:392472106--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)21072026/10/01 10:46:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45573/oidc2108--- PASS: TestPins_TopLevelShorthand (0.12s)21092026/10/01 10:46:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39881/oidc2110--- PASS: TestValidateToken_WrongAudience (0.18s)21112026/10/01 10:46:01 http: TLS handshake error from 127.0.0.1:49318: remote error: tls: bad certificate2112--- PASS: TestNewValidator_KubernetesRequiresCA (0.19s)21132026/10/01 10:46:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37067/oidc2114--- PASS: TestValidateToken_NoMatchingProvider (0.20s)21152026/10/01 10:46:01 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232116--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.21s)21172026/10/01 10:46:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40643/oidc2118--- PASS: TestPins_ReservedForMatchingRule (0.22s)21192026/10/01 10:46:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36953/oidc2120--- PASS: TestValidateToken_ValidToken (0.23s)21212026/10/01 10:46:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36977/oidc21222026/10/01 10:46:01 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37643/oidc2123--- PASS: TestValidateToken_MultipleProviders (0.25s)21242026/10/01 10:46:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41763/oidc2125--- PASS: TestValidateToken_BoundSubjectMismatch (0.26s)21262026/10/01 10:46:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36623/oidc2127--- PASS: TestValidateToken_Expired (0.34s)2128PASS2129Running hook tests...2130=== RUN TestSendPathsEmpty2131=== PAUSE TestSendPathsEmpty2132=== RUN TestQueueEnqueueAndFetch2133=== PAUSE TestQueueEnqueueAndFetch2134=== RUN TestQueueDeduplication2135=== PAUSE TestQueueDeduplication2136=== RUN TestQueueRemove2137=== PAUSE TestQueueRemove2138=== RUN TestQueueFetchBatchLimit2139=== PAUSE TestQueueFetchBatchLimit2140=== RUN TestQueueRetryMovesToBack2141=== PAUSE TestQueueRetryMovesToBack2142=== RUN TestQueueFetchRemoveLifecycle2143=== PAUSE TestQueueFetchRemoveLifecycle2144=== RUN TestQueueConcurrentWriters2145=== PAUSE TestQueueConcurrentWriters2146=== RUN TestQueueRemoveLargeClosure2147=== PAUSE TestQueueRemoveLargeClosure2148=== RUN TestServerClientIntegration2149=== PAUSE TestServerClientIntegration2150=== RUN TestServerQueueError2151=== PAUSE TestServerQueueError2152=== RUN TestGetListenerSocketActivation2153 server_test.go:210: === RUN TestGetListenerSocketActivation2154 --- PASS: TestGetListenerSocketActivation (0.00s)2155 PASS2156 2157--- PASS: TestGetListenerSocketActivation (0.01s)2158=== RUN TestDrainIsolatesPoisonPath2159=== PAUSE TestDrainIsolatesPoisonPath2160=== RUN TestRunNotBlockedByPoisonHead2161=== PAUSE TestRunNotBlockedByPoisonHead2162=== RUN TestDrainGivesUpWhenServerDown2163=== PAUSE TestDrainGivesUpWhenServerDown2164=== RUN TestFailedPathPrunedByLaterClosure2165=== PAUSE TestFailedPathPrunedByLaterClosure2166=== RUN TestWorkerUploadsAndRemoves2167=== PAUSE TestWorkerUploadsAndRemoves2168=== RUN TestWorkerSkipsGCdPaths2169=== PAUSE TestWorkerSkipsGCdPaths2170=== RUN TestWorkerPrunesClosureDeps2171=== PAUSE TestWorkerPrunesClosureDeps2172=== RUN TestDrainTimeout2173=== PAUSE TestDrainTimeout2174=== CONT TestSendPathsEmpty2175=== CONT TestServerQueueError2176=== CONT TestWorkerUploadsAndRemoves2177=== CONT TestDrainGivesUpWhenServerDown2178=== CONT TestQueueFetchBatchLimit2179=== CONT TestQueueRemove2180=== CONT TestQueueDeduplication2181=== CONT TestQueueRetryMovesToBack21822026/10/01 10:46:01 ERROR Failed to queue paths error="permission denied" count=12183=== CONT TestQueueEnqueueAndFetch2184=== CONT TestServerClientIntegration2185=== CONT TestQueueRemoveLargeClosure2186=== CONT TestQueueConcurrentWriters2187=== CONT TestQueueFetchRemoveLifecycle2188=== CONT TestRunNotBlockedByPoisonHead2189=== CONT TestDrainIsolatesPoisonPath2190=== CONT TestWorkerPrunesClosureDeps2191=== CONT TestDrainTimeout2192=== CONT TestWorkerSkipsGCdPaths2193=== CONT TestFailedPathPrunedByLaterClosure2194--- PASS: TestSendPathsEmpty (0.00s)2195--- PASS: TestServerQueueError (0.00s)2196--- PASS: TestServerClientIntegration (0.00s)21972026/10/01 10:46:01 INFO Upload queue status pending=221982026/10/01 10:46:01 INFO Uploading batch count=421992026/10/01 10:46:01 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths606525224/002/nonexistent22002026/10/01 10:46:01 INFO Uploading batch count=122012026/10/01 10:46:01 ERROR Upload failed error="upload failed" count=422022026/10/01 10:46:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1239481732/002/bbb22032026/10/01 10:46:01 INFO Upload queue status pending=222042026/10/01 10:46:01 INFO Uploading batch count=222052026/10/01 10:46:01 INFO Uploading batch count=122062026/10/01 10:46:01 INFO Upload queue status pending=322072026/10/01 10:46:01 INFO Uploading batch count=122082026/10/01 10:46:01 ERROR Upload failed error="upload failed" count=122092026/10/01 10:46:01 INFO Uploading batch count=122102026/10/01 10:46:01 ERROR Upload failed error="upload failed" count=12211--- PASS: TestQueueRemove (0.01s)2212--- PASS: TestQueueFetchBatchLimit (0.01s)2213--- PASS: TestQueueFetchRemoveLifecycle (0.01s)22142026/10/01 10:46:01 INFO Uploading batch count=122152026/10/01 10:46:01 ERROR Upload failed error="upload failed" count=122162026/10/01 10:46:01 INFO Uploading batch count=122172026/10/01 10:46:01 INFO Uploading batch count=222182026/10/01 10:46:01 INFO Upload queue status pending=22219--- PASS: TestQueueRetryMovesToBack (0.01s)22202026/10/01 10:46:01 ERROR Upload failed error="upload failed" count=222212026/10/01 10:46:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3542317536/002/a22222026/10/01 10:46:01 INFO Uploading batch count=122232026/10/01 10:46:01 ERROR Upload failed error="upload failed" count=122242026/10/01 10:46:01 INFO Uploading batch count=22225--- PASS: TestQueueEnqueueAndFetch (0.01s)2226--- PASS: TestQueueDeduplication (0.01s)22272026/10/01 10:46:01 INFO Uploading batch count=122282026/10/01 10:46:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3542317536/002/b22292026/10/01 10:46:01 INFO Uploading batch count=122302026/10/01 10:46:01 ERROR Upload failed error="upload failed" count=122312026/10/01 10:46:01 INFO Uploading batch count=222322026/10/01 10:46:01 ERROR Upload failed error="upload failed" count=222332026/10/01 10:46:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3542317536/002/c22342026/10/01 10:46:01 ERROR Drain finished with paths left in queue remaining=122352026/10/01 10:46:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3542317536/002/d2236--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)22372026/10/01 10:46:01 INFO Uploading batch count=222382026/10/01 10:46:01 ERROR Upload failed error="upload failed" count=222392026/10/01 10:46:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3542317536/002/e22402026/10/01 10:46:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3542317536/002/f2241--- PASS: TestDrainIsolatesPoisonPath (0.01s)22422026/10/01 10:46:01 ERROR Drain finished with paths left in queue remaining=102243--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2244--- PASS: TestWorkerSkipsGCdPaths (0.03s)2245--- PASS: TestWorkerPrunesClosureDeps (0.03s)2246--- PASS: TestWorkerUploadsAndRemoves (0.03s)2247--- PASS: TestQueueRemoveLargeClosure (0.14s)2248--- PASS: TestQueueConcurrentWriters (0.21s)22492026/10/01 10:46:01 ERROR Upload failed error="context deadline exceeded" count=222502026/10/01 10:46:01 ERROR Drain finished with paths left in queue remaining=42251--- PASS: TestDrainTimeout (0.21s)22522026/10/01 10:46:02 INFO Uploading batch count=122532026/10/01 10:46:02 INFO Uploading batch count=122542026/10/01 10:46:02 INFO Uploading batch count=122552026/10/01 10:46:02 ERROR Upload failed error="upload failed" count=122562026/10/01 10:46:02 INFO Uploading batch count=122572026/10/01 10:46:02 ERROR Upload failed error="upload failed" count=122582026/10/01 10:46:02 INFO Uploading batch count=122592026/10/01 10:46:02 ERROR Upload failed error="upload failed" count=122602026/10/01 10:46:02 INFO Uploading batch count=122612026/10/01 10:46:02 ERROR Upload failed error="upload failed" count=122622026/10/01 10:46:02 ERROR Drain finished with paths left in queue remaining=12263--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2264PASS