niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #343
· 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 TestScriptTokenEmptyCommand97--- PASS: TestScriptTokenEmptyCommand (0.00s)98=== CONT TestShellSplit99=== CONT TestScriptTokenScriptFails100=== CONT TestScriptTokenBadJSON101=== CONT TestSetClientTLS102=== CONT TestClientSignaturesByStorePath103=== CONT TestPathInfoCACompatibility104=== RUN TestPathInfoCACompatibility/null_ca_field105=== PAUSE TestPathInfoCACompatibility/null_ca_field106=== CONT TestStreamPushReportsSignatures107=== CONT TestStreamPushRequestLine108=== CONT TestStreamPushGivesUpOnDeadServer109=== CONT TestStreamPushIsolatesFailures110=== CONT TestFileTokenReadsAndCaches111=== CONT TestEncodeNixBase32WithRealHash112=== CONT TestStreamPushBatchesUnderLoad113=== CONT TestDoWithRetry_BodyReplayedViaGetBody114=== CONT TestStreamPushReportsEveryPath115=== CONT TestResolveStorePath116=== CONT TestShellSplitErrors117=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess118=== CONT TestFileTokenEmpty119=== CONT TestPathInfoHashCompatibility120=== CONT TestScriptTokenEmptyToken121=== CONT TestGetStorePathHash122=== CONT TestScriptTokenCachesUntilRefresh123=== CONT TestSetClientTLSDoesNotMutateDefaultTransport124=== CONT TestConvertHashToNix32125--- PASS: TestShellSplit (0.00s)126=== CONT TestScriptTokenNoExpiryRerunsEveryCall127=== RUN TestPathInfoCACompatibility/old_string_format_-_text128=== CONT TestRateLimiterFeedback129=== CONT TestFileTokenMissing130=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)131=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)132=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon133=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon134--- PASS: TestClientSignaturesByStorePath (0.00s)135=== RUN TestGetStorePathHash/valid_store_path1362026/10/01 10:41:30 ERROR Upload failed error="connection refused" count=201372026/10/01 10:41:30 ERROR Server seems unavailable, giving up on batch untried=17138=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI139=== RUN TestConvertHashToNix32/SRI_format_to_Nix32140--- PASS: TestScriptTokenScriptFails (0.00s)141--- PASS: TestShellSplitErrors (0.00s)142--- PASS: TestEncodeNixBase32WithRealHash (0.00s)143=== RUN TestRateLimiterFeedback/429_enables_limiter144--- PASS: TestFileTokenMissing (0.00s)145--- PASS: TestFileTokenReadsAndCaches (0.00s)146--- PASS: TestFileTokenEmpty (0.00s)147=== CONT TestEncodeNixBase321482026/10/01 10:41:30 WARN Rate limiter enabled after throttle name=server-test rate=5149=== RUN TestEncodeNixBase32/test_string_hash150=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text151=== CONT TestUploadMultipart_SupersededByPeer152--- PASS: TestStreamPushReportsEveryPath (0.00s)153=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive154=== CONT TestPartSizeForNAR155=== RUN TestPartSizeForNAR/zero_stays_at_minimum156=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum157=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive158--- PASS: TestResolveStorePath (0.00s)159=== RUN TestPartSizeForNAR/small_stays_at_minimum160=== CONT TestDumpPathWriterError1612026/10/01 10:41:30 ERROR Upload failed error=boom count=1162=== RUN TestPathInfoCACompatibility/new_structured_format_-_text1632026/10/01 10:41:30 ERROR Upload failed error="bad path" count=3164=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text165=== PAUSE TestPartSizeForNAR/small_stays_at_minimum166--- PASS: TestStreamPushIsolatesFailures (0.00s)167=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum168=== CONT TestUploadMultipart_PartsInParallel169--- PASS: TestScriptTokenBadJSON (0.01s)170=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32171=== CONT TestFilterOversizedClosures172=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum173=== RUN TestConvertHashToNix32/already_Nix32_format174=== PAUSE TestGetStorePathHash/valid_store_path1752026/10/01 10:41:30 WARN Rate limiter enabled after throttle name=server-test rate=5176=== PAUSE TestRateLimiterFeedback/429_enables_limiter177=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts178=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method179=== PAUSE TestEncodeNixBase32/test_string_hash1802026/10/01 10:41:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43337181=== RUN TestUploadMultipart_SupersededByPeer/exists182=== CONT TestDumpPathSingleFile183--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)184--- PASS: TestScriptTokenEmptyToken (0.00s)185=== CONT TestStaticToken186--- PASS: TestStaticToken (0.00s)187=== RUN TestFilterOversizedClosures/no_limit_keeps_everything1882026/10/01 10:41:30 WARN Rate limiter backed off name=server-test rate=51892026/10/01 10:41:30 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43337190=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI191--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)1922026/10/01 10:41:30 ERROR Upload failed error=boom count=1193--- PASS: TestDoServerRequestAttachesToken (0.01s)194=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512195=== CONT TestParsePathInfoJSONMultiplePaths196=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths197=== CONT TestCaseHackSuffix198--- PASS: TestStreamPushReportsSignatures (0.01s)199=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512200=== PAUSE TestConvertHashToNix32/already_Nix32_format201=== RUN TestGetStorePathHash/basename_without_hyphen_should_error202=== RUN TestRateLimiterFeedback/503_enables_limiter203=== RUN TestEncodeNixBase32/empty_input204=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method205=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts206=== CONT TestSetClientTLSErrors207=== PAUSE TestUploadMultipart_SupersededByPeer/exists208=== CONT TestDumpPathMatchesNix209=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything210=== CONT TestRegisterUploadedObjectReusesConnections211=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths212=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths213=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths214=== RUN TestSetClientTLS/rejects_connection_without_client_cert215=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert216=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA217=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA218=== RUN TestSetClientTLS/preserves_debug_logging_transport219=== PAUSE TestSetClientTLS/preserves_debug_logging_transport220=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI221=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon222=== CONT TestPathInfoCACompatibility/null_ca_field223=== CONT TestPathInfoCACompatibility/new_structured_format_-_text224=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive225=== CONT TestPathInfoCACompatibility/old_string_format_-_text226=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method227=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths228=== CONT TestSetClientTLS/rejects_connection_without_client_cert229=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths230=== RUN TestSetClientTLSErrors/missing_cert_file231=== PAUSE TestSetClientTLSErrors/missing_cert_file232=== CONT TestParsePathInfoJSON233=== RUN TestConvertHashToNix32/invalid_format234=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error235=== PAUSE TestRateLimiterFeedback/503_enables_limiter236--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)237=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512238=== PAUSE TestEncodeNixBase32/empty_input239=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)240=== RUN TestPartSizeForNAR/1_TiB241=== RUN TestUploadMultipart_SupersededByPeer/missing242=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped243=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped244=== RUN TestFilterOversizedClosures/all_closures_skipped245=== PAUSE TestFilterOversizedClosures/all_closures_skipped246=== RUN TestSetClientTLSErrors/missing_key_file247=== PAUSE TestSetClientTLSErrors/missing_key_file248=== RUN TestSetClientTLSErrors/missing_ca_file249=== PAUSE TestSetClientTLSErrors/missing_ca_file250=== RUN TestSetClientTLSErrors/invalid_ca_file251=== PAUSE TestSetClientTLSErrors/invalid_ca_file252=== RUN TestParsePathInfoJSON/Nix_format253=== PAUSE TestParsePathInfoJSON/Nix_format254=== RUN TestParsePathInfoJSON/Lix_format255=== PAUSE TestParsePathInfoJSON/Lix_format256=== RUN TestParsePathInfoJSON/empty_input257=== PAUSE TestParsePathInfoJSON/empty_input258=== RUN TestParsePathInfoJSON/whitespace_only259=== PAUSE TestParsePathInfoJSON/whitespace_only260=== RUN TestParsePathInfoJSON/invalid_JSON261=== PAUSE TestParsePathInfoJSON/invalid_JSON262=== PAUSE TestConvertHashToNix32/invalid_format263=== CONT TestFilterOversizedClosures/no_limit_keeps_everything264=== CONT TestFilterOversizedClosures/all_closures_skipped2652026/10/01 10:41:30 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50266=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error267=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error268=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error269=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error270=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter271=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter272=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter273=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter274=== CONT TestConvertHashToNix32/SRI_format_to_Nix32275--- PASS: TestPathInfoCACompatibility (0.01s)276 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)277 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)278 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)279 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)280 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)281=== CONT TestSetClientTLSErrors/missing_key_file282--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)283 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)284 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)285=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA286--- PASS: TestPathInfoHashCompatibility (0.01s)287 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)288 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)289 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)290 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)291=== CONT TestParsePathInfoJSON/empty_input292=== CONT TestParsePathInfoJSON/Lix_format293=== CONT TestConvertHashToNix32/invalid_format294=== CONT TestConvertHashToNix32/already_Nix32_format295--- PASS: TestConvertHashToNix32 (0.03s)296 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)297 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)298 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)299=== PAUSE TestUploadMultipart_SupersededByPeer/missing300=== PAUSE TestPartSizeForNAR/1_TiB301=== RUN TestPartSizeForNAR/5_TiB_S3_max_object302=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object303=== RUN TestPartSizeForNAR/capped_at_5_GiB304=== PAUSE TestPartSizeForNAR/capped_at_5_GiB305=== CONT TestSetClientTLSErrors/missing_ca_file306=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error307=== CONT TestGetStorePathHash/basename_without_hyphen_should_error308=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter309=== CONT TestGetStorePathHash/valid_store_path310=== CONT TestParsePathInfoJSON/Nix_format311=== CONT TestRateLimiterFeedback/429_enables_limiter312=== CONT TestSetClientTLSErrors/invalid_ca_file313=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3142026/10/01 10:41:30 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=2000315=== CONT TestEncodeNixBase32/test_string_hash316--- PASS: TestFilterOversizedClosures (0.03s)317 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)318 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)319 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)320=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error321--- PASS: TestGetStorePathHash (0.03s)322 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)323 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)324 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)325 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)326=== CONT TestParsePathInfoJSON/whitespace_only327=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter328=== CONT TestParsePathInfoJSON/invalid_JSON329--- PASS: TestParsePathInfoJSON (0.00s)330 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)331 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)332 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)333 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)334 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)335=== CONT TestRateLimiterFeedback/503_enables_limiter336=== CONT TestPartSizeForNAR/zero_stays_at_minimum337=== CONT TestSetClientTLSErrors/missing_cert_file338=== CONT TestSetClientTLS/preserves_debug_logging_transport339=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum340=== CONT TestPartSizeForNAR/small_stays_at_minimum341--- PASS: TestSetClientTLSErrors (0.00s)342 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)343 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)344 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)345 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)346=== CONT TestPartSizeForNAR/capped_at_5_GiB347=== CONT TestUploadMultipart_SupersededByPeer/exists3482026/10/01 10:41:30 WARN Rate limiter enabled after throttle name=server-test rate=5349=== CONT TestPartSizeForNAR/5_TiB_S3_max_object3502026/10/01 10:41:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:40169351=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts3522026/10/01 10:41:30 WARN Rate limiter enabled after throttle name=server-test rate=53532026/10/01 10:41:30 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:45985354=== CONT TestUploadMultipart_SupersededByPeer/missing3552026/10/01 10:41:30 WARN Rate limiter backed off name=server-test rate=53562026/10/01 10:41:30 WARN Rate limiter backed off name=server-test rate=5357--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)358=== CONT TestEncodeNixBase32/empty_input359--- PASS: TestEncodeNixBase32 (0.03s)360 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)361 --- PASS: TestEncodeNixBase32/empty_input (0.00s)362--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)363=== CONT TestPartSizeForNAR/1_TiB364--- PASS: TestPartSizeForNAR (0.03s)365 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)368 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)369 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)370 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)371 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)372--- PASS: TestRateLimiterFeedback (0.03s)373 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)374 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)375 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)376 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)377--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)378 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)379 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)3802026/10/01 10:41:30 http: TLS handshake error from 127.0.0.1:38424: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.03s)382 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)385--- PASS: TestDumpPathWriterError (0.06s)386--- PASS: TestStreamPushRequestLine (0.07s)387--- PASS: TestDumpPathSingleFile (0.06s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)390--- PASS: TestDumpPathMatchesNix (0.07s)391--- PASS: TestStreamPushBatchesUnderLoad (0.10s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)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/postgres2703449782/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/postgres2703449782/data -l logfile start422423/build/postgres2703449782:5432 - no response4242026-10-01 10:41:32.368 UTC [130] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 10:41:32.368 UTC [130] LOG: listening on Unix socket "/build/postgres2703449782/.s.PGSQL.5432"4262026-10-01 10:41:32.372 UTC [137] LOG: database system was shut down at 2026-10-01 10:41:32 UTC4272026-10-01 10:41:32.376 UTC [130] LOG: database system is ready to accept connections428/build/postgres2703449782:5432 - accepting connections429{"timestamp":"2026-10-01T10:41:32.567640222Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"2d6dc6fa-1ebc-4064-82f2-01f7ac08fe3f","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(204)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestConnectWaitsForAPeerMigration471=== PAUSE TestConnectWaitsForAPeerMigration472=== RUN TestLeadElectsOneAndHandsOver473=== PAUSE TestLeadElectsOneAndHandsOver474=== RUN TestLeadIncumbentWinsAfterRestart4752026/10/01 10:41:32 INFO lead: acquired remote=192.0.2.1:12344762026/10/01 10:41:33 INFO lead: released remote=192.0.2.1:12344772026/10/01 10:41:33 INFO lead: acquired remote=192.0.2.1:12344782026/10/01 10:41:33 INFO lead: released remote=192.0.2.1:1234479--- PASS: TestLeadIncumbentWinsAfterRestart (0.78s)480=== RUN TestLeadEndsOnShutdown481=== PAUSE TestLeadEndsOnShutdown482=== RUN TestGCAdvisoryLockBlocksConcurrentRun483=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun484=== RUN TestGCBugBareHashReferences485=== PAUSE TestGCBugBareHashReferences486=== RUN TestGCMetrics487=== PAUSE TestGCMetrics488=== RUN TestPushDedupSurvivesConcurrentGC489=== PAUSE TestPushDedupSurvivesConcurrentGC490=== RUN TestDeduplicatedObjectsRecordedAsPending491=== PAUSE TestDeduplicatedObjectsRecordedAsPending492=== RUN TestGCSweepSkipsPendingObjects493=== PAUSE TestGCSweepSkipsPendingObjects494=== RUN TestTombstonedObjectOfferedWithoutWaiting495=== PAUSE TestTombstonedObjectOfferedWithoutWaiting496=== RUN TestGCSweepDeliversEachKeyOnce497=== PAUSE TestGCSweepDeliversEachKeyOnce498=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection499=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection500=== RUN TestForceGCDuringPushOffersSweptObject501=== PAUSE TestForceGCDuringPushOffersSweptObject502=== RUN TestFailedS3DeleteKeepsTombstone503=== PAUSE TestFailedS3DeleteKeepsTombstone504=== RUN TestSweepSkipsRowsLockedByPush505=== PAUSE TestSweepSkipsRowsLockedByPush506=== RUN TestRegisterCompletedObjectNeedsPendingRow507=== PAUSE TestRegisterCompletedObjectNeedsPendingRow508=== RUN TestGetExistingObjectsLocksRows509=== PAUSE TestGetExistingObjectsLocksRows510=== RUN TestSweepRechecksPendingAfterLocking511=== PAUSE TestSweepRechecksPendingAfterLocking512=== RUN TestPushWaitsForSweepHoldingRow513=== PAUSE TestPushWaitsForSweepHoldingRow514=== RUN TestCommitRacingPendingCleanupKeepsObjects515=== PAUSE TestCommitRacingPendingCleanupKeepsObjects516=== RUN TestGCEndsOnShutdown517=== PAUSE TestGCEndsOnShutdown518=== RUN TestGCTaskStore_StartNew519=== PAUSE TestGCTaskStore_StartNew520=== RUN TestGCTaskStore_DeduplicateSameParams521=== PAUSE TestGCTaskStore_DeduplicateSameParams522=== RUN TestGCTaskStore_ConflictDifferentParams523=== PAUSE TestGCTaskStore_ConflictDifferentParams524=== RUN TestGCTaskStore_GetEmpty525=== PAUSE TestGCTaskStore_GetEmpty526=== RUN TestGCTaskStore_GetReturnsLatest527=== PAUSE TestGCTaskStore_GetReturnsLatest528=== RUN TestGCTaskStore_CompletedAllowsNewTask529=== PAUSE TestGCTaskStore_CompletedAllowsNewTask530=== RUN TestGCTaskStore_PhaseUpdates531=== PAUSE TestGCTaskStore_PhaseUpdates532=== RUN TestGCTaskStore_Fail533=== PAUSE TestGCTaskStore_Fail534=== RUN TestGracefulShutdownDrainsInflight535=== PAUSE TestGracefulShutdownDrainsInflight536=== RUN TestService_healthCheckHandler537=== PAUSE TestService_healthCheckHandler538=== RUN TestService_readinessHandler539=== PAUSE TestService_readinessHandler540=== RUN TestGenerateLandingPage541=== PAUSE TestGenerateLandingPage542=== RUN TestCacheConfigHandlerMaxNarSize543=== PAUSE TestCacheConfigHandlerMaxNarSize544=== RUN TestCreatePendingClosureRejectsOversizedNAR545=== PAUSE TestCreatePendingClosureRejectsOversizedNAR546=== RUN TestNARDeduplicationMetadataUploadBug547=== PAUSE TestNARDeduplicationMetadataUploadBug548=== RUN TestMetricsInventory549=== PAUSE TestMetricsInventory550=== RUN TestService_NativeMTLS551=== PAUSE TestService_NativeMTLS552=== RUN TestServerTLSConfig553=== PAUSE TestServerTLSConfig554=== RUN TestMultipartCleanup555=== PAUSE TestMultipartCleanup556=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded557=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded558=== RUN TestPendingCleanupUsesOneCutoff559=== PAUSE TestPendingCleanupUsesOneCutoff560=== RUN TestObjectStatsTrigger561=== PAUSE TestObjectStatsTrigger562=== RUN TestOrphanedObjectsGC563=== PAUSE TestOrphanedObjectsGC564=== RUN TestOrphanedObjectsGCStressTest565=== PAUSE TestOrphanedObjectsGCStressTest566=== RUN TestCreatePin_ReservedPins567=== PAUSE TestCreatePin_ReservedPins568=== RUN TestPresentReportsOnlyClosureRoots569=== PAUSE TestPresentReportsOnlyClosureRoots570=== RUN TestPresentNotReportedWhileGCDeletesClosure571=== PAUSE TestPresentNotReportedWhileGCDeletesClosure572=== RUN TestParseSingleRange573=== PAUSE TestParseSingleRange574=== RUN TestProxyHeadersOnlyTrustedOnSocket575=== PAUSE TestProxyHeadersOnlyTrustedOnSocket576=== RUN TestIsValidCachePath577=== PAUSE TestIsValidCachePath578=== RUN TestReadProxyNarinfo579=== PAUSE TestReadProxyNarinfo580=== RUN TestReadProxyNarinfoAlreadyDecompressed581=== PAUSE TestReadProxyNarinfoAlreadyDecompressed582=== RUN TestReadProxyNarStreaming583=== PAUSE TestReadProxyNarStreaming584=== RUN TestReadProxy404585=== PAUSE TestReadProxy404586=== RUN TestReadProxyInvalidPath587=== PAUSE TestReadProxyInvalidPath588=== RUN TestReadProxyHead589=== PAUSE TestReadProxyHead590=== RUN TestReadProxyOutlastsServerWriteTimeout591=== PAUSE TestReadProxyOutlastsServerWriteTimeout592=== RUN TestReadProxyConditionalGet593=== PAUSE TestReadProxyConditionalGet594=== RUN TestReadProxyRootRedirectsToIndexHTML595=== PAUSE TestReadProxyRootRedirectsToIndexHTML596=== RUN TestReadProxyDisabled597=== PAUSE TestReadProxyDisabled598=== RUN TestReadRedirectNar599=== PAUSE TestReadRedirectNar600=== RUN TestReadRedirectKeepsNarinfoProxied601=== PAUSE TestReadRedirectKeepsNarinfoProxied602=== RUN TestReadProxyRangeRequest603=== PAUSE TestReadProxyRangeRequest604=== RUN TestReadRedirectUsesPublicS3URL605=== PAUSE TestReadRedirectUsesPublicS3URL606=== RUN TestPush_OverlappingRootsStoreOneRowPerKey607=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey608=== RUN TestPush_CompleteCommitsEveryRoot609=== PAUSE TestPush_CompleteCommitsEveryRoot610=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit611=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit612=== RUN TestPush_RejectsBadRequests613=== PAUSE TestPush_RejectsBadRequests614=== RUN TestPush_SignsNarinfosOfItsPendingObjects615=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects616=== RUN TestRedundantMultipartUpload617=== PAUSE TestRedundantMultipartUpload618=== RUN TestCompleteMultipartUpload_ErrorButObjectExists619=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists620=== RUN TestCompletedNarNotReofferedAcrossClosures621=== PAUSE TestCompletedNarNotReofferedAcrossClosures622=== RUN TestPresignedUploadRegisteredBeforeCommit623=== PAUSE TestPresignedUploadRegisteredBeforeCommit624=== RUN TestService_Rustfstest625=== PAUSE TestService_Rustfstest626=== RUN TestParseSize627=== PAUSE TestParseSize628=== RUN TestSkippedUploadsHandler629=== PAUSE TestSkippedUploadsHandler630=== RUN TestSystemdListenerNotActivated631--- PASS: TestSystemdListenerNotActivated (0.00s)632=== RUN TestWatchdogBeatsWhenHealthy633--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)634=== RUN TestWatchdogSkipsWhenUnhealthy6352026/10/01 10:41:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 10:41:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 10:41:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 10:41:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 10:41:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 10:41:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 10:41:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 10:41:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 10:41:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 10:41:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"645--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)646=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle647=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle648=== RUN TestProxyWriteTimeout649=== PAUSE TestProxyWriteTimeout650=== RUN TestPendingClosureWriteTimeout651=== PAUSE TestPendingClosureWriteTimeout652=== RUN TestIsValidUploadKey653=== PAUSE TestIsValidUploadKey654=== RUN TestUploadHandlersRejectInvalidKeys655=== PAUSE TestUploadHandlersRejectInvalidKeys656=== RUN TestUploadHandlersRejectOversizedBody657=== PAUSE TestUploadHandlersRejectOversizedBody658=== RUN TestService_cleanupPendingClosuresHandler659=== PAUSE TestService_cleanupPendingClosuresHandler660=== RUN TestService_createPendingClosureHandler661=== PAUSE TestService_createPendingClosureHandler662=== RUN TestService_verifyS3Integrity663=== PAUSE TestService_verifyS3Integrity664=== RUN TestCompleteMultipartUnregistered665=== PAUSE TestCompleteMultipartUnregistered666=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT667=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT668=== CONT TestService_AuthMiddleware669=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT670=== CONT TestGCTaskStore_Fail671=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded672=== CONT TestSkippedUploadsHandler673=== CONT TestUploadHandlersRejectOversizedBody674--- PASS: TestGCTaskStore_Fail (0.00s)675=== CONT TestCompleteMultipartUnregistered676=== CONT TestService_verifyS3Integrity677=== CONT TestService_createPendingClosureHandler678=== CONT TestService_cleanupPendingClosuresHandler679=== CONT TestReadProxyNarinfoAlreadyDecompressed680=== CONT TestParseSize681--- PASS: TestParseSize (0.00s)682=== CONT TestReadRedirectNar6832026/10/01 10:41:33 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000684=== CONT TestService_Rustfstest685=== CONT TestPresignedUploadRegisteredBeforeCommit686=== CONT TestCompletedNarNotReofferedAcrossClosures687=== CONT TestCompleteMultipartUpload_ErrorButObjectExists688=== CONT TestRedundantMultipartUpload689=== CONT TestPush_SignsNarinfosOfItsPendingObjects690=== CONT TestPush_RejectsBadRequests691=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit692=== CONT TestPush_CompleteCommitsEveryRoot693=== CONT TestPush_OverlappingRootsStoreOneRowPerKey694=== CONT TestReadRedirectUsesPublicS3URL695=== CONT TestReadProxyRangeRequest696=== CONT TestReadRedirectKeepsNarinfoProxied697--- PASS: TestSkippedUploadsHandler (0.01s)698=== CONT TestReadProxyDisabled699=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure700=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure701=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart702=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart703=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts704=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts705=== CONT TestReadProxyRootRedirectsToIndexHTML7062026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures707--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.34s)708=== CONT TestReadProxyConditionalGet7092026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures7102026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures711--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.36s)712=== CONT TestReadProxyOutlastsServerWriteTimeout7132026/10/01 10:41:34 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"714--- PASS: TestService_AuthMiddleware (0.37s)715=== CONT TestReadProxyHead7162026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures7172026/10/01 10:41:34 INFO Received cleanup request method=DELETE path=/api/pending_closures7182026/10/01 10:41:34 INFO Aborted multipart uploads count=0 kept=07192026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures7202026/10/01 10:41:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7212026/10/01 10:41:34 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTU2ZWM1MTMtNjEzNC00M2M1LWE2NjAtZTE2YWUzNDYxNDZjLjIyMTlkZWRjLWQ4ZmQtNGEwNy1iNWVjLTNkYWY5MTZlMTdlNHgxNzkwODUxMjk0MDc4MDg2OTY57222026/10/01 10:41:34 INFO Received cleanup request method=DELETE path=/api/pending_closures7232026/10/01 10:41:34 INFO Aborted multipart uploads count=1 kept=07242026/10/01 10:41:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTU2ZWM1MTMtNjEzNC00M2M1LWE2NjAtZTE2YWUzNDYxNDZjLjIyMTlkZWRjLWQ4ZmQtNGEwNy1iNWVjLTNkYWY5MTZlMTdlNHgxNzkwODUxMjk0MDc4MDg2OTY5 parts=17252026/10/01 10:41:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7262026-10-01 10:41:34.114 UTC [450] ERROR: Closure does not exist: id=17272026-10-01 10:41:34.114 UTC [450] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE7282026-10-01 10:41:34.114 UTC [450] STATEMENT: -- name: CommitPendingClosure :exec729 SELECT commit_pending_closure($1::bigint)730 731--- PASS: TestService_cleanupPendingClosuresHandler (0.43s)732--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.43s)733=== CONT TestReadProxy404734=== CONT TestReadProxyInvalidPath735--- PASS: TestReadRedirectNar (0.44s)736=== CONT TestReadProxyNarStreaming737--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.46s)738=== CONT TestGCBugBareHashReferences739--- PASS: TestService_Rustfstest (0.47s)740=== CONT TestGCTaskStore_PhaseUpdates741--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)742=== CONT TestGCTaskStore_CompletedAllowsNewTask743--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)744=== CONT TestGCTaskStore_GetReturnsLatest745--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)746=== CONT TestGCTaskStore_GetEmpty747--- PASS: TestGCTaskStore_GetEmpty (0.00s)748=== CONT TestGCTaskStore_ConflictDifferentParams749--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)750=== CONT TestGCTaskStore_DeduplicateSameParams751--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)752=== CONT TestGCTaskStore_StartNew753--- PASS: TestGCTaskStore_StartNew (0.00s)754=== CONT TestGCEndsOnShutdown7552026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures7562026/10/01 10:41:34 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7572026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures7582026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures7592026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures7602026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures761--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.52s)762=== CONT TestCommitRacingPendingCleanupKeepsObjects763--- PASS: TestReadProxyDisabled (0.53s)764=== CONT TestPushWaitsForSweepHoldingRow7652026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures766=== RUN TestPush_RejectsBadRequests/no_roots767=== PAUSE TestPush_RejectsBadRequests/no_roots768=== RUN TestPush_RejectsBadRequests/no_objects769=== PAUSE TestPush_RejectsBadRequests/no_objects770=== RUN TestPush_RejectsBadRequests/bad_root771=== PAUSE TestPush_RejectsBadRequests/bad_root772=== RUN TestPush_RejectsBadRequests/root_not_in_objects773=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects774=== CONT TestSweepRechecksPendingAfterLocking775--- PASS: TestReadRedirectUsesPublicS3URL (0.79s)776=== CONT TestGetExistingObjectsLocksRows777--- PASS: TestReadProxyRangeRequest (0.81s)778=== CONT TestRegisterCompletedObjectNeedsPendingRow7792026/10/01 10:41:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7802026/10/01 10:41:34 INFO Received push request method=POST path=/api/pushes7812026/10/01 10:41:34 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OTU2ZWM1MTMtNjEzNC00M2M1LWE2NjAtZTE2YWUzNDYxNDZjLmE2ZjczMjUxLTAxNTgtNDU0Yi1hN2M2LTgwOTE3OWZlZWNjNXgxNzkwODUxMjk0MDI0NTE0NjUx parts=107822026/10/01 10:41:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7832026/10/01 10:41:34 INFO Completed upload id=17842026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures7852026/10/01 10:41:34 INFO Received complete push request method=POST path=/api/pushes/1/complete7862026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures7872026/10/01 10:41:34 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo7882026/10/01 10:41:34 WARN Found objects in DB but missing from S3, will re-upload count=1789--- PASS: TestService_verifyS3Integrity (0.92s)790=== CONT TestSweepSkipsRowsLockedByPush791--- PASS: TestPush_CompleteCommitsEveryRoot (0.85s)792=== CONT TestMultipartCleanup793--- PASS: TestReadRedirectKeepsNarinfoProxied (0.86s)794=== CONT TestFailedS3DeleteKeepsTombstone7952026/10/01 10:41:34 INFO Received push request method=POST path=/api/pushes7962026/10/01 10:41:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7972026/10/01 10:41:34 INFO Signed narinfos id=1 count=1798--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.89s)799=== CONT TestServerTLSConfig800=== RUN TestServerTLSConfig/no_client_CA801=== PAUSE TestServerTLSConfig/no_client_CA802=== RUN TestServerTLSConfig/missing_CA_file803=== PAUSE TestServerTLSConfig/missing_CA_file804=== RUN TestServerTLSConfig/not_a_PEM_file805=== PAUSE TestServerTLSConfig/not_a_PEM_file806=== CONT TestForceGCDuringPushOffersSweptObject807=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows808=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows809=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check810=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check811=== CONT TestService_NativeMTLS8122026/10/01 10:41:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8132026/10/01 10:41:34 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst814--- PASS: TestCompleteMultipartUnregistered (0.97s)815=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8162026/10/01 10:41:34 INFO Received push request method=POST path=/api/pushes817--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.93s)818=== CONT TestMetricsInventory8192026/10/01 10:41:34 INFO Received push request method=POST path=/api/pushes8202026/10/01 10:41:34 INFO Received complete push request method=POST path=/api/pushes/1/complete8212026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures8222026/10/01 10:41:34 INFO Received push request method=POST path=/api/pushes8232026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures824--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.91s)825=== CONT TestGCSweepDeliversEachKeyOnce8262026/10/01 10:41:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8272026/10/01 10:41:34 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OTU2ZWM1MTMtNjEzNC00M2M1LWE2NjAtZTE2YWUzNDYxNDZjLmFiMDkyZTJlLWE0MzEtNGExZC1hOTcwLWFjNzcxYzYwYjA2ZngxNzkwODUxMjk0MjA0MTE1Njky parts=108282026/10/01 10:41:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8292026/10/01 10:41:34 INFO Aborted multipart uploads count=0 kept=08302026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures8312026/10/01 10:41:34 INFO Completed upload id=18322026/10/01 10:41:34 WARN Force mode enabled - objects will be deleted immediately without grace period8332026/10/01 10:41:34 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008342026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures8352026/10/01 10:41:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures8362026/10/01 10:41:34 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=08372026/10/01 10:41:34 INFO Aborted multipart uploads count=0 kept=08382026/10/01 10:41:34 INFO Vacuumed table table=pending_closures8392026/10/01 10:41:34 INFO Vacuumed table table=pending_objects8402026/10/01 10:41:34 INFO Vacuumed table table=multipart_uploads8412026/10/01 10:41:34 INFO Vacuumed table table=closures8422026/10/01 10:41:34 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=0843--- PASS: TestReadProxyConditionalGet (0.80s)844=== CONT TestNARDeduplicationMetadataUploadBug8452026/10/01 10:41:34 INFO Vacuumed table table=objects8462026/10/01 10:41:34 INFO Received complete push request method=POST path=/api/pushes/2/complete8472026/10/01 10:41:34 INFO Vacuumed table table=pending_closures8482026/10/01 10:41:34 INFO Vacuumed table table=pending_objects849--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.07s)850=== CONT TestTombstonedObjectOfferedWithoutWaiting8512026/10/01 10:41:34 INFO Vacuumed table table=multipart_uploads8522026/10/01 10:41:34 INFO Vacuumed table table=closures8532026/10/01 10:41:34 INFO Vacuumed table table=objects8542026/10/01 10:41:34 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000855--- PASS: TestService_createPendingClosureHandler (1.17s)856=== CONT TestCreatePendingClosureRejectsOversizedNAR8572026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures858--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)859=== CONT TestGCSweepSkipsPendingObjects860--- PASS: TestReadProxyHead (0.80s)861=== CONT TestCacheConfigHandlerMaxNarSize862--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)863=== CONT TestPendingClosureWriteTimeout864=== RUN TestPendingClosureWriteTimeout/empty865=== PAUSE TestPendingClosureWriteTimeout/empty866=== RUN TestPendingClosureWriteTimeout/400_objects867=== PAUSE TestPendingClosureWriteTimeout/400_objects868=== RUN TestPendingClosureWriteTimeout/670k_objects869=== PAUSE TestPendingClosureWriteTimeout/670k_objects870=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline871=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline872=== CONT TestGenerateLandingPage873--- PASS: TestGenerateLandingPage (0.00s)874=== CONT TestService_readinessHandler8752026/10/01 10:41:34 INFO Aborted multipart uploads count=0 kept=08762026/10/01 10:41:34 WARN Force mode enabled - objects will be deleted immediately without grace period877--- PASS: TestReadProxyNarStreaming (0.75s)878=== CONT TestDeduplicatedObjectsRecordedAsPending8792026/10/01 10:41:34 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8802026/10/01 10:41:34 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."8812026/10/01 10:41:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete882--- PASS: TestFailedS3DeleteKeepsTombstone (0.27s)883=== CONT TestUploadHandlersRejectInvalidKeys884=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info885=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info886=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal887=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal888=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key889=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key890=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key891=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key892=== CONT TestPushDedupSurvivesConcurrentGC8932026/10/01 10:41:34 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OTU2ZWM1MTMtNjEzNC00M2M1LWE2NjAtZTE2YWUzNDYxNDZjLjVjYzNkYTUxLWM3OTUtNDViZC04M2Q3LTdlNDU5Njg1YTUyN3gxNzkwODUxMjk0MjQ4MzEwNDI2 parts=128942026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures895--- PASS: TestReadProxy404 (0.79s)896=== CONT TestIsValidUploadKey897=== RUN TestIsValidUploadKey/narinfo898=== PAUSE TestIsValidUploadKey/narinfo899=== RUN TestIsValidUploadKey/nar_zst900=== PAUSE TestIsValidUploadKey/nar_zst901=== RUN TestIsValidUploadKey/nar_xz902=== PAUSE TestIsValidUploadKey/nar_xz903=== RUN TestIsValidUploadKey/nar_plain904=== PAUSE TestIsValidUploadKey/nar_plain905=== RUN TestIsValidUploadKey/listing906=== PAUSE TestIsValidUploadKey/listing907=== RUN TestIsValidUploadKey/build_log908=== PAUSE TestIsValidUploadKey/build_log909=== RUN TestIsValidUploadKey/build_log_home-manager_file910=== PAUSE TestIsValidUploadKey/build_log_home-manager_file911=== RUN TestIsValidUploadKey/build_log_plus_in_name912=== PAUSE TestIsValidUploadKey/build_log_plus_in_name913=== RUN TestIsValidUploadKey/build_log_question_mark914=== PAUSE TestIsValidUploadKey/build_log_question_mark915=== RUN TestIsValidUploadKey/build_log_equals916=== PAUSE TestIsValidUploadKey/build_log_equals917=== RUN TestIsValidUploadKey/realisation918=== PAUSE TestIsValidUploadKey/realisation919=== RUN TestIsValidUploadKey/realisation_plus_in_output920=== PAUSE TestIsValidUploadKey/realisation_plus_in_output921=== RUN TestIsValidUploadKey/nix-cache-info922=== PAUSE TestIsValidUploadKey/nix-cache-info923=== RUN TestIsValidUploadKey/index.html924=== PAUSE TestIsValidUploadKey/index.html925=== RUN TestIsValidUploadKey/narinfo_key,_nar_type926=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type927=== RUN TestIsValidUploadKey/nar_key,_narinfo_type928=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type929=== RUN TestIsValidUploadKey/listing_key,_narinfo_type930=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type931=== RUN TestIsValidUploadKey/traversal932=== PAUSE TestIsValidUploadKey/traversal933=== RUN TestIsValidUploadKey/traversal_nar934=== PAUSE TestIsValidUploadKey/traversal_nar935=== RUN TestIsValidUploadKey/absolute936=== PAUSE TestIsValidUploadKey/absolute937=== RUN TestIsValidUploadKey/empty_key938=== PAUSE TestIsValidUploadKey/empty_key939=== RUN TestIsValidUploadKey/unknown_type940=== PAUSE TestIsValidUploadKey/unknown_type941=== CONT TestService_healthCheckHandler942--- PASS: TestReadProxyInvalidPath (0.79s)943=== CONT TestGCMetrics944--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.23s)945=== CONT TestGracefulShutdownDrainsInflight9462026/10/01 10:41:34 INFO Starting HTTP server address=127.0.0.1:436899472026/10/01 10:41:34 INFO Shutdown signal received, draining in-flight requests timeout=10s948--- PASS: TestGCEndsOnShutdown (0.80s)949=== CONT TestClientMultipleUploads950--- PASS: TestGracefulShutdownDrainsInflight (0.07s)951=== CONT TestService_ReadScope_PublicByDefault9522026/10/01 10:41:34 INFO Received uploads request method=POST path=/api/pending_closures9532026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=09542026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period9552026/10/01 10:41:35 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=09562026/10/01 10:41:35 INFO Vacuumed table table=pending_closures9572026/10/01 10:41:35 INFO Vacuumed table table=pending_objects9582026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads9592026/10/01 10:41:35 INFO Vacuumed table table=closures9602026/10/01 10:41:35 INFO Vacuumed table table=objects961--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.83s)962=== CONT TestGCAdvisoryLockBlocksConcurrentRun9632026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=09642026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period9652026/10/01 10:41:35 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=0966--- PASS: TestGetExistingObjectsLocksRows (0.51s)967=== CONT TestClientIntegration9682026/10/01 10:41:35 INFO Vacuumed table table=pending_closures9692026/10/01 10:41:35 INFO Vacuumed table table=pending_objects9702026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads9712026/10/01 10:41:35 INFO Vacuumed table table=closures972--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.49s)973=== CONT TestProxyWriteTimeout974=== RUN TestProxyWriteTimeout/narinfo975=== PAUSE TestProxyWriteTimeout/narinfo976=== RUN TestProxyWriteTimeout/1_GiB_nar977=== PAUSE TestProxyWriteTimeout/1_GiB_nar978=== RUN TestProxyWriteTimeout/10_GiB_nar979=== PAUSE TestProxyWriteTimeout/10_GiB_nar980=== RUN TestProxyWriteTimeout/unknown_size981=== PAUSE TestProxyWriteTimeout/unknown_size982=== CONT TestLeadEndsOnShutdown9832026/10/01 10:41:35 INFO Vacuumed table table=objects984--- PASS: TestSweepRechecksPendingAfterLocking (0.79s)985=== CONT TestClientErrorHandling986=== RUN TestClientErrorHandling/InvalidStorePath987=== PAUSE TestClientErrorHandling/InvalidStorePath988=== RUN TestClientErrorHandling/InvalidAuthToken989=== PAUSE TestClientErrorHandling/InvalidAuthToken990=== RUN TestClientErrorHandling/ServerNotAvailable991=== PAUSE TestClientErrorHandling/ServerNotAvailable992=== CONT TestLeadElectsOneAndHandsOver9932026/10/01 10:41:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9942026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures9952026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=09962026/10/01 10:41:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OTU2ZWM1MTMtNjEzNC00M2M1LWE2NjAtZTE2YWUzNDYxNDZjLmIyYzg0N2YwLTA4MzQtNGJjNC1iM2I4LTAwNzE5NTg1ZjNiNHgxNzkwODUxMjk0NzIwMTE2MDkz parts=129972026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures9982026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period9992026/10/01 10:41:35 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=010002026/10/01 10:41:35 INFO Vacuumed table table=pending_closures10012026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures10022026/10/01 10:41:35 INFO Vacuumed table table=pending_objects10032026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads10042026/10/01 10:41:35 INFO Vacuumed table table=closures10052026/10/01 10:41:35 INFO Vacuumed table table=objects10062026/10/01 10:41:35 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10072026/10/01 10:41:35 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1008--- PASS: TestService_NativeMTLS (0.47s)1009=== CONT TestClientCADerivations10102026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=010112026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period10122026/10/01 10:41:35 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=010132026/10/01 10:41:35 INFO Vacuumed table table=pending_closures10142026/10/01 10:41:35 INFO Vacuumed table table=pending_objects10152026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads10162026/10/01 10:41:35 INFO Vacuumed table table=closures10172026/10/01 10:41:35 INFO Vacuumed table table=objects1018--- PASS: TestSweepSkipsRowsLockedByPush (0.53s)1019=== CONT TestService_ReadAuthMiddleware10202026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures1021--- PASS: TestGCBugBareHashReferences (1.01s)1022=== CONT TestCacheStatsHandler1023--- PASS: TestMetricsInventory (0.48s)1024=== CONT TestClientPushesUseOnePush10252026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures10262026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=010272026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period1028--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.38s)1029=== CONT TestService_RequireScope_OIDC10302026/10/01 10:41:35 INFO Received cleanup request method=DELETE path=/api/pending_closures10312026/10/01 10:41:35 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket40/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10322026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=110332026/10/01 10:41:35 INFO Received cleanup request method=DELETE path=/api/pending_closures10342026/10/01 10:41:35 INFO Aborted multipart uploads count=1 kept=010352026/10/01 10:41:35 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=01036--- PASS: TestMultipartCleanup (0.61s)1037=== CONT TestCacheConfigHandler1038=== RUN TestCacheConfigHandler/full_config,_no_issuer1039=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1040=== RUN TestCacheConfigHandler/no_cache_url_configured1041=== PAUSE TestCacheConfigHandler/no_cache_url_configured1042=== RUN TestCacheConfigHandler/no_signing_keys1043=== PAUSE TestCacheConfigHandler/no_signing_keys1044=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1045=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1046=== CONT TestPinProtectsFromGC10472026/10/01 10:41:35 INFO Vacuumed table table=pending_closures10482026/10/01 10:41:35 INFO Vacuumed table table=pending_objects10492026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads10502026/10/01 10:41:35 INFO Vacuumed table table=closures10512026/10/01 10:41:35 INFO Vacuumed table table=objects1052--- PASS: TestGCSweepDeliversEachKeyOnce (0.48s)1053=== CONT TestService_AuthMiddleware_OIDC10542026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures10552026/10/01 10:41:35 WARN readiness check failed error="closed pool"1056--- PASS: TestService_readinessHandler (0.40s)1057=== CONT TestClientSharedPathCommittedMidPush10582026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=01059=== NAME TestNARDeduplicationMetadataUploadBug1060 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2717407316/001/store/4ack7gqln40zimqiwxbkd0lpm0asswdj-file1.txt10612026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period10622026/10/01 10:41:35 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=010632026/10/01 10:41:35 INFO Vacuumed table table=pending_closures10642026/10/01 10:41:35 INFO Vacuumed table table=pending_objects10652026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads10662026/10/01 10:41:35 INFO Vacuumed table table=closures10672026/10/01 10:41:35 INFO Vacuumed table table=objects1068--- PASS: TestGCSweepSkipsPendingObjects (0.43s)1069=== CONT TestResolveDBConnectionString1070=== RUN TestResolveDBConnectionString/flag_wins1071=== PAUSE TestResolveDBConnectionString/flag_wins1072=== RUN TestResolveDBConnectionString/file_when_flag_empty1073=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1074=== RUN TestResolveDBConnectionString/missing_file_is_an_error1075=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1076=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1077=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1078=== RUN TestResolveDBConnectionString/nothing_configured1079=== PAUSE TestResolveDBConnectionString/nothing_configured1080=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10812026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures1082--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.41s)1083=== CONT TestClientFallsBackToClosures1084--- PASS: TestService_healthCheckHandler (0.41s)1085=== CONT TestConnectWaitsForAPeerMigration10862026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures10872026/10/01 10:41:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38539/oidc10882026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes10892026/10/01 10:41:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10902026/10/01 10:41:35 INFO Uploading 4ack7gqln40zimqiwxbkd0lpm0asswdj-file1.txt (160B)10912026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10922026/10/01 10:41:35 WARN Failed to register uploaded object key=4ack7gqln40zimqiwxbkd0lpm0asswdj.ls error="server returned 404: 404 page not found\n"10932026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=010942026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1095--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.70s)1096=== CONT TestService_AuthMiddleware_MTLSBoundSubjects10972026/10/01 10:41:35 INFO Signed narinfos id=1 count=110982026/10/01 10:41:35 INFO Uploading 1 narinfos10992026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period11002026/10/01 10:41:35 INFO Received complete push request method=POST path=/api/pushes/1/complete11012026/10/01 10:41:35 WARN Failed to register uploaded object key=4ack7gqln40zimqiwxbkd0lpm0asswdj.narinfo error="server returned 404: 404 page not found\n"11022026/10/01 10:41:35 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=011032026/10/01 10:41:35 INFO Vacuumed table table=pending_closures11042026/10/01 10:41:35 INFO Vacuumed table table=pending_objects11052026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads11062026/10/01 10:41:35 INFO Vacuumed table table=closures11072026/10/01 10:41:35 INFO Vacuumed table table=objects11082026/10/01 10:41:35 INFO Upload complete. (68ms)1109=== NAME TestNARDeduplicationMetadataUploadBug1110 metadata_upload_test.go:54: Retrieved narinfo from S3:1111 StorePath: /build/TestNARDeduplicationMetadataUploadBug2717407316/001/store/4ack7gqln40zimqiwxbkd0lpm0asswdj-file1.txt1112 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1113 Compression: zstd1114 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1115 NarSize: 1601116 References: 1117 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1118--- PASS: TestGCMetrics (0.45s)1119=== CONT TestPresentReportsOnlyClosureRoots1120=== NAME TestNARDeduplicationMetadataUploadBug1121 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1122 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1123 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1124--- PASS: TestService_ReadScope_PublicByDefault (0.40s)1125=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle11262026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=011272026/10/01 10:41:35 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=01128=== NAME TestNARDeduplicationMetadataUploadBug1129 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2717407316/001/store/y5w6wxd6f5idiihwzyfg3v6y1m4z5d4f-file2.txt1130=== NAME TestClientMultipleUploads1131 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2865487793/001/store/zlgl1x1nc4ks1xnhjksvvf9s0d89bnj7-test-file-0.txt1132--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.37s)1133=== CONT TestService_AuthMiddleware_MTLSProxyHeader11342026/10/01 10:41:35 INFO Vacuumed table table=pending_closures11352026/10/01 10:41:35 INFO Vacuumed table table=pending_objects11362026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads11372026/10/01 10:41:35 INFO Vacuumed table table=closures11382026/10/01 10:41:35 INFO Vacuumed table table=objects11392026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=011402026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period11412026/10/01 10:41:35 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=011422026/10/01 10:41:35 INFO Vacuumed table table=pending_closures11432026/10/01 10:41:35 INFO Vacuumed table table=pending_objects11442026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads11452026/10/01 10:41:35 INFO Vacuumed table table=closures11462026/10/01 10:41:35 INFO Vacuumed table table=objects11472026/10/01 10:41:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45013/oidc1148--- PASS: TestPushDedupSurvivesConcurrentGC (0.55s)1149=== CONT TestReadProxyNarinfo1150=== NAME TestClientMultipleUploads1151 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2865487793/001/store/2frxqhm58nmvviiavffpdcaaiqw5rrhd-test-file-1.txt11522026/10/01 10:41:35 INFO lead: acquired remote=192.0.2.1:123411532026/10/01 10:41:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1154=== NAME TestClientIntegration1155 client_integration_test.go:286: Created store path: /build/TestClientIntegration3108142420/002/store/svvy6w5hpy3izw8lq8cjbm660r30vrbl-test-file.txt11562026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes1157=== NAME TestClientMultipleUploads1158 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2865487793/001/store/fcm4p964a8d5dwxwh9dy1zlxr549pwgc-test-file-2.txt11592026/10/01 10:41:35 INFO lead: acquired remote=192.0.2.1:123411602026/10/01 10:41:35 INFO lead: released remote=192.0.2.1:12341161--- PASS: TestLeadEndsOnShutdown (0.41s)1162=== CONT TestClientWithDependencies11632026/10/01 10:41:35 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11642026/10/01 10:41:35 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTU2ZWM1MTMtNjEzNC00M2M1LWE2NjAtZTE2YWUzNDYxNDZjLmQ5OWQxM2RmLTQ4YjItNDg5Ny1hMjEyLWZkMTdjYThjYzFmMXgxNzkwODUxMjk1MTA4OTYyNDc5 error="Get \"http://127.0.0.1:1/bucket24/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11652026/10/01 10:41:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTU2ZWM1MTMtNjEzNC00M2M1LWE2NjAtZTE2YWUzNDYxNDZjLmIyNWI3Y2I4LWZiMWUtNGFhNy1hNjQyLTNiZjA2ZTdlZGYwOXgxNzkwODUxMjk1MTAyMDc1NTE4 parts=1211662026/10/01 10:41:35 INFO Received cleanup request method=DELETE path=/api/pending_closures11672026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11682026/10/01 10:41:35 INFO Signed narinfos id=2 count=111692026/10/01 10:41:35 WARN Failed to register uploaded object key=y5w6wxd6f5idiihwzyfg3v6y1m4z5d4f.ls error="server returned 404: 404 page not found\n"11702026/10/01 10:41:35 INFO Uploading 1 narinfos11712026/10/01 10:41:35 INFO Aborted multipart uploads count=1 kept=011722026/10/01 10:41:35 INFO Received complete push request method=POST path=/api/pushes/2/complete11732026/10/01 10:41:35 WARN Failed to register uploaded object key=y5w6wxd6f5idiihwzyfg3v6y1m4z5d4f.narinfo error="server returned 404: 404 page not found\n"1174--- PASS: TestRedundantMultipartUpload (1.73s)1175=== CONT TestProxyHeadersOnlyTrustedOnSocket11762026/10/01 10:41:35 INFO Upload complete. (56ms)1177=== NAME TestNARDeduplicationMetadataUploadBug1178 metadata_upload_test.go:76: Retrieved narinfo from S3:1179 StorePath: /build/TestNARDeduplicationMetadataUploadBug2717407316/001/store/y5w6wxd6f5idiihwzyfg3v6y1m4z5d4f-file2.txt1180 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1181 Compression: zstd1182 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1183 NarSize: 1601184 References: 1185 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1186 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1187 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1188 {"version":1,"root":{"type":"regular","size":44}}1189--- PASS: TestNARDeduplicationMetadataUploadBug (0.68s)1190=== CONT TestParseSingleRange1191=== RUN TestParseSingleRange/none1192=== PAUSE TestParseSingleRange/none1193=== RUN TestParseSingleRange/unknown_unit1194=== PAUSE TestParseSingleRange/unknown_unit1195=== RUN TestParseSingleRange/multi-range_ignored1196=== PAUSE TestParseSingleRange/multi-range_ignored1197=== RUN TestParseSingleRange/malformed_no_dash1198=== PAUSE TestParseSingleRange/malformed_no_dash1199=== RUN TestParseSingleRange/malformed_both_empty1200=== PAUSE TestParseSingleRange/malformed_both_empty1201=== RUN TestParseSingleRange/malformed_end_before_start1202=== PAUSE TestParseSingleRange/malformed_end_before_start1203=== RUN TestParseSingleRange/closed1204=== PAUSE TestParseSingleRange/closed1205=== RUN TestParseSingleRange/open-ended1206=== PAUSE TestParseSingleRange/open-ended1207=== RUN TestParseSingleRange/end_clamped_to_size1208=== PAUSE TestParseSingleRange/end_clamped_to_size1209=== RUN TestParseSingleRange/suffix1210=== PAUSE TestParseSingleRange/suffix1211=== RUN TestParseSingleRange/suffix_exceeds_size1212=== PAUSE TestParseSingleRange/suffix_exceeds_size1213=== RUN TestParseSingleRange/single_byte1214=== PAUSE TestParseSingleRange/single_byte1215=== RUN TestParseSingleRange/start_past_EOF1216=== PAUSE TestParseSingleRange/start_past_EOF1217=== RUN TestParseSingleRange/start_far_past_EOF1218=== PAUSE TestParseSingleRange/start_far_past_EOF1219=== CONT TestPresentNotReportedWhileGCDeletesClosure1220--- PASS: TestPushWaitsForSweepHoldingRow (1.29s)1221=== CONT TestIsValidCachePath1222=== RUN TestIsValidCachePath/narinfo1223=== PAUSE TestIsValidCachePath/narinfo1224=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1225=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1226=== RUN TestIsValidCachePath/nar_zst1227=== PAUSE TestIsValidCachePath/nar_zst1228=== RUN TestIsValidCachePath/nar_xz1229=== PAUSE TestIsValidCachePath/nar_xz1230=== RUN TestIsValidCachePath/nar_bz21231=== PAUSE TestIsValidCachePath/nar_bz21232=== RUN TestIsValidCachePath/nar_uncompressed1233=== PAUSE TestIsValidCachePath/nar_uncompressed1234=== RUN TestIsValidCachePath/ls1235=== PAUSE TestIsValidCachePath/ls1236=== RUN TestIsValidCachePath/log1237=== PAUSE TestIsValidCachePath/log1238=== RUN TestIsValidCachePath/realisation1239=== PAUSE TestIsValidCachePath/realisation1240=== RUN TestIsValidCachePath/nix-cache-info1241=== PAUSE TestIsValidCachePath/nix-cache-info1242=== RUN TestIsValidCachePath/index.html1243=== PAUSE TestIsValidCachePath/index.html1244=== RUN TestIsValidCachePath/traversal_parent1245=== PAUSE TestIsValidCachePath/traversal_parent1246=== RUN TestIsValidCachePath/traversal_in_middle1247=== PAUSE TestIsValidCachePath/traversal_in_middle1248=== RUN TestIsValidCachePath/invalid_char_e1249=== PAUSE TestIsValidCachePath/invalid_char_e1250=== RUN TestIsValidCachePath/invalid_char_u1251=== PAUSE TestIsValidCachePath/invalid_char_u1252=== RUN TestIsValidCachePath/random_path1253=== PAUSE TestIsValidCachePath/random_path1254=== RUN TestIsValidCachePath/empty1255=== PAUSE TestIsValidCachePath/empty1256=== RUN TestIsValidCachePath/leading_slash1257=== PAUSE TestIsValidCachePath/leading_slash1258=== RUN TestIsValidCachePath/wrong_extension1259=== PAUSE TestIsValidCachePath/wrong_extension1260=== RUN TestIsValidCachePath/short_hash1261=== PAUSE TestIsValidCachePath/short_hash1262=== CONT TestObjectStatsTrigger1263--- PASS: TestService_ReadAuthMiddleware (0.40s)1264=== CONT TestOrphanedObjectsGC12652026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes12662026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes12672026/10/01 10:41:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12682026/10/01 10:41:35 INFO Uploading svvy6w5hpy3izw8lq8cjbm660r30vrbl-test-file.txt (152B)12692026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12702026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12712026/10/01 10:41:35 WARN Failed to register uploaded object key=svvy6w5hpy3izw8lq8cjbm660r30vrbl.ls error="server returned 404: 404 page not found\n"12722026/10/01 10:41:35 INFO Signed narinfos id=1 count=112732026/10/01 10:41:35 INFO Uploading 1 narinfos12742026/10/01 10:41:35 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12752026/10/01 10:41:35 INFO Uploading 2frxqhm58nmvviiavffpdcaaiqw5rrhd-test-file-1.txt (160B)12762026/10/01 10:41:35 INFO Uploading fcm4p964a8d5dwxwh9dy1zlxr549pwgc-test-file-2.txt (160B)12772026/10/01 10:41:35 INFO Uploading zlgl1x1nc4ks1xnhjksvvf9s0d89bnj7-test-file-0.txt (160B)12782026/10/01 10:41:35 INFO Received complete push request method=POST path=/api/pushes/1/complete12792026/10/01 10:41:35 WARN Failed to register uploaded object key=svvy6w5hpy3izw8lq8cjbm660r30vrbl.narinfo error="server returned 404: 404 page not found\n"12802026/10/01 10:41:35 WARN Failed to register uploaded object key=fcm4p964a8d5dwxwh9dy1zlxr549pwgc.ls error="server returned 404: 404 page not found\n"12812026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12822026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12832026/10/01 10:41:35 WARN Failed to register uploaded object key=zlgl1x1nc4ks1xnhjksvvf9s0d89bnj7.ls error="server returned 404: 404 page not found\n"12842026/10/01 10:41:35 WARN Failed to register uploaded object key=2frxqhm58nmvviiavffpdcaaiqw5rrhd.ls error="server returned 404: 404 page not found\n"12852026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12862026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12872026/10/01 10:41:35 INFO Signed narinfos id=1 count=312882026/10/01 10:41:35 INFO Uploading 3 narinfos12892026/10/01 10:41:35 INFO Upload complete. (69ms)12902026/10/01 10:41:35 WARN Failed to register uploaded object key=zlgl1x1nc4ks1xnhjksvvf9s0d89bnj7.narinfo error="server returned 404: 404 page not found\n"12912026/10/01 10:41:35 INFO Received complete push request method=POST path=/api/pushes/1/complete12922026/10/01 10:41:35 WARN Failed to register uploaded object key=fcm4p964a8d5dwxwh9dy1zlxr549pwgc.narinfo error="server returned 404: 404 page not found\n"12932026/10/01 10:41:35 WARN Failed to register uploaded object key=2frxqhm58nmvviiavffpdcaaiqw5rrhd.narinfo error="server returned 404: 404 page not found\n"1294--- PASS: TestCacheStatsHandler (0.42s)1295=== CONT TestPendingCleanupUsesOneCutoff12962026/10/01 10:41:35 INFO Upload complete. (71ms)1297=== NAME TestClientMultipleUploads1298 client_integration_test.go:369: Uploaded 3 paths in 105.750142ms1299--- PASS: TestClientMultipleUploads (0.62s)1300=== CONT TestOrphanedObjectsGCStressTest1301=== NAME TestClientCADerivations1302 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2177128457/001/store/09jmnxky1dsl287ljbm2pbpb0sblq1qw-ca-test13032026/10/01 10:41:35 INFO lead: released remote=192.0.2.1:123413042026/10/01 10:41:35 INFO All 1 paths already cached1305=== NAME TestClientIntegration1306 client_integration_test.go:312: Retrieved narinfo from S3:1307 StorePath: /build/TestClientIntegration3108142420/002/store/svvy6w5hpy3izw8lq8cjbm660r30vrbl-test-file.txt1308 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1309 Compression: zstd1310 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11311 NarSize: 1521312 References: 1313 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11314 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1315 client_integration_test.go:313: Decompressed .ls content (64 bytes):1316 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1317 client_integration_test.go:316: Testing garbage collection...1318=== NAME TestClientCADerivations1319 client_ca_test.go:139: Found 1 dependencies (including self)13202026/10/01 10:41:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures13212026/10/01 10:41:35 INFO Garbage collection started13222026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=013232026/10/01 10:41:35 INFO lead: acquired remote=192.0.2.1:123413242026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period13252026/10/01 10:41:35 INFO lead: released remote=192.0.2.1:12341326--- PASS: TestLeadElectsOneAndHandsOver (0.59s)1327=== CONT TestCreatePin_ReservedPins13282026/10/01 10:41:35 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=013292026/10/01 10:41:35 INFO Vacuumed table table=pending_closures13302026/10/01 10:41:35 INFO Vacuumed table table=pending_objects13312026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads13322026/10/01 10:41:35 INFO Vacuumed table table=closures13332026/10/01 10:41:35 INFO Vacuumed table table=objects1334=== NAME TestPinProtectsFromGC1335 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1309204789/001/store/baa52haycnspsfd41mabyi7f321wwqzq-pinned-file.txt1336 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1309204789/001/store/q6s6kcnb82l73as9xm5hqviyac31zcj1-unpinned-file.txt1337=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1338=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1339=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1340=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1341=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1342=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1343=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1344=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1345=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure13462026/10/01 10:41:35 INFO Received uploads request method=POST path=/13472026/10/01 10:41:35 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13482026/10/01 10:41:35 WARN mTLS auth: bound subjects configured but subject DN unavailable13492026/10/01 10:41:35 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1350--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.35s)1351=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart13522026/10/01 10:41:35 INFO Received complete multipart upload request method=POST path=/13532026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes1354--- PASS: TestPresentReportsOnlyClosureRoots (0.36s)1355=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts13562026/10/01 10:41:35 INFO Received request for more parts method=POST path=/13572026/10/01 10:41:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13582026/10/01 10:41:35 INFO Uploading 09jmnxky1dsl287ljbm2pbpb0sblq1qw-ca-test (144B)13592026/10/01 10:41:35 WARN Failed to register uploaded object key=09jmnxky1dsl287ljbm2pbpb0sblq1qw.ls error="server returned 404: 404 page not found\n"13602026/10/01 10:41:35 WARN Failed to register uploaded object key=log/383fr7bxsfxk4lnlhd4g81d9nxxk4kwc-ca-test.drv error="server returned 404: 404 page not found\n"13612026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures13622026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13632026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13642026/10/01 10:41:35 INFO Signed narinfos id=1 count=113652026/10/01 10:41:35 INFO Uploading 1 narinfos13662026/10/01 10:41:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33737/oidc13672026/10/01 10:41:35 INFO Received complete push request method=POST path=/api/pushes/1/complete13682026/10/01 10:41:35 WARN Failed to register uploaded object key=09jmnxky1dsl287ljbm2pbpb0sblq1qw.narinfo error="server returned 404: 404 page not found\n"13692026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes13702026/10/01 10:41:35 INFO Upload complete. (92ms)1371=== NAME TestClientCADerivations1372 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2177128457/001/store/09jmnxky1dsl287ljbm2pbpb0sblq1qw-ca-test1373 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1374 Compression: zstd1375 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1376 NarSize: 1441377 References: 1378 Deriver: /build/TestClientCADerivations2177128457/001/store/383fr7bxsfxk4lnlhd4g81d9nxxk4kwc-ca-test.drv1379 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1380 client_ca_test.go:185: Checking for realisation files in S3...1381 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1382 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13832026/10/01 10:41:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13842026/10/01 10:41:35 INFO Uploading baa52haycnspsfd41mabyi7f321wwqzq-pinned-file.txt (128B)1385--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.35s)1386=== CONT TestPush_RejectsBadRequests/no_roots13872026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes1388=== CONT TestPush_RejectsBadRequests/bad_root13892026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes1390=== CONT TestPush_RejectsBadRequests/root_not_in_objects13912026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes1392=== CONT TestPush_RejectsBadRequests/no_objects13932026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes1394=== CONT TestServerTLSConfig/no_client_CA1395--- PASS: TestPush_RejectsBadRequests (0.51s)1396 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1397 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1398 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1399 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1400=== CONT TestServerTLSConfig/not_a_PEM_file1401=== CONT TestServerTLSConfig/missing_CA_file1402--- PASS: TestServerTLSConfig (0.00s)1403 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1404 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1405 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1406=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows14072026/10/01 10:41:35 WARN Failed to register uploaded object key=baa52haycnspsfd41mabyi7f321wwqzq.ls error="server returned 404: 404 page not found\n"14082026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14092026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14102026/10/01 10:41:35 INFO Signed narinfos id=1 count=114112026/10/01 10:41:35 INFO Uploading 1 narinfos14122026/10/01 10:41:35 INFO Received complete push request method=POST path=/api/pushes/1/complete14132026/10/01 10:41:35 WARN Failed to register uploaded object key=baa52haycnspsfd41mabyi7f321wwqzq.narinfo error="server returned 404: 404 page not found\n"1414=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check14152026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes14162026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes14172026/10/01 10:41:35 INFO Upload complete. (59ms)14182026/10/01 10:41:35 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14192026/10/01 10:41:35 INFO Uploading zmwa3mpnngklgcv0n1rd2fdr7b3awd2v-top (224B)14202026/10/01 10:41:35 INFO Uploading lwhzz5gzrzsz6kfiwccawaqfrdkrcqzg-shared-dep (136B)14212026/10/01 10:41:35 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14222026/10/01 10:41:35 INFO Uploading h3f1gqkjhlkdgh4nr5h7lnpwpa07rswp-shared-dep (136B)14232026/10/01 10:41:35 INFO Uploading krrq3q7f6wk3fb5vijc6x1v8zm0maf6b-b (216B)14242026/10/01 10:41:35 WARN Failed to register uploaded object key=lwhzz5gzrzsz6kfiwccawaqfrdkrcqzg.ls error="server returned 404: 404 page not found\n"14252026/10/01 10:41:35 WARN Failed to register uploaded object key=zmwa3mpnngklgcv0n1rd2fdr7b3awd2v.ls error="server returned 404: 404 page not found\n"14262026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14272026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14282026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/0z5ji40nadz5gndr0i4f2zgs85pzbxfxahmancx7zyb56ykn7j7f.nar.zst error="server returned 404: 404 page not found\n"14292026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14302026/10/01 10:41:35 INFO Signed narinfos id=1 count=214312026/10/01 10:41:35 INFO Uploading 2 narinfos14322026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/03s1mvaizwnfy4p76sabc884jr0dby850ayagbkzwzka4h77yc68.nar.zst error="server returned 404: 404 page not found\n"14332026/10/01 10:41:35 WARN Failed to register uploaded object key=h3f1gqkjhlkdgh4nr5h7lnpwpa07rswp.ls error="server returned 404: 404 page not found\n"14342026/10/01 10:41:35 WARN Failed to register uploaded object key=382jvir9pkjlp61pvnf7c06lnfcxfl69.ls error="server returned 404: 404 page not found\n"14352026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14362026/10/01 10:41:35 WARN Failed to register uploaded object key=krrq3q7f6wk3fb5vijc6x1v8zm0maf6b.ls error="server returned 404: 404 page not found\n"14372026/10/01 10:41:35 INFO Signed narinfos id=1 count=314382026/10/01 10:41:35 INFO Uploading 3 narinfos14392026/10/01 10:41:35 INFO Received complete push request method=POST path=/api/pushes/1/complete14402026/10/01 10:41:35 WARN Failed to register uploaded object key=lwhzz5gzrzsz6kfiwccawaqfrdkrcqzg.narinfo error="server returned 404: 404 page not found\n"14412026/10/01 10:41:35 WARN Failed to register uploaded object key=zmwa3mpnngklgcv0n1rd2fdr7b3awd2v.narinfo error="server returned 404: 404 page not found\n"14422026/10/01 10:41:35 WARN Failed to register uploaded object key=krrq3q7f6wk3fb5vijc6x1v8zm0maf6b.narinfo error="server returned 404: 404 page not found\n"14432026/10/01 10:41:35 WARN Failed to register uploaded object key=382jvir9pkjlp61pvnf7c06lnfcxfl69.narinfo error="server returned 404: 404 page not found\n"14442026/10/01 10:41:35 INFO Received complete push request method=POST path=/api/pushes/1/complete14452026/10/01 10:41:35 WARN Failed to register uploaded object key=h3f1gqkjhlkdgh4nr5h7lnpwpa07rswp.narinfo error="server returned 404: 404 page not found\n"14462026/10/01 10:41:35 INFO Upload complete. (62ms)1447=== NAME TestClientSharedPathCommittedMidPush1448 client_integration_test.go:680: Retrieved narinfo from S3:1449 StorePath: /build/TestClientSharedPathCommittedMidPush1170350869/001/store/lwhzz5gzrzsz6kfiwccawaqfrdkrcqzg-shared-dep1450 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1451 Compression: zstd1452 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821453 NarSize: 1361454 References: 1455 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14562026/10/01 10:41:35 INFO Upload complete. (66ms)1457=== RUN TestService_RequireScope_OIDC/builder_may_write1458=== PAUSE TestService_RequireScope_OIDC/builder_may_write1459=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1460=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1461=== NAME TestClientPushesUseOnePush1462 client_pushes_test.go:97: Retrieved narinfo from S3:1463 StorePath: /build/TestClientPushesUseOnePush2935430330/001/store/h3f1gqkjhlkdgh4nr5h7lnpwpa07rswp-shared-dep1464 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1465 Compression: zstd1466=== RUN TestService_RequireScope_OIDC/ops_may_admin1467=== NAME TestClientPushesUseOnePush1468 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821469 NarSize: 1361470 References: 1471 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1472=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1473=== RUN TestService_RequireScope_OIDC/ops_may_not_write1474=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1475=== RUN TestService_RequireScope_OIDC/reader_may_not_write1476=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1477=== RUN TestService_RequireScope_OIDC/static_token_may_admin1478=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1479=== RUN TestService_RequireScope_OIDC/static_token_may_write1480=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1481=== RUN TestService_RequireScope_OIDC/reader_may_read1482=== PAUSE TestService_RequireScope_OIDC/reader_may_read1483=== RUN TestService_RequireScope_OIDC/writer_implies_read1484=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1485=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1486=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1487=== CONT TestPendingClosureWriteTimeout/empty1488=== CONT TestPendingClosureWriteTimeout/670k_objects1489=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1490=== NAME TestClientSharedPathCommittedMidPush1491 client_integration_test.go:680: Retrieved narinfo from S3:1492 StorePath: /build/TestClientSharedPathCommittedMidPush1170350869/001/store/zmwa3mpnngklgcv0n1rd2fdr7b3awd2v-top1493 URL: nar/0z5ji40nadz5gndr0i4f2zgs85pzbxfxahmancx7zyb56ykn7j7f.nar.zst1494 Compression: zstd1495 NarHash: sha256:0z5ji40nadz5gndr0i4f2zgs85pzbxfxahmancx7zyb56ykn7j7f1496 NarSize: 2241497 References: /build/TestClientSharedPathCommittedMidPush1170350869/001/store/lwhzz5gzrzsz6kfiwccawaqfrdkrcqzg-shared-dep1498 CA: text:sha256:0g792v95mxdk9nb06i1cmgc1bwgxbyizpb12a5g0r2nlgppx4mqp1499=== CONT TestPendingClosureWriteTimeout/400_objects1500=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1501=== NAME TestClientPushesUseOnePush15022026/10/01 10:41:35 INFO Received uploads request method=POST path=/1503 client_pushes_test.go:97: Retrieved narinfo from S3:1504 StorePath: /build/TestClientPushesUseOnePush2935430330/001/store/382jvir9pkjlp61pvnf7c06lnfcxfl69-a1505 URL: nar/03s1mvaizwnfy4p76sabc884jr0dby850ayagbkzwzka4h77yc68.nar.zst1506 Compression: zstd1507 NarHash: sha256:03s1mvaizwnfy4p76sabc884jr0dby850ayagbkzwzka4h77yc681508 NarSize: 2161509 References: /build/TestClientPushesUseOnePush2935430330/001/store/h3f1gqkjhlkdgh4nr5h7lnpwpa07rswp-shared-dep1510 CA: text:sha256:1lgnz7r1adgpnkx1lh4j1xa0i9qx1jb64x864hy72i2g4jyvhmm61511=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15122026/10/01 10:41:35 INFO Received complete multipart upload request method=POST path=/1513=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15142026/10/01 10:41:35 INFO Received request for more parts method=POST path=/1515=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15162026/10/01 10:41:35 INFO Received uploads request method=POST path=/1517=== CONT TestIsValidUploadKey/narinfo1518=== CONT TestIsValidUploadKey/realisation_plus_in_output1519=== CONT TestIsValidUploadKey/unknown_type1520=== CONT TestIsValidUploadKey/empty_key1521--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1522 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1523 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1524 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1525 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1526=== CONT TestIsValidUploadKey/absolute1527=== CONT TestIsValidUploadKey/traversal_nar1528=== CONT TestIsValidUploadKey/traversal1529=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1530=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1531=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1532=== CONT TestIsValidUploadKey/nix-cache-info1533=== CONT TestIsValidUploadKey/build_log_home-manager_file1534=== CONT TestIsValidUploadKey/realisation1535=== CONT TestIsValidUploadKey/build_log_equals1536=== CONT TestIsValidUploadKey/index.html1537=== CONT TestIsValidUploadKey/build_log_question_mark1538=== CONT TestIsValidUploadKey/build_log_plus_in_name1539=== CONT TestIsValidUploadKey/nar_plain1540=== CONT TestIsValidUploadKey/build_log1541=== CONT TestIsValidUploadKey/listing1542=== CONT TestIsValidUploadKey/nar_xz1543=== CONT TestIsValidUploadKey/nar_zst1544--- PASS: TestIsValidUploadKey (0.00s)1545 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1546 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1547 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1548 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1549 --- PASS: TestIsValidUploadKey/absolute (0.00s)1550 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1551 --- PASS: TestIsValidUploadKey/traversal (0.00s)1552 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1553 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1554 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1555 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1556 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1557 --- PASS: TestIsValidUploadKey/realisation (0.00s)1558 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1559 --- PASS: TestIsValidUploadKey/index.html (0.00s)1560 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1561 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1562 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1563 --- PASS: TestIsValidUploadKey/build_log (0.00s)1564 --- PASS: TestIsValidUploadKey/listing (0.00s)1565 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1566 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1567=== CONT TestProxyWriteTimeout/narinfo1568=== CONT TestProxyWriteTimeout/10_GiB_nar1569=== CONT TestProxyWriteTimeout/1_GiB_nar1570=== CONT TestProxyWriteTimeout/unknown_size1571--- PASS: TestProxyWriteTimeout (0.00s)1572 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1573 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1574 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1575 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1576=== CONT TestClientErrorHandling/InvalidStorePath1577=== NAME TestClientPushesUseOnePush1578 client_pushes_test.go:97: Retrieved narinfo from S3:1579 StorePath: /build/TestClientPushesUseOnePush2935430330/001/store/krrq3q7f6wk3fb5vijc6x1v8zm0maf6b-b1580 URL: nar/03s1mvaizwnfy4p76sabc884jr0dby850ayagbkzwzka4h77yc68.nar.zst1581 Compression: zstd1582 NarHash: sha256:03s1mvaizwnfy4p76sabc884jr0dby850ayagbkzwzka4h77yc681583 NarSize: 2161584 References: /build/TestClientPushesUseOnePush2935430330/001/store/h3f1gqkjhlkdgh4nr5h7lnpwpa07rswp-shared-dep1585 CA: text:sha256:1lgnz7r1adgpnkx1lh4j1xa0i9qx1jb64x864hy72i2g4jyvhmm61586--- PASS: TestClientSharedPathCommittedMidPush (0.54s)1587=== CONT TestClientErrorHandling/ServerNotAvailable1588--- PASS: TestClientPushesUseOnePush (0.63s)1589=== CONT TestClientErrorHandling/InvalidAuthToken15902026/10/01 10:41:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15912026/10/01 10:41:35 INFO Received push request method=POST path=/api/pushes15922026/10/01 10:41:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15932026/10/01 10:41:35 INFO Uploading q6s6kcnb82l73as9xm5hqviyac31zcj1-unpinned-file.txt (128B)15942026/10/01 10:41:35 INFO Starting HTTP server address=127.0.0.1:3288515952026/10/01 10:41:35 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket4136348574/001/proxy.sock15962026/10/01 10:41:35 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15972026/10/01 10:41:35 INFO Shutdown signal received, draining in-flight requests timeout=10s1598--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.35s)1599=== CONT TestCacheConfigHandler/full_config,_no_issuer16002026/10/01 10:41:35 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1601=== CONT TestCacheConfigHandler/no_signing_keys1602=== CONT TestCacheConfigHandler/no_cache_url_configured1603=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1604--- PASS: TestCacheConfigHandler (0.00s)1605 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1606 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1607 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1608 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1609=== CONT TestResolveDBConnectionString/flag_wins1610=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1611=== CONT TestResolveDBConnectionString/nothing_configured1612=== CONT TestResolveDBConnectionString/missing_file_is_an_error1613=== CONT TestResolveDBConnectionString/file_when_flag_empty1614=== CONT TestParseSingleRange/none1615=== CONT TestParseSingleRange/open-ended1616=== CONT TestParseSingleRange/start_far_past_EOF1617=== CONT TestParseSingleRange/start_past_EOF1618=== CONT TestParseSingleRange/single_byte1619=== CONT TestParseSingleRange/suffix_exceeds_size1620=== CONT TestParseSingleRange/suffix1621=== CONT TestParseSingleRange/end_clamped_to_size1622--- PASS: TestResolveDBConnectionString (0.00s)1623 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1624 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1625 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1626 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1627 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1628=== CONT TestParseSingleRange/malformed_both_empty1629=== CONT TestParseSingleRange/closed1630=== CONT TestParseSingleRange/malformed_end_before_start1631=== CONT TestParseSingleRange/unknown_unit1632=== CONT TestParseSingleRange/multi-range_ignored1633=== CONT TestParseSingleRange/malformed_no_dash1634--- PASS: TestParseSingleRange (0.00s)1635 --- PASS: TestParseSingleRange/none (0.00s)1636 --- PASS: TestParseSingleRange/open-ended (0.00s)1637 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1638 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1639 --- PASS: TestParseSingleRange/single_byte (0.00s)1640 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1641 --- PASS: TestParseSingleRange/suffix (0.00s)1642 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1643 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1644 --- PASS: TestParseSingleRange/closed (0.00s)1645 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1646 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1647 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1648 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1649=== CONT TestIsValidCachePath/narinfo1650=== CONT TestIsValidCachePath/index.html1651=== CONT TestIsValidCachePath/short_hash1652=== CONT TestIsValidCachePath/wrong_extension1653=== CONT TestIsValidCachePath/leading_slash1654=== CONT TestIsValidCachePath/empty1655=== CONT TestIsValidCachePath/random_path1656=== CONT TestIsValidCachePath/invalid_char_u1657=== CONT TestIsValidCachePath/invalid_char_e1658=== CONT TestIsValidCachePath/traversal_in_middle1659=== CONT TestIsValidCachePath/traversal_parent1660=== CONT TestIsValidCachePath/nar_uncompressed1661=== CONT TestIsValidCachePath/log1662=== CONT TestIsValidCachePath/realisation1663=== CONT TestIsValidCachePath/ls1664=== CONT TestIsValidCachePath/nix-cache-info1665=== CONT TestIsValidCachePath/nar_xz1666=== CONT TestIsValidCachePath/nar_zst1667=== CONT TestIsValidCachePath/nar_bz21668=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1669--- PASS: TestIsValidCachePath (0.00s)1670 --- PASS: TestIsValidCachePath/narinfo (0.00s)1671 --- PASS: TestIsValidCachePath/index.html (0.00s)1672 --- PASS: TestIsValidCachePath/short_hash (0.00s)1673 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1674 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1675 --- PASS: TestIsValidCachePath/empty (0.00s)1676 --- PASS: TestIsValidCachePath/random_path (0.00s)1677 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1678 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1679 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1680 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1681 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1682 --- PASS: TestIsValidCachePath/log (0.00s)1683 --- PASS: TestIsValidCachePath/realisation (0.00s)1684 --- PASS: TestIsValidCachePath/ls (0.00s)1685 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1686 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1687 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1688 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1689 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1690=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token16912026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16922026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16932026/10/01 10:41:35 WARN Failed to register uploaded object key=q6s6kcnb82l73as9xm5hqviyac31zcj1.ls error="server returned 404: 404 page not found\n"16942026/10/01 10:41:35 INFO Signed narinfos id=2 count=116952026/10/01 10:41:35 INFO Uploading 1 narinfos1696=== NAME TestClientCADerivations1697 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1698 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1699 error: binary cache 's3://bucket60?endpoint=http://localhost:40581®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2177128457/001/store'1700 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11701=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17022026/10/01 10:41:35 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]1703=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1704=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1705--- PASS: TestClientCADerivations (0.73s)1706=== CONT TestService_RequireScope_OIDC/builder_may_write17072026/10/01 10:41:35 INFO Received complete push request method=POST path=/api/pushes/2/complete17082026/10/01 10:41:35 WARN Failed to register uploaded object key=q6s6kcnb82l73as9xm5hqviyac31zcj1.narinfo error="server returned 404: 404 page not found\n"1709=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1710=== CONT TestService_RequireScope_OIDC/writer_implies_read17112026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures1712=== CONT TestService_RequireScope_OIDC/reader_may_read1713=== CONT TestService_RequireScope_OIDC/static_token_may_write1714=== CONT TestService_RequireScope_OIDC/static_token_may_admin1715=== CONT TestService_RequireScope_OIDC/reader_may_not_write17162026/10/01 10:41:35 WARN Authentication failed token_preview=eyJhbGciOi...Qn4zbJDjXA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1717=== CONT TestService_RequireScope_OIDC/ops_may_not_write1718=== CONT TestService_RequireScope_OIDC/ops_may_admin1719=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1720--- PASS: TestService_AuthMiddleware_OIDC (0.46s)1721 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1722 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1723 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1724 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1725--- PASS: TestService_RequireScope_OIDC (0.59s)1726 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1727 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1728 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1729 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1730 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1731 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1732 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1733 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1734 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1735 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)17362026/10/01 10:41:35 INFO Upload complete. (54ms)17372026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures17382026/10/01 10:41:35 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17392026/10/01 10:41:35 INFO Uploading qkbcf7dhbq34kw1k5kgqxfjr0as4vxbi-shared-dep (136B)17402026/10/01 10:41:35 INFO Uploading 44kyn5cqqzdscd4x76i7mq07hi0p6bnf-b (216B)17412026/10/01 10:41:35 WARN Failed to register uploaded object key=l8q7asi4p50kkgsvwfzgm6g59vy0pqif.ls error="server returned 404: 404 page not found\n"17422026/10/01 10:41:35 WARN Failed to register uploaded object key=44kyn5cqqzdscd4x76i7mq07hi0p6bnf.ls error="server returned 404: 404 page not found\n"17432026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/1n3sif2pv2s1xvgk3yly5qz3g6p5x7dzgb2phn1p0li6icgp7a98.nar.zst error="server returned 404: 404 page not found\n"17442026/10/01 10:41:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17452026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17462026/10/01 10:41:35 WARN Failed to register uploaded object key=qkbcf7dhbq34kw1k5kgqxfjr0as4vxbi.ls error="server returned 404: 404 page not found\n"17472026/10/01 10:41:35 INFO Signed narinfos id=1 count=217482026/10/01 10:41:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17492026/10/01 10:41:35 INFO Signed narinfos id=2 count=217502026/10/01 10:41:35 INFO Uploading 4 narinfos17512026/10/01 10:41:35 WARN Failed to register uploaded object key=qkbcf7dhbq34kw1k5kgqxfjr0as4vxbi.narinfo error="server returned 404: 404 page not found\n"17522026/10/01 10:41:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17532026/10/01 10:41:35 WARN Failed to register uploaded object key=l8q7asi4p50kkgsvwfzgm6g59vy0pqif.narinfo error="server returned 404: 404 page not found\n"17542026/10/01 10:41:35 WARN Failed to register uploaded object key=44kyn5cqqzdscd4x76i7mq07hi0p6bnf.narinfo error="server returned 404: 404 page not found\n"17552026/10/01 10:41:35 WARN Failed to register uploaded object key=qkbcf7dhbq34kw1k5kgqxfjr0as4vxbi.narinfo error="server returned 404: 404 page not found\n"17562026/10/01 10:41:35 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/present17572026/10/01 10:41:35 INFO Completed upload id=117582026/10/01 10:41:35 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17592026/10/01 10:41:35 INFO Completed upload id=217602026/10/01 10:41:35 INFO Upload complete. (72ms)1761=== NAME TestClientFallsBackToClosures1762 client_pushes_test.go:112: Retrieved narinfo from S3:1763 StorePath: /build/TestClientFallsBackToClosures2662294815/001/store/qkbcf7dhbq34kw1k5kgqxfjr0as4vxbi-shared-dep1764 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1765 Compression: zstd1766 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821767 NarSize: 1361768 References: 1769 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1770 client_pushes_test.go:112: Retrieved narinfo from S3:1771 StorePath: /build/TestClientFallsBackToClosures2662294815/001/store/l8q7asi4p50kkgsvwfzgm6g59vy0pqif-a1772 URL: nar/1n3sif2pv2s1xvgk3yly5qz3g6p5x7dzgb2phn1p0li6icgp7a98.nar.zst1773 Compression: zstd1774 NarHash: sha256:1n3sif2pv2s1xvgk3yly5qz3g6p5x7dzgb2phn1p0li6icgp7a981775 NarSize: 2161776 References: /build/TestClientFallsBackToClosures2662294815/001/store/qkbcf7dhbq34kw1k5kgqxfjr0as4vxbi-shared-dep1777 CA: text:sha256:1h92imphq9cpllkp7h3cnirbkszq95b7kimbxcmvjh9j824bv0921778 client_pushes_test.go:112: Retrieved narinfo from S3:1779 StorePath: /build/TestClientFallsBackToClosures2662294815/001/store/44kyn5cqqzdscd4x76i7mq07hi0p6bnf-b1780 URL: nar/1n3sif2pv2s1xvgk3yly5qz3g6p5x7dzgb2phn1p0li6icgp7a98.nar.zst1781 Compression: zstd1782 NarHash: sha256:1n3sif2pv2s1xvgk3yly5qz3g6p5x7dzgb2phn1p0li6icgp7a981783 NarSize: 2161784 References: /build/TestClientFallsBackToClosures2662294815/001/store/qkbcf7dhbq34kw1k5kgqxfjr0as4vxbi-shared-dep1785 CA: text:sha256:1h92imphq9cpllkp7h3cnirbkszq95b7kimbxcmvjh9j824bv0921786--- PASS: TestClientFallsBackToClosures (0.60s)17872026/10/01 10:41:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures17882026/10/01 10:41:35 INFO Garbage collection started1789--- PASS: TestObjectStatsTrigger (0.39s)17902026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=017912026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period1792=== NAME TestClientWithDependencies1793 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3867927134/001/store/wgwwdi8a9j7m0z28avgq8fjli96shchl-test-script17942026/10/01 10:41:35 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=017952026/10/01 10:41:35 INFO Vacuumed table table=pending_closures17962026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures17972026/10/01 10:41:35 INFO Vacuumed table table=pending_objects17982026/10/01 10:41:35 INFO Vacuumed table table=multipart_uploads17992026/10/01 10:41:35 INFO Vacuumed table table=closures18002026/10/01 10:41:35 INFO Vacuumed table table=objects18012026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures18022026/10/01 10:41:35 INFO Received cleanup request method=DELETE path=/api/pending_closures1803 client_integration_test.go:615: Found 1 dependencies (including self)18042026/10/01 10:41:35 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18052026/10/01 10:41:35 WARN Refused reserved pin name=worker-x86_64-linux18062026/10/01 10:41:35 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18072026/10/01 10:41:35 INFO Received create pin request method=POST path=/api/pins/my-app18082026/10/01 10:41:35 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1809--- PASS: TestCreatePin_ReservedPins (0.32s)18102026/10/01 10:41:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.153963ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18112026/10/01 10:41:35 INFO Received uploads request method=POST path=/api/pending_closures18122026/10/01 10:41:35 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161813--- PASS: TestReadProxyNarinfo (0.56s)18142026/10/01 10:41:35 INFO Aborted multipart uploads count=0 kept=018152026/10/01 10:41:35 WARN Force mode enabled - objects will be deleted immediately without grace period18162026/10/01 10:41:36 INFO Received uploads request method=POST path=/api/pending_closures18172026/10/01 10:41:36 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=018182026/10/01 10:41:36 INFO Vacuumed table table=pending_closures18192026/10/01 10:41:36 INFO Vacuumed table table=pending_objects18202026/10/01 10:41:36 INFO Vacuumed table table=multipart_uploads18212026/10/01 10:41:36 INFO Vacuumed table table=closures18222026/10/01 10:41:36 INFO Vacuumed table table=objects18232026/10/01 10:41:36 INFO Aborted multipart uploads count=0 kept=018242026/10/01 10:41:36 INFO Received uploads request method=POST path=/api/pending_closures18252026/10/01 10:41:36 WARN Force mode enabled - objects will be deleted immediately without grace period18262026/10/01 10:41:36 INFO Received push request method=POST path=/api/pushes18272026/10/01 10:41:36 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=01828--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.74s)18292026/10/01 10:41:36 INFO Vacuumed table table=pending_closures18302026/10/01 10:41:36 INFO Vacuumed table table=pending_objects18312026/10/01 10:41:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18322026/10/01 10:41:36 INFO Uploading wgwwdi8a9j7m0z28avgq8fjli96shchl-test-script (136B)18332026/10/01 10:41:36 INFO Vacuumed table table=multipart_uploads18342026/10/01 10:41:36 INFO Vacuumed table table=closures18352026/10/01 10:41:36 INFO Vacuumed table table=objects18362026/10/01 10:41:36 WARN Failed to register uploaded object key=log/36pyapg7p1ygc53svx661gmfjd97gjqs-test-script.drv error="server returned 404: 404 page not found\n"18372026/10/01 10:41:36 WARN Failed to register uploaded object key=wgwwdi8a9j7m0z28avgq8fjli96shchl.ls error="server returned 404: 404 page not found\n"18382026/10/01 10:41:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18392026/10/01 10:41:36 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18402026/10/01 10:41:36 INFO Signed narinfos id=1 count=118412026/10/01 10:41:36 INFO Uploading 1 narinfos18422026/10/01 10:41:36 INFO Received complete push request method=POST path=/api/pushes/1/complete18432026/10/01 10:41:36 WARN Failed to register uploaded object key=wgwwdi8a9j7m0z28avgq8fjli96shchl.narinfo error="server returned 404: 404 page not found\n"1844--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1845 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.27s)1846 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.27s)18472026/10/01 10:41:36 INFO Upload complete. (54ms)1848=== NAME TestClientWithDependencies1849 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3867927134/001/store) requires matching store prefix1850--- PASS: TestClientWithDependencies (0.57s)18512026/10/01 10:41:36 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18522026/10/01 10:41:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=394.919201ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18532026/10/01 10:41:36 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1854=== NAME TestOrphanedObjectsGC1855 orphaned_objects_gc_test.go:290: GC Test Summary:1856 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1857 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1858 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1859 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1860 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1861--- PASS: TestOrphanedObjectsGC (0.75s)1862--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.87s)18632026/10/01 10:41:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=790.978097ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1864--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)1865 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1866 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1867 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.06s)1868--- PASS: TestPendingClosureWriteTimeout (0.00s)1869 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1870 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1871 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1872 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.03s)1873=== NAME TestOrphanedObjectsGCStressTest1874 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1875 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1876 orphaned_objects_gc_test.go:509: Stress test completed successfully:1877 orphaned_objects_gc_test.go:510: - Active objects preserved: 201878 orphaned_objects_gc_test.go:511: - Objects deleted: 2101879 orphaned_objects_gc_test.go:512: - Total GC'd: 2101880--- PASS: TestOrphanedObjectsGCStressTest (1.62s)18812026/10/01 10:41:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.696440903s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18822026/10/01 10:41:37 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01883=== NAME TestClientIntegration1884 client_integration_test.go:323: Objects in database after GC:1885 client_integration_test.go:323: Successfully deleted all objects with GC --force1886--- PASS: TestClientIntegration (2.59s)18872026/10/01 10:41:37 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018882026/10/01 10:41:37 INFO Received create pin request method=POST path=/api/pins/myapp18892026/10/01 10:41:37 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1309204789/001/store/baa52haycnspsfd41mabyi7f321wwqzq-pinned-file.txt narinfo_key=baa52haycnspsfd41mabyi7f321wwqzq.narinfo18902026/10/01 10:41:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures18912026/10/01 10:41:37 INFO Garbage collection started18922026/10/01 10:41:37 INFO Aborted multipart uploads count=0 kept=018932026/10/01 10:41:37 WARN Force mode enabled - objects will be deleted immediately without grace period18942026/10/01 10:41:37 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=018952026/10/01 10:41:37 INFO Vacuumed table table=pending_closures18962026/10/01 10:41:37 INFO Vacuumed table table=pending_objects18972026/10/01 10:41:37 INFO Vacuumed table table=multipart_uploads18982026/10/01 10:41:37 INFO Vacuumed table table=closures18992026/10/01 10:41:37 INFO Vacuumed table table=objects1900--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.00s)19012026/10/01 10:41:39 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-config19022026/10/01 10:41:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.725182ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19032026/10/01 10:41:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.078815ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19042026/10/01 10:41:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=738.850251ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1905=== NAME TestPinProtectsFromGC1906 client_integration_test.go:840: Pin successfully protected closure from garbage collection1907--- PASS: TestPinProtectsFromGC (4.69s)1908--- PASS: TestConnectWaitsForAPeerMigration (5.12s)19092026/10/01 10:41:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.636115927s 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:41:41 WARN Rate limiter enabled after throttle name=s3-test rate=519112026/10/01 10:41:41 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1912=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1913 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101914 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001915--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.71s)19162026/10/01 10:41:41 INFO Aborted multipart uploads count=1 kept=019172026/10/01 10:41:41 INFO Received cleanup request method=DELETE path=/api/pending_closures19182026/10/01 10:41:41 INFO Aborted multipart uploads count=1 kept=01919--- PASS: TestPendingCleanupUsesOneCutoff (6.38s)19202026/10/01 10:41:42 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"19212026/10/01 10:41:42 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19222026/10/01 10:41:42 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.935579ms 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:41:42 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=413.360046ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19242026/10/01 10:41:42 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=845.071685ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19252026/10/01 10:41:43 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.461670675s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19262026/10/01 10:41:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19272026/10/01 10:41:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.133236ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19282026/10/01 10:41:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.042955ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19292026/10/01 10:41:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=843.707782ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19302026/10/01 10:41:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.712558556s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1931--- PASS: TestClientErrorHandling (0.00s)1932 --- PASS: TestClientErrorHandling/InvalidStorePath (0.27s)1933 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.45s)1934 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.70s)1935PASS1936{"timestamp":"2026-10-01T10:41:48.496369254Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55184","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(207)"}19372026-10-01 10:41:48.722 UTC [130] LOG: received smart shutdown request19382026-10-01 10:41:48.726 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 119392026-10-01 10:41:48.738 UTC [135] LOG: shutting down19402026-10-01 10:41:48.738 UTC [135] LOG: checkpoint starting: shutdown immediate19412026-10-01 10:41:49.208 UTC [135] LOG: checkpoint complete: wrote 10805 buffers (65.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.182 s, sync=0.268 s, total=0.471 s; sync files=29656, longest=0.002 s, average=0.001 s; distance=410231 kB, estimate=410231 kB; lsn=0/1A803BE0, redo lsn=0/1A803BE019422026-10-01 10:41:49.276 UTC [130] LOG: database system is shut down1943Running OIDC tests...1944=== RUN TestAudienceForIssuer1945=== PAUSE TestAudienceForIssuer1946=== RUN TestGlobMatch1947=== PAUSE TestGlobMatch1948=== RUN TestValidateToken_ValidToken1949=== PAUSE TestValidateToken_ValidToken1950=== RUN TestValidateToken_WrongAudience1951=== PAUSE TestValidateToken_WrongAudience1952=== RUN TestValidateToken_Expired1953=== PAUSE TestValidateToken_Expired1954=== RUN TestValidateToken_BoundClaimsMismatch1955=== PAUSE TestValidateToken_BoundClaimsMismatch1956=== RUN TestValidateToken_BoundSubjectMismatch1957=== PAUSE TestValidateToken_BoundSubjectMismatch1958=== RUN TestValidateToken_MultipleProviders1959=== PAUSE TestValidateToken_MultipleProviders1960=== RUN TestValidateToken_NoMatchingProvider1961=== PAUSE TestValidateToken_NoMatchingProvider1962=== RUN TestValidateToken_KubernetesServiceAccount1963=== PAUSE TestValidateToken_KubernetesServiceAccount1964=== RUN TestNewValidator_KubernetesRequiresCA1965=== PAUSE TestNewValidator_KubernetesRequiresCA1966=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1967=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1968=== RUN TestPins_ReservedForMatchingRule1969=== PAUSE TestPins_ReservedForMatchingRule1970=== RUN TestPins_TopLevelShorthand1971=== PAUSE TestPins_TopLevelShorthand1972=== RUN TestPins_ConfigValidation1973=== PAUSE TestPins_ConfigValidation1974=== RUN TestScopes_LegacyProviderDefaultsToWrite1975=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1976=== RUN TestScopes_Rules1977=== PAUSE TestScopes_Rules1978=== RUN TestScopes_ConfigValidation1979=== PAUSE TestScopes_ConfigValidation1980=== CONT TestAudienceForIssuer1981=== CONT TestValidateToken_KubernetesServiceAccount1982=== CONT TestPins_ConfigValidation1983--- PASS: TestAudienceForIssuer (0.00s)1984=== CONT TestValidateToken_Expired1985=== CONT TestValidateToken_WrongAudience1986=== CONT TestValidateToken_ValidToken1987=== CONT TestGlobMatch1988=== RUN TestGlobMatch/foo_foo1989=== PAUSE TestGlobMatch/foo_foo1990=== RUN TestGlobMatch/foo_bar1991=== PAUSE TestGlobMatch/foo_bar1992=== RUN TestGlobMatch/*_1993=== CONT TestPins_ReservedForMatchingRule1994=== CONT TestPins_TopLevelShorthand1995=== CONT TestValidateToken_KubernetesIssuerFromOwnToken1996=== CONT TestValidateToken_MultipleProviders1997=== CONT TestValidateToken_NoMatchingProvider1998=== CONT TestValidateToken_BoundSubjectMismatch1999=== CONT TestScopes_Rules2000=== CONT TestScopes_ConfigValidation2001=== CONT TestScopes_LegacyProviderDefaultsToWrite2002=== CONT TestValidateToken_BoundClaimsMismatch2003=== CONT TestNewValidator_KubernetesRequiresCA2004=== PAUSE TestGlobMatch/*_2005=== RUN TestGlobMatch/*_anything2006=== PAUSE TestGlobMatch/*_anything2007=== RUN TestGlobMatch/foo*_foo2008=== PAUSE TestGlobMatch/foo*_foo2009=== RUN TestGlobMatch/foo*_foobar2010=== PAUSE TestGlobMatch/foo*_foobar2011=== RUN TestGlobMatch/foo*_bar2012=== PAUSE TestGlobMatch/foo*_bar2013=== RUN TestGlobMatch/*bar_bar2014=== PAUSE TestGlobMatch/*bar_bar2015=== RUN TestGlobMatch/*bar_foobar2016=== PAUSE TestGlobMatch/*bar_foobar2017=== RUN TestGlobMatch/*bar_foo2018=== PAUSE TestGlobMatch/*bar_foo2019=== RUN TestGlobMatch/foo*bar_foobar2020=== PAUSE TestGlobMatch/foo*bar_foobar2021=== RUN TestGlobMatch/foo*bar_foo123bar2022=== PAUSE TestGlobMatch/foo*bar_foo123bar2023=== RUN TestGlobMatch/foo*bar_foobarbaz2024--- PASS: TestPins_ConfigValidation (0.00s)2025=== PAUSE TestGlobMatch/foo*bar_foobarbaz2026=== RUN TestGlobMatch/*/*_foo/bar2027=== PAUSE TestGlobMatch/*/*_foo/bar2028=== RUN TestGlobMatch/*/*_foo2029=== PAUSE TestGlobMatch/*/*_foo2030=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2031=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2032=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02033=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02034=== RUN TestGlobMatch/refs/*/main_refs/heads/main2035=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2036=== RUN TestGlobMatch/fo?_foo2037=== PAUSE TestGlobMatch/fo?_foo2038=== RUN TestGlobMatch/fo?_fo2039=== PAUSE TestGlobMatch/fo?_fo2040=== RUN TestGlobMatch/fo?_fooo2041=== PAUSE TestGlobMatch/fo?_fooo2042=== RUN TestGlobMatch/?oo_foo2043=== PAUSE TestGlobMatch/?oo_foo2044=== RUN TestGlobMatch/?oo_boo2045=== PAUSE TestGlobMatch/?oo_boo2046=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2047=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2048=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2049=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2050=== CONT TestGlobMatch/foo_foo2051=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2052=== CONT TestGlobMatch/foo*bar_foo123bar2053=== CONT TestGlobMatch/foo*bar_foobar2054=== CONT TestGlobMatch/*bar_foo2055=== CONT TestGlobMatch/*bar_foobar2056=== CONT TestGlobMatch/*bar_bar2057=== CONT TestGlobMatch/foo*_bar2058=== CONT TestGlobMatch/foo*_foobar2059=== CONT TestGlobMatch/foo*_foo2060=== CONT TestGlobMatch/*_anything2061=== CONT TestGlobMatch/*_2062=== CONT TestGlobMatch/foo*bar_foobarbaz2063=== CONT TestGlobMatch/refs/*/main_refs/heads/main2064=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02065=== CONT TestGlobMatch/*/*_foo2066=== CONT TestGlobMatch/*/*_foo/bar2067=== CONT TestGlobMatch/foo_bar2068=== CONT TestGlobMatch/fo?_foo2069=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2070=== CONT TestGlobMatch/?oo_boo2071=== CONT TestGlobMatch/?oo_foo2072=== CONT TestGlobMatch/fo?_fooo2073=== CONT TestGlobMatch/fo?_fo2074=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2075--- PASS: TestScopes_ConfigValidation (0.00s)2076--- PASS: TestGlobMatch (0.00s)2077 --- PASS: TestGlobMatch/foo_foo (0.00s)2078 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2079 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2080 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2081 --- PASS: TestGlobMatch/*bar_foo (0.00s)2082 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2083 --- PASS: TestGlobMatch/*bar_bar (0.00s)2084 --- PASS: TestGlobMatch/foo*_bar (0.00s)2085 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2086 --- PASS: TestGlobMatch/foo*_foo (0.00s)2087 --- PASS: TestGlobMatch/*_anything (0.00s)2088 --- PASS: TestGlobMatch/*_ (0.00s)2089 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2090 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2091 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2092 --- PASS: TestGlobMatch/*/*_foo (0.00s)2093 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2094 --- PASS: TestGlobMatch/foo_bar (0.00s)2095 --- PASS: TestGlobMatch/fo?_foo (0.00s)2096 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2097 --- PASS: TestGlobMatch/?oo_boo (0.00s)2098 --- PASS: TestGlobMatch/?oo_foo (0.00s)2099 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2100 --- PASS: TestGlobMatch/fo?_fo (0.00s)2101 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)21022026/10/01 10:41:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34217/oidc2103--- PASS: TestScopes_Rules (0.04s)21042026/10/01 10:41:50 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4000921052026/10/01 10:41:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34063/oidc2106--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)2107--- PASS: TestValidateToken_ValidToken (0.09s)21082026/10/01 10:41:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45131/oidc21092026/10/01 10:41:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36323/oidc21102026/10/01 10:41:50 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46059/oidc2111--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.11s)2112--- PASS: TestValidateToken_MultipleProviders (0.12s)21132026/10/01 10:41:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37591/oidc2114--- PASS: TestValidateToken_Expired (0.14s)21152026/10/01 10:41:50 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321162026/10/01 10:41:50 http: TLS handshake error from 127.0.0.1:41358: remote error: tls: bad certificate2117--- PASS: TestNewValidator_KubernetesRequiresCA (0.14s)21182026/10/01 10:41:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44985/oidc21192026/10/01 10:41:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45521/oidc2120--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.15s)2121--- PASS: TestPins_TopLevelShorthand (0.15s)2122--- PASS: TestValidateToken_BoundClaimsMismatch (0.15s)21232026/10/01 10:41:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35979/oidc2124--- PASS: TestValidateToken_WrongAudience (0.16s)21252026/10/01 10:41:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42725/oidc2126--- PASS: TestPins_ReservedForMatchingRule (0.17s)21272026/10/01 10:41:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41719/oidc2128--- PASS: TestValidateToken_BoundSubjectMismatch (0.19s)21292026/10/01 10:41:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46537/oidc2130--- PASS: TestValidateToken_NoMatchingProvider (0.25s)2131PASS2132Running hook tests...2133=== RUN TestSendPathsEmpty2134=== PAUSE TestSendPathsEmpty2135=== RUN TestQueueEnqueueAndFetch2136=== PAUSE TestQueueEnqueueAndFetch2137=== RUN TestQueueDeduplication2138=== PAUSE TestQueueDeduplication2139=== RUN TestQueueRemove2140=== PAUSE TestQueueRemove2141=== RUN TestQueueFetchBatchLimit2142=== PAUSE TestQueueFetchBatchLimit2143=== RUN TestQueueRetryMovesToBack2144=== PAUSE TestQueueRetryMovesToBack2145=== RUN TestQueueFetchRemoveLifecycle2146=== PAUSE TestQueueFetchRemoveLifecycle2147=== RUN TestQueueConcurrentWriters2148=== PAUSE TestQueueConcurrentWriters2149=== RUN TestQueueRemoveLargeClosure2150=== PAUSE TestQueueRemoveLargeClosure2151=== RUN TestServerClientIntegration2152=== PAUSE TestServerClientIntegration2153=== RUN TestServerQueueError2154=== PAUSE TestServerQueueError2155=== RUN TestGetListenerSocketActivation2156 server_test.go:210: === RUN TestGetListenerSocketActivation2157 --- PASS: TestGetListenerSocketActivation (0.00s)2158 PASS2159 2160--- PASS: TestGetListenerSocketActivation (0.01s)2161=== RUN TestDrainIsolatesPoisonPath2162=== PAUSE TestDrainIsolatesPoisonPath2163=== RUN TestRunNotBlockedByPoisonHead2164=== PAUSE TestRunNotBlockedByPoisonHead2165=== RUN TestDrainGivesUpWhenServerDown2166=== PAUSE TestDrainGivesUpWhenServerDown2167=== RUN TestFailedPathPrunedByLaterClosure2168=== PAUSE TestFailedPathPrunedByLaterClosure2169=== RUN TestWorkerUploadsAndRemoves2170=== PAUSE TestWorkerUploadsAndRemoves2171=== RUN TestWorkerSkipsGCdPaths2172=== PAUSE TestWorkerSkipsGCdPaths2173=== RUN TestWorkerPrunesClosureDeps2174=== PAUSE TestWorkerPrunesClosureDeps2175=== RUN TestDrainTimeout2176=== PAUSE TestDrainTimeout2177=== CONT TestSendPathsEmpty2178=== CONT TestServerQueueError2179=== CONT TestQueueRemove2180--- PASS: TestSendPathsEmpty (0.00s)2181=== CONT TestQueueDeduplication2182=== CONT TestQueueEnqueueAndFetch2183=== CONT TestWorkerUploadsAndRemoves2184=== CONT TestDrainTimeout2185=== CONT TestWorkerPrunesClosureDeps2186=== CONT TestWorkerSkipsGCdPaths2187=== CONT TestQueueRemoveLargeClosure2188=== CONT TestServerClientIntegration21892026/10/01 10:41:51 ERROR Failed to queue paths error="permission denied" count=12190=== CONT TestDrainGivesUpWhenServerDown2191=== CONT TestFailedPathPrunedByLaterClosure2192=== CONT TestQueueConcurrentWriters2193=== CONT TestRunNotBlockedByPoisonHead2194=== CONT TestQueueFetchBatchLimit2195=== CONT TestDrainIsolatesPoisonPath2196=== CONT TestQueueFetchRemoveLifecycle2197=== CONT TestQueueRetryMovesToBack2198--- PASS: TestServerQueueError (0.00s)2199--- PASS: TestServerClientIntegration (0.00s)22002026/10/01 10:41:51 INFO Uploading batch count=222012026/10/01 10:41:51 INFO Upload queue status pending=222022026/10/01 10:41:51 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2091653725/002/nonexistent22032026/10/01 10:41:51 INFO Upload queue status pending=222042026/10/01 10:41:51 INFO Uploading batch count=122052026/10/01 10:41:51 ERROR Upload failed error="upload failed" count=122062026/10/01 10:41:51 INFO Uploading batch count=222072026/10/01 10:41:51 INFO Uploading batch count=422082026/10/01 10:41:51 ERROR Upload failed error="upload failed" count=422092026/10/01 10:41:51 INFO Uploading batch count=122102026/10/01 10:41:51 INFO Upload queue status pending=322112026/10/01 10:41:51 INFO Uploading batch count=12212--- PASS: TestQueueEnqueueAndFetch (0.01s)22132026/10/01 10:41:51 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath657671492/002/bbb22142026/10/01 10:41:51 INFO Uploading batch count=122152026/10/01 10:41:51 ERROR Upload failed error="upload failed" count=122162026/10/01 10:41:51 INFO Upload queue status pending=222172026/10/01 10:41:51 INFO Uploading batch count=22218--- PASS: TestQueueFetchBatchLimit (0.01s)22192026/10/01 10:41:51 ERROR Upload failed error="upload failed" count=222202026/10/01 10:41:51 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3875961990/002/a2221--- PASS: TestQueueRemove (0.01s)22222026/10/01 10:41:51 INFO Uploading batch count=122232026/10/01 10:41:51 INFO Uploading batch count=12224--- PASS: TestQueueDeduplication (0.01s)22252026/10/01 10:41:51 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3875961990/002/b2226--- PASS: TestQueueFetchRemoveLifecycle (0.01s)22272026/10/01 10:41:51 INFO Uploading batch count=222282026/10/01 10:41:51 ERROR Upload failed error="upload failed" count=222292026/10/01 10:41:51 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3875961990/002/c22302026/10/01 10:41:51 INFO Uploading batch count=12231--- PASS: TestQueueRetryMovesToBack (0.01s)22322026/10/01 10:41:51 ERROR Upload failed error="upload failed" count=122332026/10/01 10:41:51 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3875961990/002/d22342026/10/01 10:41:51 INFO Uploading batch count=122352026/10/01 10:41:51 ERROR Upload failed error="upload failed" count=122362026/10/01 10:41:51 INFO Uploading batch count=222372026/10/01 10:41:51 ERROR Upload failed error="upload failed" count=222382026/10/01 10:41:51 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3875961990/002/e2239--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22402026/10/01 10:41:51 INFO Uploading batch count=122412026/10/01 10:41:51 ERROR Upload failed error="upload failed" count=122422026/10/01 10:41:51 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3875961990/002/f22432026/10/01 10:41:51 ERROR Drain finished with paths left in queue remaining=122442026/10/01 10:41:51 ERROR Drain finished with paths left in queue remaining=102245--- PASS: TestDrainIsolatesPoisonPath (0.02s)2246--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2247--- PASS: TestWorkerSkipsGCdPaths (0.03s)2248--- PASS: TestWorkerPrunesClosureDeps (0.03s)2249--- PASS: TestWorkerUploadsAndRemoves (0.03s)2250--- PASS: TestQueueRemoveLargeClosure (0.15s)2251--- PASS: TestQueueConcurrentWriters (0.16s)22522026/10/01 10:41:51 ERROR Upload failed error="context deadline exceeded" count=222532026/10/01 10:41:51 ERROR Drain finished with paths left in queue remaining=42254--- PASS: TestDrainTimeout (0.21s)22552026/10/01 10:41:52 INFO Uploading batch count=122562026/10/01 10:41:52 INFO Uploading batch count=122572026/10/01 10:41:52 INFO Uploading batch count=122582026/10/01 10:41:52 ERROR Upload failed error="upload failed" count=122592026/10/01 10:41:52 INFO Uploading batch count=122602026/10/01 10:41:52 ERROR Upload failed error="upload failed" count=122612026/10/01 10:41:52 INFO Uploading batch count=122622026/10/01 10:41:52 ERROR Upload failed error="upload failed" count=122632026/10/01 10:41:52 INFO Uploading batch count=122642026/10/01 10:41:52 ERROR Upload failed error="upload failed" count=122652026/10/01 10:41:52 ERROR Drain finished with paths left in queue remaining=12266--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2267PASS