niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #346
· raw
1tribuchet: building on jamie2Running 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.04s)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 TestParsePathInfoJSONMultiplePaths97=== CONT TestSetClientTLS98=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths99=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths100=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths101=== CONT TestScriptTokenEmptyCommand102--- PASS: TestScriptTokenEmptyCommand (0.00s)103=== CONT TestScriptTokenScriptFails104=== CONT TestScriptTokenBadJSON105=== CONT TestScriptTokenEmptyToken106=== CONT TestScriptTokenCachesUntilRefresh107=== CONT TestScriptTokenNoExpiryRerunsEveryCall108=== CONT TestFileTokenEmpty109=== CONT TestFileTokenMissing110=== CONT TestFileTokenReadsAndCaches111=== CONT TestStaticToken112=== CONT TestSetClientTLSErrors113=== CONT TestSetClientTLSDoesNotMutateDefaultTransport114=== CONT TestDumpPathSingleFile115=== CONT TestParsePathInfoJSON116=== RUN TestParsePathInfoJSON/Nix_format117=== PAUSE TestParsePathInfoJSON/Nix_format118=== CONT TestPathInfoHashCompatibility119=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)120=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)121--- PASS: TestScriptTokenScriptFails (0.00s)122=== CONT TestGetStorePathHash123=== RUN TestGetStorePathHash/valid_store_path124=== PAUSE TestGetStorePathHash/valid_store_path125=== CONT TestStreamPushReportsEveryPath126--- PASS: TestStaticToken (0.00s)127=== CONT TestConvertHashToNix32128=== CONT TestClientSignaturesByStorePath129=== CONT TestEncodeNixBase32WithRealHash130=== CONT TestStreamPushReportsSignatures131=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths132=== CONT TestEncodeNixBase32133=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon134=== CONT TestStreamPushRequestLine135--- PASS: TestFileTokenEmpty (0.00s)136--- PASS: TestClientSignaturesByStorePath (0.00s)137=== RUN TestGetStorePathHash/basename_without_hyphen_should_error138=== CONT TestResolveStorePath139=== RUN TestConvertHashToNix32/SRI_format_to_Nix32140=== CONT TestShellSplitErrors141=== CONT TestStreamPushGivesUpOnDeadServer142=== RUN TestEncodeNixBase32/test_string_hash143=== CONT TestDumpPathWriterError144=== CONT TestShellSplit145=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32146=== RUN TestConvertHashToNix32/already_Nix32_format147=== RUN TestSetClientTLSErrors/missing_cert_file148=== PAUSE TestSetClientTLSErrors/missing_cert_file149=== PAUSE TestEncodeNixBase32/test_string_hash150=== CONT TestRateLimiterFeedback151=== CONT TestPathInfoCACompatibility152=== RUN TestRateLimiterFeedback/429_enables_limiter153=== RUN TestPathInfoCACompatibility/null_ca_field154=== PAUSE TestRateLimiterFeedback/429_enables_limiter155=== PAUSE TestConvertHashToNix32/already_Nix32_format1562026/10/01 13:01:12 ERROR Upload failed error="connection refused" count=20157=== CONT TestStreamPushBatchesUnderLoad1582026/10/01 13:01:12 ERROR Server seems unavailable, giving up on batch untried=171592026/10/01 13:01:12 ERROR Upload failed error=boom count=11602026/10/01 13:01:12 ERROR Upload failed error=boom count=1161=== RUN TestParsePathInfoJSON/Lix_format162=== PAUSE TestParsePathInfoJSON/Lix_format163=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error164=== CONT TestDoWithRetry_BodyReplayedViaGetBody165=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon166=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess167=== RUN TestSetClientTLSErrors/missing_key_file168=== PAUSE TestPathInfoCACompatibility/null_ca_field169=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI170=== CONT TestUploadMultipart_PartsInParallel171=== RUN TestRateLimiterFeedback/503_enables_limiter172=== PAUSE TestRateLimiterFeedback/503_enables_limiter173=== RUN TestConvertHashToNix32/invalid_format174=== PAUSE TestConvertHashToNix32/invalid_format175=== CONT TestFilterOversizedClosures176=== RUN TestFilterOversizedClosures/no_limit_keeps_everything177=== CONT TestUploadMultipart_SupersededByPeer178=== RUN TestEncodeNixBase32/empty_input179=== CONT TestPartSizeForNAR180=== CONT TestDumpPathMatchesNix181=== CONT TestCaseHackSuffix182=== RUN TestParsePathInfoJSON/empty_input1832026/10/01 13:01:12 WARN Rate limiter enabled after throttle name=server-test rate=5184=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error185=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error186=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error187=== CONT TestRegisterUploadedObjectReusesConnections188=== RUN TestPathInfoCACompatibility/old_string_format_-_text189=== PAUSE TestSetClientTLSErrors/missing_key_file190=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1912026/10/01 13:01:12 WARN Rate limiter enabled after throttle name=server-test rate=5192--- PASS: TestEncodeNixBase32WithRealHash (0.00s)193=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter194=== CONT TestStreamPushIsolatesFailures195=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything1962026/10/01 13:01:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33447197=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5121982026/10/01 13:01:12 ERROR Upload failed error="bad path" count=3199=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512200=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped201=== CONT TestConvertHashToNix32/SRI_format_to_Nix32202=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped203=== RUN TestFilterOversizedClosures/all_closures_skipped204=== PAUSE TestFilterOversizedClosures/all_closures_skipped205=== PAUSE TestEncodeNixBase32/empty_input206=== CONT TestConvertHashToNix32/invalid_format2072026/10/01 13:01:12 WARN Rate limiter backed off name=server-test rate=5208=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122092026/10/01 13:01:12 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33447210=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths211=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI212=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon213=== CONT TestEncodeNixBase32/test_string_hash214=== CONT TestFilterOversizedClosures/all_closures_skipped215=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped216=== RUN TestPartSizeForNAR/zero_stays_at_minimum2172026/10/01 13:01:12 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=50218=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum2192026/10/01 13:01:12 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=2000220=== RUN TestPartSizeForNAR/small_stays_at_minimum221=== PAUSE TestPartSizeForNAR/small_stays_at_minimum222=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum223=== CONT TestEncodeNixBase32/empty_input224=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths225=== CONT TestFilterOversizedClosures/no_limit_keeps_everything226=== PAUSE TestParsePathInfoJSON/empty_input227=== RUN TestParsePathInfoJSON/whitespace_only228=== PAUSE TestParsePathInfoJSON/whitespace_only229=== RUN TestParsePathInfoJSON/invalid_JSON230=== PAUSE TestParsePathInfoJSON/invalid_JSON231=== CONT TestParsePathInfoJSON/Nix_format232=== RUN TestSetClientTLS/rejects_connection_without_client_cert233=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert234=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA235=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA236=== RUN TestSetClientTLS/preserves_debug_logging_transport237=== PAUSE TestSetClientTLS/preserves_debug_logging_transport238=== CONT TestSetClientTLS/rejects_connection_without_client_cert239=== CONT TestParsePathInfoJSON/Lix_format240=== CONT TestParsePathInfoJSON/invalid_JSON241=== CONT TestParsePathInfoJSON/whitespace_only242=== CONT TestParsePathInfoJSON/empty_input243=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error244=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text245=== RUN TestSetClientTLSErrors/missing_ca_file246--- PASS: TestFileTokenMissing (0.00s)247=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter248=== RUN TestUploadMultipart_SupersededByPeer/exists249=== CONT TestConvertHashToNix32/already_Nix32_format250=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)251=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum252=== CONT TestSetClientTLS/preserves_debug_logging_transport253=== PAUSE TestUploadMultipart_SupersededByPeer/exists254=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts255=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts256=== RUN TestPartSizeForNAR/1_TiB257=== PAUSE TestPartSizeForNAR/1_TiB258=== RUN TestPartSizeForNAR/5_TiB_S3_max_object259=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object260=== RUN TestPartSizeForNAR/capped_at_5_GiB261=== PAUSE TestPartSizeForNAR/capped_at_5_GiB262=== CONT TestPartSizeForNAR/zero_stays_at_minimum263--- PASS: TestFileTokenReadsAndCaches (0.00s)264=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts265=== CONT TestPartSizeForNAR/small_stays_at_minimum266=== CONT TestPartSizeForNAR/1_TiB267=== RUN TestUploadMultipart_SupersededByPeer/missing268=== PAUSE TestUploadMultipart_SupersededByPeer/missing269=== CONT TestUploadMultipart_SupersededByPeer/exists270=== PAUSE TestSetClientTLSErrors/missing_ca_file271=== CONT TestGetStorePathHash/valid_store_path272=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error273=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error274=== CONT TestGetStorePathHash/basename_without_hyphen_should_error275=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive276=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive277=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter278=== CONT TestPartSizeForNAR/capped_at_5_GiB279=== CONT TestPartSizeForNAR/5_TiB_S3_max_object280=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA281=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum282--- PASS: TestShellSplitErrors (0.00s)283=== CONT TestUploadMultipart_SupersededByPeer/missing284=== RUN TestSetClientTLSErrors/invalid_ca_file285=== PAUSE TestSetClientTLSErrors/invalid_ca_file286=== CONT TestSetClientTLSErrors/missing_cert_file287=== CONT TestSetClientTLSErrors/invalid_ca_file288=== CONT TestSetClientTLSErrors/missing_ca_file289=== CONT TestSetClientTLSErrors/missing_key_file290=== RUN TestPathInfoCACompatibility/new_structured_format_-_text291--- PASS: TestShellSplit (0.00s)292--- PASS: TestScriptTokenBadJSON (0.01s)293=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text294=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method295=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method296=== CONT TestPathInfoCACompatibility/null_ca_field297=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive298=== CONT TestPathInfoCACompatibility/new_structured_format_-_text299=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter300=== CONT TestRateLimiterFeedback/429_enables_limiter301=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter302=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter303=== CONT TestRateLimiterFeedback/503_enables_limiter304--- PASS: TestStreamPushReportsEveryPath (0.00s)305--- PASS: TestScriptTokenEmptyToken (0.01s)306--- PASS: TestStreamPushReportsSignatures (0.00s)307--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)308--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)309--- PASS: TestResolveStorePath (0.00s)310--- PASS: TestDoServerRequestAttachesToken (0.01s)311=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method312=== CONT TestPathInfoCACompatibility/old_string_format_-_text313--- PASS: TestStreamPushIsolatesFailures (0.00s)314--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)315--- PASS: TestDumpPathSingleFile (0.04s)316--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)317--- PASS: TestEncodeNixBase32 (0.03s)318 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)319 --- PASS: TestEncodeNixBase32/empty_input (0.00s)3202026/10/01 13:01:12 WARN Rate limiter enabled after throttle name=server-test rate=5321--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)3222026/10/01 13:01:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:37927323--- PASS: TestFilterOversizedClosures (0.03s)324 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)325 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)326 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)3272026/10/01 13:01:12 WARN Rate limiter enabled after throttle name=server-test rate=5328--- PASS: TestGetStorePathHash (0.04s)329 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)330 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)331 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)332 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)3332026/10/01 13:01:12 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:41943334--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)335 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)336 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)3372026/10/01 13:01:12 WARN Rate limiter backed off name=server-test rate=5338--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)339 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)340 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)3412026/10/01 13:01:12 WARN Rate limiter backed off name=server-test rate=5342--- PASS: TestConvertHashToNix32 (0.00s)343 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)344 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)345 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)346--- PASS: TestParsePathInfoJSON (0.04s)347 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)348 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)349 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)350 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)351 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)352--- PASS: TestPathInfoHashCompatibility (0.04s)353 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)354 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)355 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)356 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)357--- PASS: TestPartSizeForNAR (0.00s)358 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)359 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)360 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)361 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)362 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)363 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)364 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)365--- PASS: TestPathInfoCACompatibility (0.03s)366 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)367 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)368 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)369 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)370 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)371--- PASS: TestSetClientTLSErrors (0.04s)372 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)373 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)374 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)375 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)376--- PASS: TestRateLimiterFeedback (0.03s)377 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)379 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)380 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)3812026/10/01 13:01:12 http: TLS handshake error from 127.0.0.1:36958: remote error: tls: bad certificate382--- PASS: TestStreamPushRequestLine (0.05s)383--- PASS: TestSetClientTLS (0.04s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)388--- PASS: TestDumpPathWriterError (0.06s)389--- PASS: TestCaseHackSuffix (0.03s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.08s)392--- PASS: TestUploadMultipart_PartsInParallel (0.64s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.03s)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/postgres897127102/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/postgres897127102/data -l logfile start422423/build/postgres897127102:5432 - no response4242026-10-01 13:01:13.879 UTC [130] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 13:01:13.880 UTC [130] LOG: listening on Unix socket "/build/postgres897127102/.s.PGSQL.5432"4262026-10-01 13:01:13.888 UTC [137] LOG: database system was shut down at 2026-10-01 13:01:13 UTC4272026-10-01 13:01:13.892 UTC [130] LOG: database system is ready to accept connections428/build/postgres897127102:5432 - accepting connections429{"timestamp":"2026-10-01T13:01:14.188743656Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"be60db1b-ee2e-46ad-87d5-e84fecc29744","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(395)"}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 13:01:14 INFO lead: acquired remote=192.0.2.1:12344762026/10/01 13:01:15 INFO lead: released remote=192.0.2.1:12344772026/10/01 13:01:15 INFO lead: acquired remote=192.0.2.1:12344782026/10/01 13:01:16 INFO lead: released remote=192.0.2.1:1234479--- PASS: TestLeadIncumbentWinsAfterRestart (2.34s)480=== RUN TestLeadEndsOnShutdown481=== PAUSE TestLeadEndsOnShutdown482=== RUN TestLeadEndsWhenItsConnectionHangs4832026/10/01 13:01:16 INFO lead: acquired remote=192.0.2.1:12344842026-10-01 13:01:18.160 UTC [578] FATAL: terminating connection due to administrator command4852026/10/01 13:01:18 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 13:01:19 WARN lead: lock connection lost error="timeout: context deadline exceeded"4872026/10/01 13:01:19 INFO lead: released remote=192.0.2.1:12344882026/10/01 13:01:19 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadEndsWhenItsConnectionHangs (3.12s)490=== RUN TestGCAdvisoryLockBlocksConcurrentRun491=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun492=== RUN TestGCBugBareHashReferences493=== PAUSE TestGCBugBareHashReferences494=== RUN TestGCMetrics495=== PAUSE TestGCMetrics496=== RUN TestPushDedupSurvivesConcurrentGC497=== PAUSE TestPushDedupSurvivesConcurrentGC498=== RUN TestDeduplicatedObjectsRecordedAsPending499=== PAUSE TestDeduplicatedObjectsRecordedAsPending500=== RUN TestGCSweepSkipsPendingObjects501=== PAUSE TestGCSweepSkipsPendingObjects502=== RUN TestTombstonedObjectOfferedWithoutWaiting503=== PAUSE TestTombstonedObjectOfferedWithoutWaiting504=== RUN TestGCSweepDeliversEachKeyOnce505=== PAUSE TestGCSweepDeliversEachKeyOnce506=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection507=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection508=== RUN TestForceGCDuringPushOffersSweptObject509=== PAUSE TestForceGCDuringPushOffersSweptObject510=== RUN TestFailedS3DeleteKeepsTombstone511=== PAUSE TestFailedS3DeleteKeepsTombstone512=== RUN TestSweepSkipsRowsLockedByPush513=== PAUSE TestSweepSkipsRowsLockedByPush514=== RUN TestRegisterCompletedObjectNeedsPendingRow515=== PAUSE TestRegisterCompletedObjectNeedsPendingRow516=== RUN TestGetExistingObjectsLocksRows517=== PAUSE TestGetExistingObjectsLocksRows518=== RUN TestSweepRechecksPendingAfterLocking519=== PAUSE TestSweepRechecksPendingAfterLocking520=== RUN TestPushWaitsForSweepHoldingRow521=== PAUSE TestPushWaitsForSweepHoldingRow522=== RUN TestCommitRacingPendingCleanupKeepsObjects523=== PAUSE TestCommitRacingPendingCleanupKeepsObjects524=== RUN TestGCEndsOnShutdown525=== PAUSE TestGCEndsOnShutdown526=== RUN TestGCTaskStore_StartNew527=== PAUSE TestGCTaskStore_StartNew528=== RUN TestGCTaskStore_DeduplicateSameParams529=== PAUSE TestGCTaskStore_DeduplicateSameParams530=== RUN TestGCTaskStore_ConflictDifferentParams531=== PAUSE TestGCTaskStore_ConflictDifferentParams532=== RUN TestGCTaskStore_GetEmpty533=== PAUSE TestGCTaskStore_GetEmpty534=== RUN TestGCTaskStore_GetReturnsLatest535=== PAUSE TestGCTaskStore_GetReturnsLatest536=== RUN TestGCTaskStore_CompletedAllowsNewTask537=== PAUSE TestGCTaskStore_CompletedAllowsNewTask538=== RUN TestGCTaskStore_PhaseUpdates539=== PAUSE TestGCTaskStore_PhaseUpdates540=== RUN TestGCTaskStore_Fail541=== PAUSE TestGCTaskStore_Fail542=== RUN TestGracefulShutdownDrainsInflight543=== PAUSE TestGracefulShutdownDrainsInflight544=== RUN TestService_healthCheckHandler545=== PAUSE TestService_healthCheckHandler546=== RUN TestService_readinessHandler547=== PAUSE TestService_readinessHandler548=== RUN TestGenerateLandingPage549=== PAUSE TestGenerateLandingPage550=== RUN TestCacheConfigHandlerMaxNarSize551=== PAUSE TestCacheConfigHandlerMaxNarSize552=== RUN TestCreatePendingClosureRejectsOversizedNAR553=== PAUSE TestCreatePendingClosureRejectsOversizedNAR554=== RUN TestNARDeduplicationMetadataUploadBug555=== PAUSE TestNARDeduplicationMetadataUploadBug556=== RUN TestMetricsInventory557=== PAUSE TestMetricsInventory558=== RUN TestService_NativeMTLS559=== PAUSE TestService_NativeMTLS560=== RUN TestServerTLSConfig561=== PAUSE TestServerTLSConfig562=== RUN TestMultipartCleanup563=== PAUSE TestMultipartCleanup564=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded565=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded566=== RUN TestPendingCleanupUsesOneCutoff567=== PAUSE TestPendingCleanupUsesOneCutoff568=== RUN TestObjectStatsTrigger569=== PAUSE TestObjectStatsTrigger570=== RUN TestOrphanedObjectsGC571=== PAUSE TestOrphanedObjectsGC572=== RUN TestOrphanedObjectsGCStressTest573=== PAUSE TestOrphanedObjectsGCStressTest574=== RUN TestCreatePin_ReservedPins575=== PAUSE TestCreatePin_ReservedPins576=== RUN TestPresentReportsOnlyClosureRoots577=== PAUSE TestPresentReportsOnlyClosureRoots578=== RUN TestPresentNotReportedWhileGCDeletesClosure579=== PAUSE TestPresentNotReportedWhileGCDeletesClosure580=== RUN TestParseSingleRange581=== PAUSE TestParseSingleRange582=== RUN TestProxyHeadersOnlyTrustedOnSocket583=== PAUSE TestProxyHeadersOnlyTrustedOnSocket584=== RUN TestIsValidCachePath585=== PAUSE TestIsValidCachePath586=== RUN TestReadProxyNarinfo587=== PAUSE TestReadProxyNarinfo588=== RUN TestReadProxyNarinfoAlreadyDecompressed589=== PAUSE TestReadProxyNarinfoAlreadyDecompressed590=== RUN TestReadProxyNarStreaming591=== PAUSE TestReadProxyNarStreaming592=== RUN TestReadProxy404593=== PAUSE TestReadProxy404594=== RUN TestReadProxyInvalidPath595=== PAUSE TestReadProxyInvalidPath596=== RUN TestReadProxyHead597=== PAUSE TestReadProxyHead598=== RUN TestReadProxyOutlastsServerWriteTimeout599=== PAUSE TestReadProxyOutlastsServerWriteTimeout600=== RUN TestReadProxyConditionalGet601=== PAUSE TestReadProxyConditionalGet602=== RUN TestReadProxyRootRedirectsToIndexHTML603=== PAUSE TestReadProxyRootRedirectsToIndexHTML604=== RUN TestReadProxyDisabled605=== PAUSE TestReadProxyDisabled606=== RUN TestReadRedirectNar607=== PAUSE TestReadRedirectNar608=== RUN TestReadRedirectKeepsNarinfoProxied609=== PAUSE TestReadRedirectKeepsNarinfoProxied610=== RUN TestReadProxyRangeRequest611=== PAUSE TestReadProxyRangeRequest612=== RUN TestReadRedirectUsesPublicS3URL613=== PAUSE TestReadRedirectUsesPublicS3URL614=== RUN TestPush_OverlappingRootsStoreOneRowPerKey615=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey616=== RUN TestPush_CompleteCommitsEveryRoot617=== PAUSE TestPush_CompleteCommitsEveryRoot618=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit619=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit620=== RUN TestPush_RejectsBadRequests621=== PAUSE TestPush_RejectsBadRequests622=== RUN TestPush_SignsNarinfosOfItsPendingObjects623=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects624=== RUN TestRedundantMultipartUpload625=== PAUSE TestRedundantMultipartUpload626=== RUN TestCompleteMultipartUpload_ErrorButObjectExists627=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists628=== RUN TestCompletedNarNotReofferedAcrossClosures629=== PAUSE TestCompletedNarNotReofferedAcrossClosures630=== RUN TestPresignedUploadRegisteredBeforeCommit631=== PAUSE TestPresignedUploadRegisteredBeforeCommit632=== RUN TestService_Rustfstest633=== PAUSE TestService_Rustfstest634=== RUN TestParseSize635=== PAUSE TestParseSize636=== RUN TestSkippedUploadsHandler637=== PAUSE TestSkippedUploadsHandler638=== RUN TestSystemdListenerNotActivated639--- PASS: TestSystemdListenerNotActivated (0.00s)640=== RUN TestWatchdogBeatsWhenHealthy641--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)642=== RUN TestWatchdogSkipsWhenUnhealthy6432026/10/01 13:01:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 13:01:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/01 13:01:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/01 13:01:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 13:01:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 13:01:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 13:01:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 13:01:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/01 13:01:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/01 13:01:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"653--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)654=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle655=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle656=== RUN TestProxyWriteTimeout657=== PAUSE TestProxyWriteTimeout658=== RUN TestPendingClosureWriteTimeout659=== PAUSE TestPendingClosureWriteTimeout660=== RUN TestIsValidUploadKey661=== PAUSE TestIsValidUploadKey662=== RUN TestUploadHandlersRejectInvalidKeys663=== PAUSE TestUploadHandlersRejectInvalidKeys664=== RUN TestUploadHandlersRejectOversizedBody665=== PAUSE TestUploadHandlersRejectOversizedBody666=== RUN TestService_cleanupPendingClosuresHandler667=== PAUSE TestService_cleanupPendingClosuresHandler668=== RUN TestService_createPendingClosureHandler669=== PAUSE TestService_createPendingClosureHandler670=== RUN TestService_verifyS3Integrity671=== PAUSE TestService_verifyS3Integrity672=== RUN TestCompleteMultipartUnregistered673=== PAUSE TestCompleteMultipartUnregistered674=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT675=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT676=== CONT TestService_AuthMiddleware677=== CONT TestService_createPendingClosureHandler678=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit679=== CONT TestRegisterCompletedObjectNeedsPendingRow680=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT681=== CONT TestCompleteMultipartUnregistered682=== CONT TestService_verifyS3Integrity683=== CONT TestProxyHeadersOnlyTrustedOnSocket684=== CONT TestParseSingleRange685=== CONT TestPresentNotReportedWhileGCDeletesClosure686=== CONT TestPresentReportsOnlyClosureRoots687=== CONT TestCreatePin_ReservedPins688=== CONT TestOrphanedObjectsGCStressTest689=== CONT TestOrphanedObjectsGC690=== CONT TestObjectStatsTrigger691=== CONT TestPendingCleanupUsesOneCutoff692=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded693=== CONT TestMultipartCleanup694=== CONT TestServerTLSConfig695=== RUN TestServerTLSConfig/no_client_CA696=== PAUSE TestServerTLSConfig/no_client_CA697=== RUN TestServerTLSConfig/missing_CA_file698=== PAUSE TestServerTLSConfig/missing_CA_file699=== RUN TestServerTLSConfig/not_a_PEM_file700=== PAUSE TestServerTLSConfig/not_a_PEM_file701=== CONT TestCacheConfigHandlerMaxNarSize702=== CONT TestService_NativeMTLS703--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)704=== CONT TestGenerateLandingPage705=== CONT TestMetricsInventory706=== CONT TestNARDeduplicationMetadataUploadBug707=== CONT TestCreatePendingClosureRejectsOversizedNAR708=== CONT TestIsValidCachePath709=== RUN TestParseSingleRange/none7102026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures711=== RUN TestIsValidCachePath/narinfo712--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)713=== CONT TestService_readinessHandler714=== PAUSE TestParseSingleRange/none715=== PAUSE TestIsValidCachePath/narinfo716=== RUN TestParseSingleRange/unknown_unit717=== PAUSE TestParseSingleRange/unknown_unit718=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars719=== RUN TestParseSingleRange/multi-range_ignored720=== PAUSE TestParseSingleRange/multi-range_ignored721=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars722=== RUN TestIsValidCachePath/nar_zst723=== PAUSE TestIsValidCachePath/nar_zst724=== RUN TestIsValidCachePath/nar_xz725=== PAUSE TestIsValidCachePath/nar_xz726=== RUN TestIsValidCachePath/nar_bz2727=== CONT TestService_healthCheckHandler728=== RUN TestParseSingleRange/malformed_no_dash729=== PAUSE TestParseSingleRange/malformed_no_dash730=== RUN TestParseSingleRange/malformed_both_empty731--- PASS: TestGenerateLandingPage (0.00s)732=== PAUSE TestIsValidCachePath/nar_bz2733=== PAUSE TestParseSingleRange/malformed_both_empty734=== RUN TestIsValidCachePath/nar_uncompressed735=== PAUSE TestIsValidCachePath/nar_uncompressed736=== RUN TestParseSingleRange/malformed_end_before_start737=== PAUSE TestParseSingleRange/malformed_end_before_start738=== RUN TestParseSingleRange/closed739=== PAUSE TestParseSingleRange/closed740=== RUN TestParseSingleRange/open-ended741=== PAUSE TestParseSingleRange/open-ended742=== RUN TestIsValidCachePath/ls743=== PAUSE TestIsValidCachePath/ls744=== RUN TestParseSingleRange/end_clamped_to_size745=== RUN TestIsValidCachePath/log746=== PAUSE TestIsValidCachePath/log747=== RUN TestIsValidCachePath/realisation748=== PAUSE TestParseSingleRange/end_clamped_to_size749=== RUN TestParseSingleRange/suffix750=== PAUSE TestParseSingleRange/suffix751=== RUN TestParseSingleRange/suffix_exceeds_size752=== PAUSE TestParseSingleRange/suffix_exceeds_size753=== RUN TestParseSingleRange/single_byte754=== PAUSE TestParseSingleRange/single_byte755=== RUN TestParseSingleRange/start_past_EOF756=== PAUSE TestParseSingleRange/start_past_EOF757=== RUN TestParseSingleRange/start_far_past_EOF758=== PAUSE TestParseSingleRange/start_far_past_EOF759=== PAUSE TestIsValidCachePath/realisation760=== RUN TestIsValidCachePath/nix-cache-info761=== PAUSE TestIsValidCachePath/nix-cache-info762=== RUN TestIsValidCachePath/index.html763=== PAUSE TestIsValidCachePath/index.html764=== CONT TestGracefulShutdownDrainsInflight765=== RUN TestIsValidCachePath/traversal_parent766=== PAUSE TestIsValidCachePath/traversal_parent767=== RUN TestIsValidCachePath/traversal_in_middle768=== PAUSE TestIsValidCachePath/traversal_in_middle769=== RUN TestIsValidCachePath/invalid_char_e770=== PAUSE TestIsValidCachePath/invalid_char_e771=== RUN TestIsValidCachePath/invalid_char_u772=== PAUSE TestIsValidCachePath/invalid_char_u773=== RUN TestIsValidCachePath/random_path774=== PAUSE TestIsValidCachePath/random_path775=== RUN TestIsValidCachePath/empty776=== PAUSE TestIsValidCachePath/empty777=== RUN TestIsValidCachePath/leading_slash778=== PAUSE TestIsValidCachePath/leading_slash779=== RUN TestIsValidCachePath/wrong_extension780=== PAUSE TestIsValidCachePath/wrong_extension781=== RUN TestIsValidCachePath/short_hash782=== PAUSE TestIsValidCachePath/short_hash7832026/10/01 13:01:20 INFO Starting HTTP server address=127.0.0.1:43085784=== CONT TestGCTaskStore_Fail785--- PASS: TestGCTaskStore_Fail (0.00s)786=== CONT TestGCTaskStore_PhaseUpdates787--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)788=== CONT TestGCTaskStore_CompletedAllowsNewTask789--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)790=== CONT TestGCTaskStore_GetReturnsLatest791--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)792=== CONT TestGCTaskStore_GetEmpty793--- PASS: TestGCTaskStore_GetEmpty (0.00s)794=== CONT TestGCTaskStore_ConflictDifferentParams795--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)796=== CONT TestGCTaskStore_DeduplicateSameParams797--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)798=== CONT TestGCTaskStore_StartNew799--- PASS: TestGCTaskStore_StartNew (0.00s)8002026/10/01 13:01:20 INFO Shutdown signal received, draining in-flight requests timeout=10s801=== CONT TestGCEndsOnShutdown8022026/10/01 13:01:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44405/oidc803--- PASS: TestGracefulShutdownDrainsInflight (0.07s)804=== CONT TestCommitRacingPendingCleanupKeepsObjects8052026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures8062026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures8072026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures8082026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures809--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.38s)810=== CONT TestPushWaitsForSweepHoldingRow8112026/10/01 13:01:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8122026/10/01 13:01:20 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst813--- PASS: TestCompleteMultipartUnregistered (0.44s)814=== CONT TestSweepRechecksPendingAfterLocking8152026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures8162026/10/01 13:01:20 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"817--- PASS: TestService_AuthMiddleware (0.48s)818=== CONT TestGetExistingObjectsLocksRows819--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.49s)820=== CONT TestSkippedUploadsHandler8212026/10/01 13:01:20 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000822--- PASS: TestSkippedUploadsHandler (0.01s)823=== CONT TestService_cleanupPendingClosuresHandler8242026/10/01 13:01:20 INFO Received push request method=POST path=/api/pushes8252026/10/01 13:01:20 INFO Received complete push request method=POST path=/api/pushes/1/complete8262026/10/01 13:01:20 INFO Starting HTTP server address=127.0.0.1:329478272026/10/01 13:01:20 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket341091957/001/proxy.sock8282026/10/01 13:01:20 INFO Received push request method=POST path=/api/pushes8292026/10/01 13:01:20 WARN mTLS auth: subject not in bound subjects subject="CN=someone"8302026/10/01 13:01:20 INFO Shutdown signal received, draining in-flight requests timeout=10s831--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.55s)832=== CONT TestUploadHandlersRejectOversizedBody8332026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures834--- PASS: TestService_healthCheckHandler (0.65s)835=== CONT TestUploadHandlersRejectInvalidKeys836=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info837=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info838=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal839=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal840=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key841=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key842=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key843=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key844=== CONT TestIsValidUploadKey845=== RUN TestIsValidUploadKey/narinfo846=== PAUSE TestIsValidUploadKey/narinfo847=== RUN TestIsValidUploadKey/nar_zst848=== PAUSE TestIsValidUploadKey/nar_zst849=== RUN TestIsValidUploadKey/nar_xz850=== PAUSE TestIsValidUploadKey/nar_xz851=== RUN TestIsValidUploadKey/nar_plain852=== PAUSE TestIsValidUploadKey/nar_plain853=== RUN TestIsValidUploadKey/listing854=== PAUSE TestIsValidUploadKey/listing855=== RUN TestIsValidUploadKey/build_log856=== PAUSE TestIsValidUploadKey/build_log857=== RUN TestIsValidUploadKey/build_log_home-manager_file858=== PAUSE TestIsValidUploadKey/build_log_home-manager_file859=== RUN TestIsValidUploadKey/build_log_plus_in_name860=== PAUSE TestIsValidUploadKey/build_log_plus_in_name861=== RUN TestIsValidUploadKey/build_log_question_mark862=== PAUSE TestIsValidUploadKey/build_log_question_mark863=== RUN TestIsValidUploadKey/build_log_equals864=== PAUSE TestIsValidUploadKey/build_log_equals865=== RUN TestIsValidUploadKey/realisation866=== PAUSE TestIsValidUploadKey/realisation8672026/10/01 13:01:20 INFO Aborted multipart uploads count=0 kept=0868=== RUN TestIsValidUploadKey/realisation_plus_in_output869=== PAUSE TestIsValidUploadKey/realisation_plus_in_output870=== RUN TestIsValidUploadKey/nix-cache-info871=== PAUSE TestIsValidUploadKey/nix-cache-info872=== RUN TestIsValidUploadKey/index.html873=== PAUSE TestIsValidUploadKey/index.html874=== RUN TestIsValidUploadKey/narinfo_key,_nar_type8752026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures876=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type877=== RUN TestIsValidUploadKey/nar_key,_narinfo_type878=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type879=== RUN TestIsValidUploadKey/listing_key,_narinfo_type880=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type881=== RUN TestIsValidUploadKey/traversal882=== PAUSE TestIsValidUploadKey/traversal883=== RUN TestIsValidUploadKey/traversal_nar884=== PAUSE TestIsValidUploadKey/traversal_nar885=== RUN TestIsValidUploadKey/absolute886=== PAUSE TestIsValidUploadKey/absolute887=== RUN TestIsValidUploadKey/empty_key888=== PAUSE TestIsValidUploadKey/empty_key889=== RUN TestIsValidUploadKey/unknown_type890=== PAUSE TestIsValidUploadKey/unknown_type891=== CONT TestPendingClosureWriteTimeout892=== RUN TestPendingClosureWriteTimeout/empty893=== PAUSE TestPendingClosureWriteTimeout/empty894=== RUN TestPendingClosureWriteTimeout/400_objects895=== PAUSE TestPendingClosureWriteTimeout/400_objects896=== RUN TestPendingClosureWriteTimeout/670k_objects897=== PAUSE TestPendingClosureWriteTimeout/670k_objects898=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline899=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline900=== CONT TestProxyWriteTimeout901=== RUN TestProxyWriteTimeout/narinfo902=== PAUSE TestProxyWriteTimeout/narinfo903=== RUN TestProxyWriteTimeout/1_GiB_nar904=== PAUSE TestProxyWriteTimeout/1_GiB_nar905=== RUN TestProxyWriteTimeout/10_GiB_nar906=== PAUSE TestProxyWriteTimeout/10_GiB_nar907=== RUN TestProxyWriteTimeout/unknown_size908=== PAUSE TestProxyWriteTimeout/unknown_size909=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9102026/10/01 13:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period911=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure912=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure913=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart914=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart915=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts916=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts917=== CONT TestReadProxyRootRedirectsToIndexHTML9182026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures9192026/10/01 13:01:20 INFO Received cleanup request method=DELETE path=/api/pending_closures9202026/10/01 13:01:20 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=09212026/10/01 13:01:20 INFO Vacuumed table table=pending_closures9222026/10/01 13:01:20 INFO Vacuumed table table=pending_objects9232026/10/01 13:01:20 INFO Vacuumed table table=multipart_uploads9242026/10/01 13:01:20 INFO Vacuumed table table=closures9252026/10/01 13:01:20 INFO Vacuumed table table=objects9262026/10/01 13:01:20 INFO Received complete push request method=POST path=/api/pushes/2/complete927--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.79s)928=== CONT TestPush_CompleteCommitsEveryRoot9292026/10/01 13:01:20 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9302026/10/01 13:01:20 WARN mTLS auth: subject not in bound subjects subject="CN=reader"931--- PASS: TestService_NativeMTLS (0.82s)932=== CONT TestPush_OverlappingRootsStoreOneRowPerKey933=== NAME TestOrphanedObjectsGC934 orphaned_objects_gc_test.go:290: GC Test Summary:935 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A936 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B937 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)938 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)939 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects940--- PASS: TestOrphanedObjectsGC (0.85s)941=== CONT TestReadRedirectUsesPublicS3URL942--- PASS: TestGCEndsOnShutdown (0.85s)943=== CONT TestReadProxyRangeRequest9442026/10/01 13:01:20 INFO Received cleanup request method=DELETE path=/api/pending_closures9452026/10/01 13:01:20 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket14/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""9462026/10/01 13:01:20 INFO Aborted multipart uploads count=0 kept=19472026/10/01 13:01:20 INFO Received cleanup request method=DELETE path=/api/pending_closures9482026/10/01 13:01:20 INFO Aborted multipart uploads count=1 kept=0949--- PASS: TestMultipartCleanup (0.90s)950=== CONT TestReadRedirectKeepsNarinfoProxied9512026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures952--- PASS: TestMetricsInventory (0.91s)953=== CONT TestReadRedirectNar954--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.93s)955=== CONT TestReadProxyDisabled9562026/10/01 13:01:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9572026/10/01 13:01:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete958--- PASS: TestPresentReportsOnlyClosureRoots (0.95s)959=== CONT TestReadProxyInvalidPath9602026/10/01 13:01:20 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OGYzYjUyZjktOGEzZC00ODIzLThlYWQtZGU0ODQ5MmQ2MTM5LjJmMDk2OTdjLTU2YzUtNDViZS04ODM1LWQ0N2E1ZDUxYmQ1MXgxNzkwODU5NjgwMzU4MTMxMDQx parts=109612026/10/01 13:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9622026/10/01 13:01:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OGYzYjUyZjktOGEzZC00ODIzLThlYWQtZGU0ODQ5MmQ2MTM5LmNjZDU3MmQyLTQwMDctNDc3OS1iNjgzLTEwMzY5YmZhZjNmN3gxNzkwODU5NjgwMzQxMDQyNjE2 parts=109632026/10/01 13:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9642026/10/01 13:01:20 INFO Completed upload id=19652026/10/01 13:01:20 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009662026/10/01 13:01:20 INFO Completed upload id=19672026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures9682026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures9692026/10/01 13:01:20 INFO Received uploads request method=POST path=/api/pending_closures9702026/10/01 13:01:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures9712026/10/01 13:01:20 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9722026/10/01 13:01:20 WARN Found objects in DB but missing from S3, will re-upload count=1973--- PASS: TestService_verifyS3Integrity (1.00s)974=== CONT TestReadProxyConditionalGet9752026/10/01 13:01:20 INFO Aborted multipart uploads count=0 kept=09762026/10/01 13:01:21 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=09772026/10/01 13:01:21 INFO Vacuumed table table=pending_closures9782026/10/01 13:01:21 INFO Vacuumed table table=pending_objects9792026/10/01 13:01:21 INFO Vacuumed table table=multipart_uploads980=== NAME TestNARDeduplicationMetadataUploadBug981 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1225469649/001/store/lmnb24sk0l87rvn7ganjbdqhzgqs8jb3-file1.txt9822026/10/01 13:01:21 INFO Vacuumed table table=closures9832026/10/01 13:01:21 INFO Vacuumed table table=objects9842026/10/01 13:01:21 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000985--- PASS: TestService_createPendingClosureHandler (1.04s)986=== CONT TestReadProxyOutlastsServerWriteTimeout987--- PASS: TestObjectStatsTrigger (1.06s)988=== CONT TestReadProxyHead9892026/10/01 13:01:21 INFO Received push request method=POST path=/api/pushes9902026/10/01 13:01:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9912026/10/01 13:01:21 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9922026/10/01 13:01:21 WARN Refused reserved pin name=worker-x86_64-linux9932026/10/01 13:01:21 INFO Uploading lmnb24sk0l87rvn7ganjbdqhzgqs8jb3-file1.txt (160B)9942026/10/01 13:01:21 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9952026/10/01 13:01:21 INFO Received create pin request method=POST path=/api/pins/my-app9962026/10/01 13:01:21 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9972026/10/01 13:01:21 INFO Aborted multipart uploads count=0 kept=0998--- PASS: TestCreatePin_ReservedPins (1.11s)999=== CONT TestReadProxyNarStreaming10002026/10/01 13:01:21 WARN Force mode enabled - objects will be deleted immediately without grace period10012026/10/01 13:01:21 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=010022026/10/01 13:01:21 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10032026/10/01 13:01:21 INFO Vacuumed table table=pending_closures10042026/10/01 13:01:21 WARN Failed to register uploaded object key=lmnb24sk0l87rvn7ganjbdqhzgqs8jb3.ls error="server returned 404: 404 page not found\n"10052026/10/01 13:01:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10062026/10/01 13:01:21 INFO Vacuumed table table=pending_objects10072026/10/01 13:01:21 INFO Vacuumed table table=multipart_uploads10082026/10/01 13:01:21 INFO Signed narinfos id=1 count=110092026/10/01 13:01:21 INFO Uploading 1 narinfos10102026/10/01 13:01:21 INFO Vacuumed table table=closures10112026/10/01 13:01:21 INFO Vacuumed table table=objects10122026/10/01 13:01:21 WARN readiness check failed error="closed pool"1013--- PASS: TestService_readinessHandler (1.12s)1014=== CONT TestReadProxy40410152026/10/01 13:01:21 INFO Received complete push request method=POST path=/api/pushes/1/complete10162026/10/01 13:01:21 WARN Failed to register uploaded object key=lmnb24sk0l87rvn7ganjbdqhzgqs8jb3.narinfo error="server returned 404: 404 page not found\n"1017--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.05s)1018=== CONT TestReadProxyNarinfoAlreadyDecompressed10192026/10/01 13:01:21 INFO Upload complete. (76ms)1020=== NAME TestNARDeduplicationMetadataUploadBug1021 metadata_upload_test.go:54: Retrieved narinfo from S3:1022 StorePath: /build/TestNARDeduplicationMetadataUploadBug1225469649/001/store/lmnb24sk0l87rvn7ganjbdqhzgqs8jb3-file1.txt1023 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1024 Compression: zstd1025 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1026 NarSize: 1601027 References: 1028 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1029 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1030 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1031 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}10322026/10/01 13:01:21 INFO Received uploads request method=POST path=/api/pending_closures1033 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1225469649/001/store/wni80jzvh4svprwq9v50p79b07divvy0-file2.txt10342026/10/01 13:01:21 INFO Received uploads request method=POST path=/api/pending_closures10352026/10/01 13:01:21 INFO Aborted multipart uploads count=0 kept=010362026/10/01 13:01:21 WARN Force mode enabled - objects will be deleted immediately without grace period10372026/10/01 13:01:21 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=010382026/10/01 13:01:21 INFO Vacuumed table table=pending_closures10392026/10/01 13:01:21 INFO Vacuumed table table=pending_objects10402026/10/01 13:01:21 INFO Vacuumed table table=multipart_uploads10412026/10/01 13:01:21 INFO Vacuumed table table=closures10422026/10/01 13:01:21 INFO Vacuumed table table=objects1043--- PASS: TestSweepRechecksPendingAfterLocking (0.80s)1044=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10452026/10/01 13:01:21 INFO Received push request method=POST path=/api/pushes10462026/10/01 13:01:21 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1047--- PASS: TestGetExistingObjectsLocksRows (0.77s)1048=== CONT TestSweepSkipsRowsLockedByPush10492026/10/01 13:01:21 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10502026/10/01 13:01:21 WARN Failed to register uploaded object key=wni80jzvh4svprwq9v50p79b07divvy0.ls error="server returned 404: 404 page not found\n"10512026/10/01 13:01:21 INFO Signed narinfos id=2 count=110522026/10/01 13:01:21 INFO Uploading 1 narinfos10532026/10/01 13:01:21 INFO Received cleanup request method=DELETE path=/api/pending_closures10542026/10/01 13:01:21 INFO Received complete push request method=POST path=/api/pushes/2/complete10552026/10/01 13:01:21 WARN Failed to register uploaded object key=wni80jzvh4svprwq9v50p79b07divvy0.narinfo error="server returned 404: 404 page not found\n"10562026/10/01 13:01:21 INFO Aborted multipart uploads count=0 kept=010572026/10/01 13:01:21 INFO Upload complete. (57ms)1058=== NAME TestNARDeduplicationMetadataUploadBug1059 metadata_upload_test.go:76: Retrieved narinfo from S3:1060 StorePath: /build/TestNARDeduplicationMetadataUploadBug1225469649/001/store/wni80jzvh4svprwq9v50p79b07divvy0-file2.txt1061 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1062 Compression: zstd1063 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1064 NarSize: 1601065 References: 1066 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf10672026/10/01 13:01:21 INFO Received uploads request method=POST path=/api/pending_closures1068 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1069 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1070 {"version":1,"root":{"type":"regular","size":44}}1071--- PASS: TestNARDeduplicationMetadataUploadBug (1.27s)1072=== CONT TestFailedS3DeleteKeepsTombstone10732026/10/01 13:01:21 INFO Received cleanup request method=DELETE path=/api/pending_closures10742026/10/01 13:01:21 INFO Aborted multipart uploads count=1 kept=010752026/10/01 13:01:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10762026-10-01 13:01:21.284 UTC [687] ERROR: Closure does not exist: id=110772026-10-01 13:01:21.284 UTC [687] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE10782026-10-01 13:01:21.284 UTC [687] STATEMENT: -- name: CommitPendingClosure :exec1079 SELECT commit_pending_closure($1::bigint)1080 1081--- PASS: TestService_cleanupPendingClosuresHandler (0.79s)1082=== CONT TestForceGCDuringPushOffersSweptObject1083=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1084=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1085=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1086=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1087=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1088--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.54s)1089=== CONT TestGCSweepDeliversEachKeyOnce10902026/10/01 13:01:21 INFO Received push request method=POST path=/api/pushes10912026/10/01 13:01:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10922026/10/01 13:01:21 INFO Received push request method=POST path=/api/pushes10932026/10/01 13:01:21 INFO Received complete push request method=POST path=/api/pushes/1/complete1094--- PASS: TestPush_CompleteCommitsEveryRoot (0.56s)1095=== CONT TestTombstonedObjectOfferedWithoutWaiting1096--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.54s)1097=== CONT TestGCSweepSkipsPendingObjects1098--- PASS: TestReadProxyRangeRequest (0.51s)1099=== CONT TestDeduplicatedObjectsRecordedAsPending1100--- PASS: TestReadRedirectUsesPublicS3URL (0.56s)1101=== CONT TestPushDedupSurvivesConcurrentGC1102--- PASS: TestReadRedirectKeepsNarinfoProxied (0.53s)1103=== CONT TestGCMetrics1104--- PASS: TestReadRedirectNar (0.55s)1105=== CONT TestGCBugBareHashReferences1106--- PASS: TestReadProxyDisabled (0.56s)1107=== CONT TestGCAdvisoryLockBlocksConcurrentRun1108--- PASS: TestReadProxyInvalidPath (0.56s)1109=== CONT TestLeadEndsOnShutdown1110--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.52s)1111=== CONT TestLeadElectsOneAndHandsOver1112--- PASS: TestReadProxyConditionalGet (0.60s)1113=== CONT TestConnectWaitsForAPeerMigration1114--- PASS: TestReadProxyHead (0.60s)1115=== CONT TestResolveDBConnectionString1116=== RUN TestResolveDBConnectionString/flag_wins1117=== PAUSE TestResolveDBConnectionString/flag_wins1118=== RUN TestResolveDBConnectionString/file_when_flag_empty1119=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1120=== RUN TestResolveDBConnectionString/missing_file_is_an_error1121=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1122=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1123=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1124=== RUN TestResolveDBConnectionString/nothing_configured1125=== PAUSE TestResolveDBConnectionString/nothing_configured1126=== CONT TestReadProxyNarinfo1127--- PASS: TestPushWaitsForSweepHoldingRow (1.29s)1128=== CONT TestClientCADerivations1129--- PASS: TestReadProxy404 (0.58s)1130=== CONT TestClientFallsBackToClosures1131--- PASS: TestReadProxyNarStreaming (0.61s)1132=== CONT TestClientPushesUseOnePush1133--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.62s)1134=== CONT TestPinProtectsFromGC11352026/10/01 13:01:21 INFO Aborted multipart uploads count=0 kept=011362026/10/01 13:01:21 WARN Force mode enabled - objects will be deleted immediately without grace period11372026/10/01 13:01:21 INFO Received uploads request method=POST path=/api/pending_closures11382026/10/01 13:01:21 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=011392026/10/01 13:01:21 INFO Vacuumed table table=pending_closures11402026/10/01 13:01:21 INFO Vacuumed table table=pending_objects11412026/10/01 13:01:21 INFO Vacuumed table table=multipart_uploads11422026/10/01 13:01:21 INFO Vacuumed table table=closures11432026/10/01 13:01:21 INFO Vacuumed table table=objects11442026/10/01 13:01:21 INFO Aborted multipart uploads count=0 kept=011452026/10/01 13:01:21 WARN Force mode enabled - objects will be deleted immediately without grace period11462026/10/01 13:01:21 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=011472026/10/01 13:01:21 INFO Vacuumed table table=pending_closures11482026/10/01 13:01:21 INFO Vacuumed table table=pending_objects11492026/10/01 13:01:21 INFO Vacuumed table table=multipart_uploads11502026/10/01 13:01:21 INFO Vacuumed table table=closures11512026/10/01 13:01:21 INFO Received uploads request method=POST path=/api/pending_closures11522026/10/01 13:01:21 INFO Vacuumed table table=objects1153--- PASS: TestSweepSkipsRowsLockedByPush (0.62s)1154=== CONT TestClientSharedPathCommittedMidPush11552026/10/01 13:01:21 INFO Aborted multipart uploads count=0 kept=011562026/10/01 13:01:21 INFO Received uploads request method=POST path=/api/pending_closures11572026/10/01 13:01:21 INFO Aborted multipart uploads count=0 kept=011582026/10/01 13:01:21 WARN Force mode enabled - objects will be deleted immediately without grace period11592026/10/01 13:01:21 WARN Force mode enabled - objects will be deleted immediately without grace period1160--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.59s)1161=== CONT TestClientWithDependencies11622026/10/01 13:01:21 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11632026/10/01 13:01:21 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1164--- PASS: TestFailedS3DeleteKeepsTombstone (0.67s)1165=== CONT TestClientMultipleUploads11662026/10/01 13:01:21 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=011672026/10/01 13:01:21 INFO Vacuumed table table=pending_closures11682026/10/01 13:01:21 INFO Vacuumed table table=pending_objects11692026/10/01 13:01:21 INFO Vacuumed table table=multipart_uploads11702026/10/01 13:01:21 INFO Vacuumed table table=closures11712026/10/01 13:01:21 INFO Vacuumed table table=objects1172--- PASS: TestGCSweepDeliversEachKeyOnce (0.66s)1173=== CONT TestClientIntegration11742026/10/01 13:01:21 INFO Received uploads request method=POST path=/api/pending_closures11752026/10/01 13:01:21 INFO Aborted multipart uploads count=0 kept=011762026/10/01 13:01:21 INFO Received uploads request method=POST path=/api/pending_closures11772026/10/01 13:01:21 WARN Force mode enabled - objects will be deleted immediately without grace period11782026/10/01 13:01:21 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=011792026/10/01 13:01:21 INFO Vacuumed table table=pending_closures1180--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.62s)1181=== CONT TestClientErrorHandling1182=== RUN TestClientErrorHandling/InvalidStorePath1183=== PAUSE TestClientErrorHandling/InvalidStorePath1184=== RUN TestClientErrorHandling/InvalidAuthToken1185=== PAUSE TestClientErrorHandling/InvalidAuthToken1186=== RUN TestClientErrorHandling/ServerNotAvailable1187=== PAUSE TestClientErrorHandling/ServerNotAvailable1188=== CONT TestService_Rustfstest11892026/10/01 13:01:21 INFO Vacuumed table table=pending_objects11902026/10/01 13:01:21 INFO Vacuumed table table=multipart_uploads11912026/10/01 13:01:21 INFO Vacuumed table table=closures11922026/10/01 13:01:21 INFO Vacuumed table table=objects1193--- PASS: TestGCSweepSkipsPendingObjects (0.67s)1194=== CONT TestParseSize1195--- PASS: TestParseSize (0.00s)1196=== CONT TestRedundantMultipartUpload11972026/10/01 13:01:22 INFO Aborted multipart uploads count=0 kept=011982026/10/01 13:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period11992026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures1200--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.82s)1201=== CONT TestCompleteMultipartUpload_ErrorButObjectExists12022026/10/01 13:01:22 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=012032026/10/01 13:01:22 INFO Vacuumed table table=pending_closures12042026/10/01 13:01:22 INFO Vacuumed table table=pending_objects12052026/10/01 13:01:22 INFO Vacuumed table table=multipart_uploads12062026/10/01 13:01:22 INFO Vacuumed table table=closures12072026/10/01 13:01:22 INFO Vacuumed table table=objects1208--- PASS: TestGCMetrics (0.63s)1209=== CONT TestPush_SignsNarinfosOfItsPendingObjects1210--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.79s)1211=== CONT TestService_RequireScope_OIDC1212--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.62s)1213=== CONT TestCacheStatsHandler12142026/10/01 13:01:22 INFO Aborted multipart uploads count=0 kept=012152026/10/01 13:01:22 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=012162026/10/01 13:01:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35987/oidc12172026/10/01 13:01:22 INFO lead: acquired remote=192.0.2.1:123412182026/10/01 13:01:22 INFO Vacuumed table table=pending_closures12192026/10/01 13:01:22 INFO Vacuumed table table=pending_objects12202026/10/01 13:01:22 INFO Vacuumed table table=multipart_uploads12212026/10/01 13:01:22 INFO Vacuumed table table=closures12222026/10/01 13:01:22 INFO Vacuumed table table=objects12232026/10/01 13:01:22 INFO Aborted multipart uploads count=0 kept=012242026/10/01 13:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period12252026/10/01 13:01:22 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=012262026/10/01 13:01:22 INFO Vacuumed table table=pending_closures12272026/10/01 13:01:22 INFO Vacuumed table table=pending_objects12282026/10/01 13:01:22 INFO Vacuumed table table=multipart_uploads12292026/10/01 13:01:22 INFO Vacuumed table table=closures12302026/10/01 13:01:22 INFO lead: acquired remote=192.0.2.1:123412312026/10/01 13:01:22 INFO Vacuumed table table=objects1232--- PASS: TestPushDedupSurvivesConcurrentGC (0.76s)1233=== CONT TestCacheConfigHandler1234=== RUN TestCacheConfigHandler/full_config,_no_issuer1235=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1236=== RUN TestCacheConfigHandler/no_cache_url_configured1237=== PAUSE TestCacheConfigHandler/no_cache_url_configured1238=== RUN TestCacheConfigHandler/no_signing_keys1239=== PAUSE TestCacheConfigHandler/no_signing_keys1240=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1241=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1242=== CONT TestService_ReadScope_PublicByDefault12432026/10/01 13:01:22 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1244=== NAME TestClientCADerivations1245 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2925747815/001/store/v1bf18p1ffg5kzkpnk0a00zfpl397fsi-ca-test1246--- PASS: TestService_ReadScope_PublicByDefault (0.14s)1247=== CONT TestPush_RejectsBadRequests1248=== NAME TestClientCADerivations1249 client_ca_test.go:139: Found 1 dependencies (including self)1250--- PASS: TestGCBugBareHashReferences (0.87s)1251=== CONT TestCompletedNarNotReofferedAcrossClosures12522026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes1253=== NAME TestPinProtectsFromGC1254 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1249488608/001/store/zf464nynknpsxg8hy50610fgb2lpzbx2-pinned-file.txt1255 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1249488608/001/store/5fb1rfd95b0jxk9vyb6hpvb266f3srpd-unpinned-file.txt12562026/10/01 13:01:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12572026/10/01 13:01:22 INFO Uploading v1bf18p1ffg5kzkpnk0a00zfpl397fsi-ca-test (144B)12582026/10/01 13:01:22 WARN Failed to register uploaded object key=v1bf18p1ffg5kzkpnk0a00zfpl397fsi.ls error="server returned 404: 404 page not found\n"12592026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"12602026/10/01 13:01:22 WARN Failed to register uploaded object key=log/p2mwp98bblsqm6h2iringk8l2p0jyw31-ca-test.drv error="server returned 404: 404 page not found\n"12612026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12622026/10/01 13:01:22 INFO Signed narinfos id=1 count=112632026/10/01 13:01:22 INFO Uploading 1 narinfos12642026/10/01 13:01:22 INFO Received complete push request method=POST path=/api/pushes/1/complete12652026/10/01 13:01:22 WARN Failed to register uploaded object key=v1bf18p1ffg5kzkpnk0a00zfpl397fsi.narinfo error="server returned 404: 404 page not found\n"12662026/10/01 13:01:22 INFO Upload complete. (97ms)12672026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures1268=== NAME TestClientCADerivations1269 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2925747815/001/store/v1bf18p1ffg5kzkpnk0a00zfpl397fsi-ca-test1270 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1271 Compression: zstd1272 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1273 NarSize: 1441274 References: 1275 Deriver: /build/TestClientCADerivations2925747815/001/store/p2mwp98bblsqm6h2iringk8l2p0jyw31-ca-test.drv1276 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1277 client_ca_test.go:185: Checking for realisation files in S3...12782026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures1279 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1280 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache12812026/10/01 13:01:22 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12822026/10/01 13:01:22 INFO Uploading r3syiwqb35d5am7irrs1h3v6mr0pxfq1-b (216B)12832026/10/01 13:01:22 INFO Uploading y8bn2xc7np7r864f3jdramqq68ccjy46-shared-dep (136B)12842026/10/01 13:01:22 WARN Failed to register uploaded object key=03zn9j71x7r45byigmf2578igf928936.ls error="server returned 404: 404 page not found\n"12852026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/031k8ykdr7z8nbxr5wl9wgfkcklgwqnj4whiq3kyl6ja4j97kpf8.nar.zst error="server returned 404: 404 page not found\n"12862026/10/01 13:01:22 WARN Failed to register uploaded object key=y8bn2xc7np7r864f3jdramqq68ccjy46.ls error="server returned 404: 404 page not found\n"12872026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12882026/10/01 13:01:22 WARN Failed to register uploaded object key=r3syiwqb35d5am7irrs1h3v6mr0pxfq1.ls error="server returned 404: 404 page not found\n"12892026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12902026/10/01 13:01:22 INFO Signed narinfos id=1 count=212912026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12922026/10/01 13:01:22 INFO Signed narinfos id=2 count=212932026/10/01 13:01:22 INFO Uploading 4 narinfos12942026/10/01 13:01:22 WARN Failed to register uploaded object key=y8bn2xc7np7r864f3jdramqq68ccjy46.narinfo error="server returned 404: 404 page not found\n"12952026/10/01 13:01:22 WARN Failed to register uploaded object key=r3syiwqb35d5am7irrs1h3v6mr0pxfq1.narinfo error="server returned 404: 404 page not found\n"12962026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes12972026/10/01 13:01:22 WARN Failed to register uploaded object key=03zn9j71x7r45byigmf2578igf928936.narinfo error="server returned 404: 404 page not found\n"1298=== NAME TestClientMultipleUploads1299 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads534564997/001/store/qjl5yg5g6q11sxppgvvkfl3v1lzvqq8f-test-file-0.txt13002026/10/01 13:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13012026/10/01 13:01:22 WARN Failed to register uploaded object key=y8bn2xc7np7r864f3jdramqq68ccjy46.narinfo error="server returned 404: 404 page not found\n"13022026/10/01 13:01:22 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13032026/10/01 13:01:22 INFO Uploading nwngb42xknm7sh3fwadpfb0xi68s2rhw-shared-dep (136B)13042026/10/01 13:01:22 INFO Uploading api25y40vlmh1zl8sscz8d4gbclj897s-b (216B)13052026/10/01 13:01:22 INFO Completed upload id=113062026/10/01 13:01:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13072026/10/01 13:01:22 INFO Completed upload id=213082026/10/01 13:01:22 INFO Upload complete. (69ms)13092026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures1310=== NAME TestClientFallsBackToClosures1311 client_pushes_test.go:112: Retrieved narinfo from S3:1312 StorePath: /build/TestClientFallsBackToClosures2163355846/001/store/y8bn2xc7np7r864f3jdramqq68ccjy46-shared-dep1313 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1314 Compression: zstd1315 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821316 NarSize: 1361317 References: 1318 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13192026/10/01 13:01:22 WARN Failed to register uploaded object key=ygcwgnr33kvx73p22x58s4lbmjc3bhjn.ls error="server returned 404: 404 page not found\n"13202026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/140yrrxvywydxz075fv3ifjp7xfv42lz9dq8rgxyim3r0j0mikwg.nar.zst error="server returned 404: 404 page not found\n"13212026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13222026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13232026/10/01 13:01:22 WARN Failed to register uploaded object key=api25y40vlmh1zl8sscz8d4gbclj897s.ls error="server returned 404: 404 page not found\n"13242026/10/01 13:01:22 WARN Failed to register uploaded object key=nwngb42xknm7sh3fwadpfb0xi68s2rhw.ls error="server returned 404: 404 page not found\n"13252026/10/01 13:01:22 INFO Signed narinfos id=1 count=31326 client_pushes_test.go:112: Retrieved narinfo from S3:1327 StorePath: /build/TestClientFallsBackToClosures2163355846/001/store/03zn9j71x7r45byigmf2578igf928936-a13282026/10/01 13:01:22 INFO Uploading 3 narinfos1329 URL: nar/031k8ykdr7z8nbxr5wl9wgfkcklgwqnj4whiq3kyl6ja4j97kpf8.nar.zst1330 Compression: zstd1331 NarHash: sha256:031k8ykdr7z8nbxr5wl9wgfkcklgwqnj4whiq3kyl6ja4j97kpf81332 NarSize: 2161333 References: /build/TestClientFallsBackToClosures2163355846/001/store/y8bn2xc7np7r864f3jdramqq68ccjy46-shared-dep1334 CA: text:sha256:0q09j6kbsykabjsqvmp45c8mw3biribnncr901hnx4lbpa595aj81335 client_pushes_test.go:112: Retrieved narinfo from S3:13362026/10/01 13:01:22 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161337 StorePath: /build/TestClientFallsBackToClosures2163355846/001/store/r3syiwqb35d5am7irrs1h3v6mr0pxfq1-b1338 URL: nar/031k8ykdr7z8nbxr5wl9wgfkcklgwqnj4whiq3kyl6ja4j97kpf8.nar.zst1339 Compression: zstd1340 NarHash: sha256:031k8ykdr7z8nbxr5wl9wgfkcklgwqnj4whiq3kyl6ja4j97kpf81341 NarSize: 2161342 References: /build/TestClientFallsBackToClosures2163355846/001/store/y8bn2xc7np7r864f3jdramqq68ccjy46-shared-dep1343 CA: text:sha256:0q09j6kbsykabjsqvmp45c8mw3biribnncr901hnx4lbpa595aj81344--- PASS: TestReadProxyNarinfo (0.82s)1345=== CONT TestPresignedUploadRegisteredBeforeCommit13462026/10/01 13:01:22 WARN Failed to register uploaded object key=nwngb42xknm7sh3fwadpfb0xi68s2rhw.narinfo error="server returned 404: 404 page not found\n"13472026/10/01 13:01:22 WARN Failed to register uploaded object key=ygcwgnr33kvx73p22x58s4lbmjc3bhjn.narinfo error="server returned 404: 404 page not found\n"13482026/10/01 13:01:22 INFO Received complete push request method=POST path=/api/pushes/1/complete13492026/10/01 13:01:22 WARN Failed to register uploaded object key=api25y40vlmh1zl8sscz8d4gbclj897s.narinfo error="server returned 404: 404 page not found\n"13502026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures1351--- PASS: TestClientFallsBackToClosures (0.78s)1352=== CONT TestService_ReadAuthMiddleware1353=== NAME TestClientWithDependencies1354 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3343163994/001/store/xd8h5f4wp9r09y80im56vmgg5xqfcd86-test-script1355=== NAME TestClientIntegration13562026/10/01 13:01:22 INFO Upload complete. (65ms)1357 client_integration_test.go:286: Created store path: /build/TestClientIntegration3340886619/002/store/naqd05glpx3lgbfyf4l782577nyr05cm-test-file.txt1358=== NAME TestClientPushesUseOnePush1359 client_pushes_test.go:97: Retrieved narinfo from S3:1360 StorePath: /build/TestClientPushesUseOnePush2101051576/001/store/nwngb42xknm7sh3fwadpfb0xi68s2rhw-shared-dep1361 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1362 Compression: zstd1363 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821364 NarSize: 1361365 References: 1366 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13672026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes1368 client_pushes_test.go:97: Retrieved narinfo from S3:1369 StorePath: /build/TestClientPushesUseOnePush2101051576/001/store/ygcwgnr33kvx73p22x58s4lbmjc3bhjn-a1370 URL: nar/140yrrxvywydxz075fv3ifjp7xfv42lz9dq8rgxyim3r0j0mikwg.nar.zst1371 Compression: zstd1372 NarHash: sha256:140yrrxvywydxz075fv3ifjp7xfv42lz9dq8rgxyim3r0j0mikwg1373 NarSize: 2161374 References: /build/TestClientPushesUseOnePush2101051576/001/store/nwngb42xknm7sh3fwadpfb0xi68s2rhw-shared-dep1375 CA: text:sha256:0i7pp237lq96d8l8cvgd8vw9nw6r25fv91dw8mi4s27fy33vjcr01376 client_pushes_test.go:97: Retrieved narinfo from S3:1377 StorePath: /build/TestClientPushesUseOnePush2101051576/001/store/api25y40vlmh1zl8sscz8d4gbclj897s-b1378 URL: nar/140yrrxvywydxz075fv3ifjp7xfv42lz9dq8rgxyim3r0j0mikwg.nar.zst1379 Compression: zstd1380 NarHash: sha256:140yrrxvywydxz075fv3ifjp7xfv42lz9dq8rgxyim3r0j0mikwg1381 NarSize: 2161382 References: /build/TestClientPushesUseOnePush2101051576/001/store/nwngb42xknm7sh3fwadpfb0xi68s2rhw-shared-dep1383 CA: text:sha256:0i7pp237lq96d8l8cvgd8vw9nw6r25fv91dw8mi4s27fy33vjcr013842026/10/01 13:01:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13852026/10/01 13:01:22 INFO Uploading zf464nynknpsxg8hy50610fgb2lpzbx2-pinned-file.txt (128B)1386--- PASS: TestService_Rustfstest (0.51s)1387=== CONT TestService_AuthMiddleware_OIDC13882026/10/01 13:01:22 WARN Failed to register uploaded object key=zf464nynknpsxg8hy50610fgb2lpzbx2.ls error="server returned 404: 404 page not found\n"13892026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13902026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13912026/10/01 13:01:22 INFO Signed narinfos id=1 count=113922026/10/01 13:01:22 INFO Uploading 1 narinfos1393--- PASS: TestClientPushesUseOnePush (0.79s)1394=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13952026/10/01 13:01:22 INFO Received complete push request method=POST path=/api/pushes/1/complete13962026/10/01 13:01:22 WARN Failed to register uploaded object key=zf464nynknpsxg8hy50610fgb2lpzbx2.narinfo error="server returned 404: 404 page not found\n"1397=== NAME TestClientWithDependencies1398 client_integration_test.go:615: Found 1 dependencies (including self)1399=== NAME TestClientMultipleUploads1400 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads534564997/001/store/cgdl2h3gpjwzcp39rrcxnrhlyqm6dcnk-test-file-1.txt14012026/10/01 13:01:22 INFO Upload complete. (65ms)14022026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures14032026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes14042026/10/01 13:01:22 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14052026/10/01 13:01:22 INFO Uploading 3fpqkr8shh0hc869jrg7czlzjgaczd1b-top (224B)14062026/10/01 13:01:22 INFO Uploading s4530bw6042bv40igz7p8addpq7mm6l3-shared-dep (136B)14072026/10/01 13:01:22 WARN Failed to register uploaded object key=3fpqkr8shh0hc869jrg7czlzjgaczd1b.ls error="server returned 404: 404 page not found\n"14082026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/0cdqp17mp12kzprzmilsagw8hmfvji3isd7cdnrf1jn78f3r3yj7.nar.zst error="server returned 404: 404 page not found\n"14092026/10/01 13:01:22 WARN Failed to register uploaded object key=s4530bw6042bv40igz7p8addpq7mm6l3.ls error="server returned 404: 404 page not found\n"14102026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14112026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14122026/10/01 13:01:22 INFO Signed narinfos id=1 count=214132026/10/01 13:01:22 INFO Uploading 2 narinfos14142026/10/01 13:01:22 INFO Received complete push request method=POST path=/api/pushes/1/complete14152026/10/01 13:01:22 WARN Failed to register uploaded object key=3fpqkr8shh0hc869jrg7czlzjgaczd1b.narinfo error="server returned 404: 404 page not found\n"14162026/10/01 13:01:22 WARN Failed to register uploaded object key=s4530bw6042bv40igz7p8addpq7mm6l3.narinfo error="server returned 404: 404 page not found\n"1417 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads534564997/001/store/9d1kk0qfxam7519lrzxdv4b1gcmldnrx-test-file-2.txt14182026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes14192026/10/01 13:01:22 INFO Upload complete. (78ms)1420=== NAME TestClientSharedPathCommittedMidPush1421 client_integration_test.go:680: Retrieved narinfo from S3:1422 StorePath: /build/TestClientSharedPathCommittedMidPush3119357454/001/store/s4530bw6042bv40igz7p8addpq7mm6l3-shared-dep1423 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1424 Compression: zstd1425 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821426 NarSize: 1361427 References: 1428 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14292026/10/01 13:01:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1430 client_integration_test.go:680: Retrieved narinfo from S3:1431 StorePath: /build/TestClientSharedPathCommittedMidPush3119357454/001/store/3fpqkr8shh0hc869jrg7czlzjgaczd1b-top1432 URL: nar/0cdqp17mp12kzprzmilsagw8hmfvji3isd7cdnrf1jn78f3r3yj7.nar.zst1433 Compression: zstd1434 NarHash: sha256:0cdqp17mp12kzprzmilsagw8hmfvji3isd7cdnrf1jn78f3r3yj71435 NarSize: 2241436 References: /build/TestClientSharedPathCommittedMidPush3119357454/001/store/s4530bw6042bv40igz7p8addpq7mm6l3-shared-dep1437 CA: text:sha256:1jv3y61rm51z7v5q5367jpsqy3x1grqr0kby8v0g9p1axrhdsab71438=== NAME TestOrphanedObjectsGCStressTest1439 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains14402026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14412026/10/01 13:01:22 INFO Signed narinfos id=1 count=11442--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.51s)1443=== CONT TestService_AuthMiddleware_MTLSProxyHeader14442026/10/01 13:01:22 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGYzYjUyZjktOGEzZC00ODIzLThlYWQtZGU0ODQ5MmQ2MTM5LmJmMzNkMWQ4LWZkODgtNDlmMS1hYmM5LTM3YjRhODI5OTQxZngxNzkwODU5NjgyNTM4OTM5NzQw1445=== NAME TestClientCADerivations1446 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1447 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1448 error: binary cache 's3://bucket61?endpoint=http://localhost:38433®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2925747815/001/store'1449 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 114502026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes1451--- PASS: TestClientSharedPathCommittedMidPush (0.71s)1452=== CONT TestServerTLSConfig/no_client_CA1453=== CONT TestServerTLSConfig/not_a_PEM_file1454=== CONT TestServerTLSConfig/missing_CA_file1455=== CONT TestParseSingleRange/none1456--- PASS: TestServerTLSConfig (0.00s)1457 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1458 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1459 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1460=== CONT TestParseSingleRange/start_far_past_EOF1461=== CONT TestParseSingleRange/start_past_EOF1462=== CONT TestParseSingleRange/single_byte1463=== CONT TestParseSingleRange/suffix_exceeds_size1464=== CONT TestParseSingleRange/suffix1465=== CONT TestParseSingleRange/end_clamped_to_size1466=== CONT TestParseSingleRange/open-ended1467=== CONT TestParseSingleRange/closed1468=== CONT TestParseSingleRange/malformed_end_before_start1469=== CONT TestParseSingleRange/malformed_both_empty1470=== CONT TestParseSingleRange/malformed_no_dash1471=== CONT TestParseSingleRange/multi-range_ignored14722026/10/01 13:01:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGYzYjUyZjktOGEzZC00ODIzLThlYWQtZGU0ODQ5MmQ2MTM5LmJmMzNkMWQ4LWZkODgtNDlmMS1hYmM5LTM3YjRhODI5OTQxZngxNzkwODU5NjgyNTM4OTM5NzQw parts=11473=== CONT TestParseSingleRange/unknown_unit1474--- PASS: TestParseSingleRange (0.01s)1475 --- PASS: TestParseSingleRange/none (0.00s)1476 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1477 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1478 --- PASS: TestParseSingleRange/single_byte (0.00s)1479 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1480 --- PASS: TestParseSingleRange/suffix (0.00s)1481 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1482 --- PASS: TestParseSingleRange/open-ended (0.00s)1483 --- PASS: TestParseSingleRange/closed (0.00s)1484 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1485 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1486 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1487 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1488 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1489=== CONT TestIsValidCachePath/narinfo1490=== CONT TestIsValidCachePath/index.html1491=== CONT TestIsValidCachePath/short_hash1492=== CONT TestIsValidCachePath/wrong_extension1493=== CONT TestIsValidCachePath/leading_slash1494=== CONT TestIsValidCachePath/empty1495=== CONT TestIsValidCachePath/random_path1496=== CONT TestIsValidCachePath/invalid_char_u1497=== CONT TestIsValidCachePath/invalid_char_e1498=== CONT TestIsValidCachePath/traversal_in_middle1499=== CONT TestIsValidCachePath/traversal_parent1500=== CONT TestIsValidCachePath/nar_uncompressed1501=== CONT TestIsValidCachePath/nix-cache-info1502=== CONT TestIsValidCachePath/realisation1503=== CONT TestIsValidCachePath/log1504=== CONT TestIsValidCachePath/ls1505=== CONT TestIsValidCachePath/nar_xz1506=== CONT TestIsValidCachePath/nar_bz21507=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1508=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15092026/10/01 13:01:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1510--- PASS: TestClientCADerivations (0.92s)15112026/10/01 13:01:22 INFO Uploading naqd05glpx3lgbfyf4l782577nyr05cm-test-file.txt (152B)1512=== CONT TestIsValidCachePath/nar_zst15132026/10/01 13:01:22 INFO Received uploads request method=POST path=/1514=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1515--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.53s)15162026/10/01 13:01:22 INFO Received request for more parts method=POST path=/1517=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15182026/10/01 13:01:22 INFO Received complete multipart upload request method=POST path=/1519=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15202026/10/01 13:01:22 INFO Received uploads request method=POST path=/1521--- PASS: TestIsValidCachePath (0.01s)1522 --- PASS: TestIsValidCachePath/narinfo (0.00s)1523 --- PASS: TestIsValidCachePath/index.html (0.00s)1524 --- PASS: TestIsValidCachePath/short_hash (0.00s)1525 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1526 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1527 --- PASS: TestIsValidCachePath/empty (0.00s)1528 --- PASS: TestIsValidCachePath/random_path (0.00s)1529 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1530 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1531 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1532 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1533 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1534 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1535 --- PASS: TestIsValidCachePath/realisation (0.00s)1536 --- PASS: TestIsValidCachePath/log (0.00s)1537 --- PASS: TestIsValidCachePath/ls (0.00s)1538 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1539 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1540 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1541 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1542=== CONT TestIsValidUploadKey/narinfo1543=== CONT TestIsValidUploadKey/traversal1544=== CONT TestIsValidUploadKey/absolute1545=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1546=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1547=== CONT TestIsValidUploadKey/index.html1548=== CONT TestIsValidUploadKey/nix-cache-info1549=== CONT TestIsValidUploadKey/realisation_plus_in_output1550=== CONT TestIsValidUploadKey/realisation1551=== CONT TestIsValidUploadKey/build_log_equals1552=== CONT TestIsValidUploadKey/build_log_question_mark1553=== CONT TestIsValidUploadKey/build_log_plus_in_name1554=== CONT TestIsValidUploadKey/build_log_home-manager_file1555=== CONT TestIsValidUploadKey/build_log1556=== CONT TestIsValidUploadKey/traversal_nar1557--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1558 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1559 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1560 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1561 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1562=== CONT TestIsValidUploadKey/nar_plain1563=== CONT TestIsValidUploadKey/nar_xz1564=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1565=== CONT TestIsValidUploadKey/listing1566=== CONT TestIsValidUploadKey/empty_key1567=== CONT TestIsValidUploadKey/nar_zst1568=== CONT TestIsValidUploadKey/unknown_type1569--- PASS: TestIsValidUploadKey (0.00s)1570 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1571 --- PASS: TestIsValidUploadKey/traversal (0.00s)1572 --- PASS: TestIsValidUploadKey/absolute (0.00s)1573 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1574 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1575 --- PASS: TestIsValidUploadKey/index.html (0.00s)1576 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1577 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1578 --- PASS: TestIsValidUploadKey/realisation (0.00s)1579 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1580 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1581 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1582 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1583 --- PASS: TestIsValidUploadKey/build_log (0.00s)1584 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1585 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1586 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1587 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1588 --- PASS: TestIsValidUploadKey/listing (0.00s)1589 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1590 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1591 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1592=== CONT TestPendingClosureWriteTimeout/empty1593=== CONT TestPendingClosureWriteTimeout/400_objects1594=== CONT TestProxyWriteTimeout/narinfo1595=== CONT TestPendingClosureWriteTimeout/670k_objects1596=== CONT TestProxyWriteTimeout/unknown_size1597=== CONT TestProxyWriteTimeout/1_GiB_nar1598=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1599=== CONT TestProxyWriteTimeout/10_GiB_nar1600--- PASS: TestProxyWriteTimeout (0.00s)1601 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1602 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1603 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1604 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1605=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16062026/10/01 13:01:22 INFO Received uploads request method=POST path=/1607=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16082026/10/01 13:01:22 INFO Received request for more parts method=POST path=/16092026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes16102026/10/01 13:01:22 WARN Failed to register uploaded object key=naqd05glpx3lgbfyf4l782577nyr05cm.ls error="server returned 404: 404 page not found\n"16112026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16122026/10/01 13:01:22 INFO Signed narinfos id=1 count=116132026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16142026/10/01 13:01:22 INFO Uploading 1 narinfos16152026/10/01 13:01:22 INFO Received complete push request method=POST path=/api/pushes/1/complete16162026/10/01 13:01:22 WARN Failed to register uploaded object key=naqd05glpx3lgbfyf4l782577nyr05cm.narinfo error="server returned 404: 404 page not found\n"16172026/10/01 13:01:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16182026/10/01 13:01:22 INFO Uploading xd8h5f4wp9r09y80im56vmgg5xqfcd86-test-script (136B)1619--- PASS: TestCacheStatsHandler (0.49s)1620=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16212026/10/01 13:01:22 INFO Received complete multipart upload request method=POST path=/16222026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes16232026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16242026/10/01 13:01:22 WARN Failed to register uploaded object key=xd8h5f4wp9r09y80im56vmgg5xqfcd86.ls error="server returned 404: 404 page not found\n"16252026/10/01 13:01:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16262026/10/01 13:01:22 WARN Failed to register uploaded object key=log/r7mwpbn6bj0m961v5hxvjjmc3s5wlw3y-test-script.drv error="server returned 404: 404 page not found\n"16272026/10/01 13:01:22 INFO Uploading 5fb1rfd95b0jxk9vyb6hpvb266f3srpd-unpinned-file.txt (128B)16282026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16292026/10/01 13:01:22 INFO Signed narinfos id=1 count=116302026/10/01 13:01:22 INFO Uploading 1 narinfos16312026/10/01 13:01:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34397/oidc16322026/10/01 13:01:22 INFO Upload complete. (83ms)16332026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16342026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16352026/10/01 13:01:22 INFO Received complete push request method=POST path=/api/pushes/1/complete16362026/10/01 13:01:22 WARN Failed to register uploaded object key=5fb1rfd95b0jxk9vyb6hpvb266f3srpd.ls error="server returned 404: 404 page not found\n"16372026/10/01 13:01:22 INFO Signed narinfos id=2 count=116382026/10/01 13:01:22 WARN Failed to register uploaded object key=xd8h5f4wp9r09y80im56vmgg5xqfcd86.narinfo error="server returned 404: 404 page not found\n"16392026/10/01 13:01:22 INFO Uploading 1 narinfos1640=== NAME TestOrphanedObjectsGCStressTest1641 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16422026/10/01 13:01:22 WARN Failed to register uploaded object key=5fb1rfd95b0jxk9vyb6hpvb266f3srpd.narinfo error="server returned 404: 404 page not found\n"16432026/10/01 13:01:22 INFO Received complete push request method=POST path=/api/pushes/2/complete16442026/10/01 13:01:22 INFO Upload complete. (57ms)16452026/10/01 13:01:22 INFO Upload complete. (64ms)1646=== NAME TestClientWithDependencies1647 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3343163994/001/store) requires matching store prefix1648--- PASS: TestClientWithDependencies (0.69s)1649=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16502026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes1651=== RUN TestService_RequireScope_OIDC/builder_may_write1652=== PAUSE TestService_RequireScope_OIDC/builder_may_write1653=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1654=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1655=== RUN TestService_RequireScope_OIDC/ops_may_admin1656=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1657=== RUN TestService_RequireScope_OIDC/ops_may_not_write1658=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1659=== RUN TestService_RequireScope_OIDC/reader_may_not_write1660=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1661=== RUN TestService_RequireScope_OIDC/static_token_may_admin1662=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1663=== RUN TestService_RequireScope_OIDC/static_token_may_write1664=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1665=== RUN TestService_RequireScope_OIDC/reader_may_read1666=== PAUSE TestService_RequireScope_OIDC/reader_may_read1667=== RUN TestService_RequireScope_OIDC/writer_implies_read1668=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1669=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1670=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1671=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16722026/10/01 13:01:22 INFO All 1 paths already cached1673=== NAME TestClientIntegration1674 client_integration_test.go:312: Retrieved narinfo from S3:1675 StorePath: /build/TestClientIntegration3340886619/002/store/naqd05glpx3lgbfyf4l782577nyr05cm-test-file.txt1676 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1677 Compression: zstd1678 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11679 NarSize: 1521680 References: 1681 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk116822026/10/01 13:01:22 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1683=== RUN TestPush_RejectsBadRequests/no_objects16842026/10/01 13:01:22 INFO Uploading 9d1kk0qfxam7519lrzxdv4b1gcmldnrx-test-file-2.txt (160B)1685=== PAUSE TestPush_RejectsBadRequests/no_objects1686=== RUN TestPush_RejectsBadRequests/bad_root16872026/10/01 13:01:22 INFO Uploading qjl5yg5g6q11sxppgvvkfl3v1lzvqq8f-test-file-0.txt (160B)1688=== PAUSE TestPush_RejectsBadRequests/bad_root16892026/10/01 13:01:22 INFO Uploading cgdl2h3gpjwzcp39rrcxnrhlyqm6dcnk-test-file-1.txt (160B)1690=== RUN TestPush_RejectsBadRequests/root_not_in_objects1691=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1692=== RUN TestPush_RejectsBadRequests/no_roots1693=== PAUSE TestPush_RejectsBadRequests/no_roots1694=== CONT TestResolveDBConnectionString/flag_wins1695=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1696=== CONT TestResolveDBConnectionString/nothing_configured1697=== CONT TestResolveDBConnectionString/missing_file_is_an_error1698=== CONT TestResolveDBConnectionString/file_when_flag_empty1699=== CONT TestClientErrorHandling/InvalidStorePath1700=== NAME TestClientIntegration1701 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1702--- PASS: TestResolveDBConnectionString (0.00s)1703 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1704 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1705 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1706 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1707 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1708=== NAME TestClientIntegration1709 client_integration_test.go:313: Decompressed .ls content (64 bytes):1710 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1711 client_integration_test.go:316: Testing garbage collection...17122026/10/01 13:01:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures17132026/10/01 13:01:22 WARN Failed to register uploaded object key=9d1kk0qfxam7519lrzxdv4b1gcmldnrx.ls error="server returned 404: 404 page not found\n"17142026/10/01 13:01:22 WARN Failed to register uploaded object key=qjl5yg5g6q11sxppgvvkfl3v1lzvqq8f.ls error="server returned 404: 404 page not found\n"17152026/10/01 13:01:22 INFO Garbage collection started17162026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17172026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17182026/10/01 13:01:22 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17192026/10/01 13:01:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17202026/10/01 13:01:22 WARN Failed to register uploaded object key=cgdl2h3gpjwzcp39rrcxnrhlyqm6dcnk.ls error="server returned 404: 404 page not found\n"17212026/10/01 13:01:22 INFO Signed narinfos id=1 count=317222026/10/01 13:01:22 INFO Uploading 3 narinfos17232026/10/01 13:01:22 WARN Failed to register uploaded object key=9d1kk0qfxam7519lrzxdv4b1gcmldnrx.narinfo error="server returned 404: 404 page not found\n"17242026/10/01 13:01:22 WARN Failed to register uploaded object key=qjl5yg5g6q11sxppgvvkfl3v1lzvqq8f.narinfo error="server returned 404: 404 page not found\n"17252026/10/01 13:01:22 INFO Received complete push request method=POST path=/api/pushes/1/complete17262026/10/01 13:01:22 WARN Failed to register uploaded object key=cgdl2h3gpjwzcp39rrcxnrhlyqm6dcnk.narinfo error="server returned 404: 404 page not found\n"1727=== CONT TestClientErrorHandling/ServerNotAvailable17282026/10/01 13:01:22 INFO Aborted multipart uploads count=0 kept=01729=== CONT TestClientErrorHandling/InvalidAuthToken17302026/10/01 13:01:22 INFO Upload complete. (78ms)1731=== NAME TestClientMultipleUploads1732 client_integration_test.go:369: Uploaded 3 paths in 112.584996ms17332026/10/01 13:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period17342026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures1735--- PASS: TestClientMultipleUploads (0.74s)1736=== CONT TestCacheConfigHandler/full_config,_no_issuer1737=== CONT TestCacheConfigHandler/no_signing_keys1738=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1739=== CONT TestCacheConfigHandler/no_cache_url_configured1740=== CONT TestService_RequireScope_OIDC/builder_may_write1741--- PASS: TestCacheConfigHandler (0.00s)1742 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1743 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1744 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1745 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1746=== CONT TestService_RequireScope_OIDC/static_token_may_admin1747=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1748=== CONT TestService_RequireScope_OIDC/writer_implies_read1749=== CONT TestService_RequireScope_OIDC/reader_may_read1750=== CONT TestService_RequireScope_OIDC/static_token_may_write1751=== CONT TestService_RequireScope_OIDC/ops_may_admin1752=== CONT TestService_RequireScope_OIDC/reader_may_not_write1753=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1754=== CONT TestService_RequireScope_OIDC/ops_may_not_write1755=== CONT TestPush_RejectsBadRequests/no_objects17562026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes1757=== CONT TestPush_RejectsBadRequests/root_not_in_objects17582026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes1759=== CONT TestPush_RejectsBadRequests/no_roots17602026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes1761--- PASS: TestService_RequireScope_OIDC (0.55s)1762 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1763 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1764 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1765 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1766 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1767 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1768 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1769 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1770 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1771 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1772=== CONT TestPush_RejectsBadRequests/bad_root17732026/10/01 13:01:22 INFO Received push request method=POST path=/api/pushes1774--- PASS: TestPush_RejectsBadRequests (0.33s)1775 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1776 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1777 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1778 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)17792026/10/01 13:01:22 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=017802026/10/01 13:01:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures17812026/10/01 13:01:22 INFO Garbage collection started17822026/10/01 13:01:22 INFO Aborted multipart uploads count=0 kept=017832026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures17842026/10/01 13:01:22 INFO Vacuumed table table=pending_closures17852026/10/01 13:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period17862026/10/01 13:01:22 INFO Vacuumed table table=pending_objects17872026/10/01 13:01:22 INFO Vacuumed table table=multipart_uploads17882026/10/01 13:01:22 INFO Vacuumed table table=closures17892026/10/01 13:01:22 INFO Vacuumed table table=objects17902026/10/01 13:01:22 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst17912026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures17922026/10/01 13:01:22 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=01793--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.25s)17942026/10/01 13:01:22 INFO Vacuumed table table=pending_closures17952026/10/01 13:01:22 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/present1796--- PASS: TestService_ReadAuthMiddleware (0.25s)17972026/10/01 13:01:22 INFO Vacuumed table table=pending_objects17982026/10/01 13:01:22 INFO Vacuumed table table=multipart_uploads17992026/10/01 13:01:22 INFO Vacuumed table table=closures18002026/10/01 13:01:22 INFO Vacuumed table table=objects18012026/10/01 13:01:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18022026/10/01 13:01:22 WARN mTLS auth: bound subjects configured but subject DN unavailable18032026/10/01 13:01:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1804--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.28s)18052026/10/01 13:01:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.786979ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1806--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.27s)18072026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures1808=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1809=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1810=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1811=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1812=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1813=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1814=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1815=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1816=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1817=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1818=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured18192026/10/01 13:01:22 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]1820=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18212026/10/01 13:01:22 WARN Authentication failed token_preview=eyJhbGciOi...fSsd-fTP5A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1822--- PASS: TestService_AuthMiddleware_OIDC (0.40s)1823 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1824 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1825 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1826 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18272026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures18282026/10/01 13:01:22 INFO Aborted multipart uploads count=0 kept=018292026/10/01 13:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period18302026/10/01 13:01:22 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=018312026/10/01 13:01:22 INFO Vacuumed table table=pending_closures18322026/10/01 13:01:22 INFO Vacuumed table table=pending_objects18332026/10/01 13:01:22 INFO Vacuumed table table=multipart_uploads18342026/10/01 13:01:22 INFO Vacuumed table table=closures18352026/10/01 13:01:22 INFO Vacuumed table table=objects18362026/10/01 13:01:22 INFO Received uploads request method=POST path=/api/pending_closures18372026/10/01 13:01:22 INFO Aborted multipart uploads count=0 kept=018382026/10/01 13:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period18392026/10/01 13:01:22 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=018402026/10/01 13:01:22 INFO Vacuumed table table=pending_closures18412026/10/01 13:01:22 INFO Vacuumed table table=pending_objects18422026/10/01 13:01:22 INFO Vacuumed table table=multipart_uploads18432026/10/01 13:01:22 INFO Vacuumed table table=closures18442026/10/01 13:01:22 INFO Vacuumed table table=objects1845--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1846 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.36s)1847 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.37s)18482026/10/01 13:01:23 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=365.800567ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1849=== NAME TestOrphanedObjectsGCStressTest1850 orphaned_objects_gc_test.go:509: Stress test completed successfully:1851 orphaned_objects_gc_test.go:510: - Active objects preserved: 201852 orphaned_objects_gc_test.go:511: - Objects deleted: 2101853 orphaned_objects_gc_test.go:512: - Total GC'd: 2101854--- PASS: TestOrphanedObjectsGCStressTest (3.04s)18552026/10/01 13:01:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18562026/10/01 13:01:23 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18572026/10/01 13:01:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OGYzYjUyZjktOGEzZC00ODIzLThlYWQtZGU0ODQ5MmQ2MTM5LjFmMzE1ZGNjLTQ1ZWMtNDM1OS04NTM1LTVmMWRiZTM0OTkzY3gxNzkwODU5NjgyNDgxMDYyODEx parts=1218582026/10/01 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures18592026/10/01 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures18602026/10/01 13:01:23 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18612026/10/01 13:01:23 INFO lead: released remote=192.0.2.1:12341862--- PASS: TestLeadEndsOnShutdown (1.67s)1863--- PASS: TestUploadHandlersRejectOversizedBody (0.21s)1864 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1865 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1866 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.63s)18672026/10/01 13:01:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18682026/10/01 13:01:23 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OGYzYjUyZjktOGEzZC00ODIzLThlYWQtZGU0ODQ5MmQ2MTM5LjUyNjBkZDU2LTJmZTctNDVjZS04ZWRlLTkxODQyMWVkNDRhZHgxNzkwODU5NjgyNjgyNzg1MTA1 parts=1218692026/10/01 13:01:23 INFO Received uploads request method=POST path=/api/pending_closures1870--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.99s)18712026/10/01 13:01:23 INFO lead: released remote=192.0.2.1:123418722026/10/01 13:01:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=856.157545ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18732026/10/01 13:01:23 INFO lead: acquired remote=192.0.2.1:12341874--- PASS: TestPendingClosureWriteTimeout (0.00s)1875 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1876 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1877 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1878 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.10s)18792026/10/01 13:01:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18802026/10/01 13:01:23 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGYzYjUyZjktOGEzZC00ODIzLThlYWQtZGU0ODQ5MmQ2MTM5LjYxZjY4ODQ4LWQyNjctNDdmZi04OTE2LWJjYzkxZDBlYmYxY3gxNzkwODU5NjgzMTEyNjg5NzM0 error="Get \"http://127.0.0.1:1/bucket70/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"18812026/10/01 13:01:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGYzYjUyZjktOGEzZC00ODIzLThlYWQtZGU0ODQ5MmQ2MTM5LjBiNmIxOWNlLWQyZTYtNDA0NC05YjNlLTI2NzQzZjcxNDgzYXgxNzkwODU5NjgzMTA2NDA1MTAw parts=1218822026/10/01 13:01:23 INFO Received cleanup request method=DELETE path=/api/pending_closures18832026/10/01 13:01:23 INFO Aborted multipart uploads count=1 kept=01884--- PASS: TestRedundantMultipartUpload (1.72s)18852026/10/01 13:01:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.458571148s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18862026/10/01 13:01:24 INFO lead: released remote=192.0.2.1:12341887--- PASS: TestLeadElectsOneAndHandsOver (2.95s)18882026/10/01 13:01:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018892026/10/01 13:01:24 INFO Received create pin request method=POST path=/api/pins/myapp18902026/10/01 13:01:24 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1249488608/001/store/zf464nynknpsxg8hy50610fgb2lpzbx2-pinned-file.txt narinfo_key=zf464nynknpsxg8hy50610fgb2lpzbx2.narinfo18912026/10/01 13:01:24 INFO Starting cleanup of old closures method=DELETE path=/api/closures18922026/10/01 13:01:24 INFO Garbage collection started18932026/10/01 13:01:24 INFO Aborted multipart uploads count=0 kept=018942026/10/01 13:01:24 WARN Force mode enabled - objects will be deleted immediately without grace period18952026/10/01 13:01:24 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=018962026/10/01 13:01:24 INFO Vacuumed table table=pending_closures18972026/10/01 13:01:24 INFO Vacuumed table table=pending_objects18982026/10/01 13:01:24 INFO Vacuumed table table=multipart_uploads18992026/10/01 13:01:24 INFO Vacuumed table table=closures19002026/10/01 13:01:24 INFO Vacuumed table table=objects19012026/10/01 13:01:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01902=== NAME TestClientIntegration1903 client_integration_test.go:323: Objects in database after GC:1904 client_integration_test.go:323: Successfully deleted all objects with GC --force1905--- PASS: TestClientIntegration (2.75s)19062026/10/01 13:01:25 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-config1907--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.79s)19082026/10/01 13:01:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.164223ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19092026/10/01 13:01:26 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=414.522346ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19102026/10/01 13:01:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=800.843203ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19112026/10/01 13:01:26 WARN Rate limiter enabled after throttle name=s3-test rate=519122026/10/01 13:01:26 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1913=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1914 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101915 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001916--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.82s)1917=== NAME TestPinProtectsFromGC1918 client_integration_test.go:840: Pin successfully protected closure from garbage collection1919--- PASS: TestPinProtectsFromGC (4.93s)1920--- PASS: TestConnectWaitsForAPeerMigration (5.15s)19212026/10/01 13:01:26 INFO Aborted multipart uploads count=1 kept=019222026/10/01 13:01:26 INFO Received cleanup request method=DELETE path=/api/pending_closures19232026/10/01 13:01:26 INFO Aborted multipart uploads count=1 kept=01924--- PASS: TestPendingCleanupUsesOneCutoff (6.78s)19252026/10/01 13:01:27 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.487423207s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19262026/10/01 13:01:28 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"19272026/10/01 13:01:28 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-config19282026/10/01 13:01:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.659497ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19292026/10/01 13:01:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=415.486571ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19302026/10/01 13:01:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=862.352922ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19312026/10/01 13:01:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.607049152s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19322026/10/01 13:01:31 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_closures19332026/10/01 13:01:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.789016ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19342026/10/01 13:01:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.731344ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19352026/10/01 13:01:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=780.624541ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19362026/10/01 13:01:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.611780715s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1937--- PASS: TestClientErrorHandling (0.00s)1938 --- PASS: TestClientErrorHandling/InvalidStorePath (0.40s)1939 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.47s)1940 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.36s)1941PASS1942{"timestamp":"2026-10-01T13:01:35.017723614Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:40498","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(399)"}19432026-10-01 13:01:35.375 UTC [130] LOG: received smart shutdown request19442026-10-01 13:01:35.380 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 119452026-10-01 13:01:35.394 UTC [135] LOG: shutting down19462026-10-01 13:01:35.395 UTC [135] LOG: checkpoint starting: shutdown immediate19472026-10-01 13:01:36.293 UTC [135] LOG: checkpoint complete: wrote 11048 buffers (67.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.276 s, sync=0.578 s, total=0.900 s; sync files=29992, longest=0.006 s, average=0.001 s; distance=414796 kB, estimate=414796 kB; lsn=0/1AC78E98, redo lsn=0/1AC78E9819482026-10-01 13:01:36.380 UTC [130] LOG: database system is shut down1949Running OIDC tests...1950=== RUN TestAudienceForIssuer1951=== PAUSE TestAudienceForIssuer1952=== RUN TestGlobMatch1953=== PAUSE TestGlobMatch1954=== RUN TestValidateToken_ValidToken1955=== PAUSE TestValidateToken_ValidToken1956=== RUN TestValidateToken_WrongAudience1957=== PAUSE TestValidateToken_WrongAudience1958=== RUN TestValidateToken_Expired1959=== PAUSE TestValidateToken_Expired1960=== RUN TestValidateToken_BoundClaimsMismatch1961=== PAUSE TestValidateToken_BoundClaimsMismatch1962=== RUN TestValidateToken_BoundSubjectMismatch1963=== PAUSE TestValidateToken_BoundSubjectMismatch1964=== RUN TestValidateToken_MultipleProviders1965=== PAUSE TestValidateToken_MultipleProviders1966=== RUN TestValidateToken_NoMatchingProvider1967=== PAUSE TestValidateToken_NoMatchingProvider1968=== RUN TestValidateToken_KubernetesServiceAccount1969=== PAUSE TestValidateToken_KubernetesServiceAccount1970=== RUN TestNewValidator_KubernetesRequiresCA1971=== PAUSE TestNewValidator_KubernetesRequiresCA1972=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1973=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1974=== RUN TestPins_ReservedForMatchingRule1975=== PAUSE TestPins_ReservedForMatchingRule1976=== RUN TestPins_TopLevelShorthand1977=== PAUSE TestPins_TopLevelShorthand1978=== RUN TestPins_ConfigValidation1979=== PAUSE TestPins_ConfigValidation1980=== RUN TestScopes_LegacyProviderDefaultsToWrite1981=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1982=== RUN TestScopes_Rules1983=== PAUSE TestScopes_Rules1984=== RUN TestScopes_ConfigValidation1985=== PAUSE TestScopes_ConfigValidation1986=== CONT TestAudienceForIssuer1987=== CONT TestValidateToken_KubernetesServiceAccount1988=== CONT TestScopes_Rules1989--- PASS: TestAudienceForIssuer (0.00s)1990=== CONT TestValidateToken_NoMatchingProvider1991=== CONT TestValidateToken_MultipleProviders1992=== CONT TestValidateToken_BoundSubjectMismatch1993=== CONT TestValidateToken_BoundClaimsMismatch1994=== CONT TestPins_ConfigValidation1995=== CONT TestValidateToken_Expired1996=== CONT TestValidateToken_WrongAudience1997--- PASS: TestPins_ConfigValidation (0.00s)1998=== CONT TestValidateToken_ValidToken1999=== CONT TestScopes_LegacyProviderDefaultsToWrite2000=== CONT TestGlobMatch2001=== RUN TestGlobMatch/foo_foo2002=== PAUSE TestGlobMatch/foo_foo2003=== RUN TestGlobMatch/foo_bar2004=== PAUSE TestGlobMatch/foo_bar2005=== RUN TestGlobMatch/*_2006=== PAUSE TestGlobMatch/*_2007=== RUN TestGlobMatch/*_anything2008=== PAUSE TestGlobMatch/*_anything2009=== RUN TestGlobMatch/foo*_foo2010=== PAUSE TestGlobMatch/foo*_foo2011=== RUN TestGlobMatch/foo*_foobar2012=== PAUSE TestGlobMatch/foo*_foobar2013=== RUN TestGlobMatch/foo*_bar2014=== PAUSE TestGlobMatch/foo*_bar2015=== RUN TestGlobMatch/*bar_bar2016=== CONT TestPins_ReservedForMatchingRule2017=== CONT TestScopes_ConfigValidation2018=== CONT TestPins_TopLevelShorthand2019=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2020=== CONT TestNewValidator_KubernetesRequiresCA2021=== PAUSE TestGlobMatch/*bar_bar2022=== RUN TestGlobMatch/*bar_foobar2023=== PAUSE TestGlobMatch/*bar_foobar2024=== RUN TestGlobMatch/*bar_foo2025=== PAUSE TestGlobMatch/*bar_foo2026=== RUN TestGlobMatch/foo*bar_foobar2027=== PAUSE TestGlobMatch/foo*bar_foobar2028=== RUN TestGlobMatch/foo*bar_foo123bar2029=== PAUSE TestGlobMatch/foo*bar_foo123bar2030=== RUN TestGlobMatch/foo*bar_foobarbaz2031=== PAUSE TestGlobMatch/foo*bar_foobarbaz2032=== RUN TestGlobMatch/*/*_foo/bar2033=== PAUSE TestGlobMatch/*/*_foo/bar2034=== RUN TestGlobMatch/*/*_foo2035=== PAUSE TestGlobMatch/*/*_foo2036=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2037=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2038=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02039=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02040=== RUN TestGlobMatch/refs/*/main_refs/heads/main2041=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2042=== RUN TestGlobMatch/fo?_foo2043=== PAUSE TestGlobMatch/fo?_foo2044=== RUN TestGlobMatch/fo?_fo2045=== PAUSE TestGlobMatch/fo?_fo2046=== RUN TestGlobMatch/fo?_fooo2047=== PAUSE TestGlobMatch/fo?_fooo2048=== RUN TestGlobMatch/?oo_foo2049=== PAUSE TestGlobMatch/?oo_foo2050=== RUN TestGlobMatch/?oo_boo2051=== PAUSE TestGlobMatch/?oo_boo2052=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2053=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2054=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2055=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2056=== CONT TestGlobMatch/foo_foo2057=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2058=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2059=== CONT TestGlobMatch/?oo_boo2060=== CONT TestGlobMatch/?oo_foo2061=== CONT TestGlobMatch/fo?_fooo2062=== CONT TestGlobMatch/fo?_fo2063=== CONT TestGlobMatch/fo?_foo2064=== CONT TestGlobMatch/refs/*/main_refs/heads/main2065=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02066=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2067=== CONT TestGlobMatch/*/*_foo2068=== CONT TestGlobMatch/*/*_foo/bar2069=== CONT TestGlobMatch/foo*bar_foobarbaz2070=== CONT TestGlobMatch/foo*bar_foo123bar2071=== CONT TestGlobMatch/foo*bar_foobar2072=== CONT TestGlobMatch/*bar_foo2073=== CONT TestGlobMatch/*bar_foobar2074=== CONT TestGlobMatch/*bar_bar2075=== CONT TestGlobMatch/foo*_bar2076=== CONT TestGlobMatch/foo*_foobar2077=== CONT TestGlobMatch/foo*_foo2078=== CONT TestGlobMatch/*_anything2079=== CONT TestGlobMatch/*_2080=== CONT TestGlobMatch/foo_bar2081--- PASS: TestGlobMatch (0.00s)2082 --- PASS: TestGlobMatch/foo_foo (0.00s)2083 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2084 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2085 --- PASS: TestGlobMatch/?oo_boo (0.00s)2086 --- PASS: TestGlobMatch/?oo_foo (0.00s)2087 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2088 --- PASS: TestGlobMatch/fo?_fo (0.00s)2089 --- PASS: TestGlobMatch/fo?_foo (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/refs/heads/*_refs/heads/main (0.00s)2093 --- PASS: TestGlobMatch/*/*_foo (0.00s)2094 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2095 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2096 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2097 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2098 --- PASS: TestGlobMatch/*bar_foo (0.00s)2099 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2100 --- PASS: TestGlobMatch/*bar_bar (0.00s)2101 --- PASS: TestGlobMatch/foo*_bar (0.00s)2102 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2103 --- PASS: TestGlobMatch/foo*_foo (0.00s)2104 --- PASS: TestGlobMatch/*_anything (0.00s)2105 --- PASS: TestGlobMatch/*_ (0.00s)2106 --- PASS: TestGlobMatch/foo_bar (0.00s)2107--- PASS: TestScopes_ConfigValidation (0.00s)21082026/10/01 13:01:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43813/oidc21092026/10/01 13:01:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42007/oidc2110--- PASS: TestValidateToken_ValidToken (0.03s)2111--- PASS: TestScopes_Rules (0.04s)21122026/10/01 13:01:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32875/oidc2113--- PASS: TestValidateToken_BoundSubjectMismatch (0.04s)21142026/10/01 13:01:38 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34801/oidc2115--- PASS: TestValidateToken_NoMatchingProvider (0.05s)21162026/10/01 13:01:38 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:398732117--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)21182026/10/01 13:01:38 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321192026/10/01 13:01:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42617/oidc2120--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)2121--- PASS: TestValidateToken_WrongAudience (0.07s)21222026/10/01 13:01:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44455/oidc2123--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)21242026/10/01 13:01:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35491/oidc2125--- PASS: TestPins_TopLevelShorthand (0.09s)21262026/10/01 13:01:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45603/oidc2127--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)21282026/10/01 13:01:38 http: TLS handshake error from 127.0.0.1:52904: remote error: tls: bad certificate2129--- PASS: TestNewValidator_KubernetesRequiresCA (0.10s)21302026/10/01 13:01:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36063/oidc2131--- PASS: TestPins_ReservedForMatchingRule (0.10s)21322026/10/01 13:01:38 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45481/oidc21332026/10/01 13:01:38 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34309/oidc2134--- PASS: TestValidateToken_MultipleProviders (0.12s)21352026/10/01 13:01:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37159/oidc2136--- PASS: TestValidateToken_Expired (0.19s)2137PASS2138Running hook tests...2139=== RUN TestSendPathsEmpty2140=== PAUSE TestSendPathsEmpty2141=== RUN TestQueueEnqueueAndFetch2142=== PAUSE TestQueueEnqueueAndFetch2143=== RUN TestQueueDeduplication2144=== PAUSE TestQueueDeduplication2145=== RUN TestQueueRemove2146=== PAUSE TestQueueRemove2147=== RUN TestQueueFetchBatchLimit2148=== PAUSE TestQueueFetchBatchLimit2149=== RUN TestQueueRetryMovesToBack2150=== PAUSE TestQueueRetryMovesToBack2151=== RUN TestQueueFetchRemoveLifecycle2152=== PAUSE TestQueueFetchRemoveLifecycle2153=== RUN TestQueueConcurrentWriters2154=== PAUSE TestQueueConcurrentWriters2155=== RUN TestQueueRemoveLargeClosure2156=== PAUSE TestQueueRemoveLargeClosure2157=== RUN TestServerClientIntegration2158=== PAUSE TestServerClientIntegration2159=== RUN TestServerQueueError2160=== PAUSE TestServerQueueError2161=== RUN TestGetListenerSocketActivation2162 server_test.go:210: === RUN TestGetListenerSocketActivation2163 --- PASS: TestGetListenerSocketActivation (0.00s)2164 PASS2165 2166--- PASS: TestGetListenerSocketActivation (0.01s)2167=== RUN TestDrainIsolatesPoisonPath2168=== PAUSE TestDrainIsolatesPoisonPath2169=== RUN TestRunNotBlockedByPoisonHead2170=== PAUSE TestRunNotBlockedByPoisonHead2171=== RUN TestDrainGivesUpWhenServerDown2172=== PAUSE TestDrainGivesUpWhenServerDown2173=== RUN TestFailedPathPrunedByLaterClosure2174=== PAUSE TestFailedPathPrunedByLaterClosure2175=== RUN TestWorkerUploadsAndRemoves2176=== PAUSE TestWorkerUploadsAndRemoves2177=== RUN TestWorkerSkipsGCdPaths2178=== PAUSE TestWorkerSkipsGCdPaths2179=== RUN TestWorkerPrunesClosureDeps2180=== PAUSE TestWorkerPrunesClosureDeps2181=== RUN TestDrainTimeout2182=== PAUSE TestDrainTimeout2183=== CONT TestSendPathsEmpty2184=== CONT TestServerQueueError2185=== CONT TestQueueRemoveLargeClosure2186--- PASS: TestSendPathsEmpty (0.00s)2187=== CONT TestQueueFetchBatchLimit2188=== CONT TestQueueRemove2189=== CONT TestQueueDeduplication21902026/10/01 13:01:38 ERROR Failed to queue paths error="permission denied" count=12191=== CONT TestQueueEnqueueAndFetch2192=== CONT TestWorkerUploadsAndRemoves2193=== CONT TestDrainTimeout2194=== CONT TestWorkerPrunesClosureDeps2195=== CONT TestWorkerSkipsGCdPaths2196=== CONT TestDrainGivesUpWhenServerDown2197=== CONT TestFailedPathPrunedByLaterClosure2198=== CONT TestRunNotBlockedByPoisonHead2199=== CONT TestDrainIsolatesPoisonPath2200=== CONT TestServerClientIntegration2201=== CONT TestQueueConcurrentWriters2202=== CONT TestQueueFetchRemoveLifecycle2203=== CONT TestQueueRetryMovesToBack2204--- PASS: TestServerQueueError (0.00s)2205--- PASS: TestServerClientIntegration (0.00s)22062026/10/01 13:01:38 INFO Uploading batch count=122072026/10/01 13:01:38 ERROR Upload failed error="upload failed" count=122082026/10/01 13:01:38 INFO Upload queue status pending=222092026/10/01 13:01:38 INFO Upload queue status pending=222102026/10/01 13:01:38 INFO Uploading batch count=122112026/10/01 13:01:38 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4141456446/002/nonexistent2212--- PASS: TestQueueRemove (0.02s)22132026/10/01 13:01:38 INFO Uploading batch count=12214--- PASS: TestQueueDeduplication (0.02s)22152026/10/01 13:01:38 INFO Uploading batch count=222162026/10/01 13:01:38 INFO Uploading batch count=42217--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22182026/10/01 13:01:38 INFO Upload queue status pending=222192026/10/01 13:01:38 ERROR Upload failed error="upload failed" count=422202026/10/01 13:01:38 INFO Uploading batch count=122212026/10/01 13:01:38 INFO Uploading batch count=222222026/10/01 13:01:38 INFO Uploading batch count=122232026/10/01 13:01:38 INFO Uploading batch count=222242026/10/01 13:01:38 ERROR Upload failed error="upload failed" count=222252026/10/01 13:01:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1672400496/002/a22262026/10/01 13:01:38 INFO Upload queue status pending=322272026/10/01 13:01:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3794766809/002/bbb2228--- PASS: TestQueueFetchBatchLimit (0.02s)22292026/10/01 13:01:38 INFO Uploading batch count=12230--- PASS: TestQueueRetryMovesToBack (0.02s)22312026/10/01 13:01:38 ERROR Upload failed error="upload failed" count=12232--- PASS: TestQueueEnqueueAndFetch (0.02s)22332026/10/01 13:01:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1672400496/002/b22342026/10/01 13:01:38 INFO Uploading batch count=222352026/10/01 13:01:38 ERROR Upload failed error="upload failed" count=222362026/10/01 13:01:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1672400496/002/c22372026/10/01 13:01:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1672400496/002/d22382026/10/01 13:01:38 INFO Uploading batch count=122392026/10/01 13:01:38 ERROR Upload failed error="upload failed" count=122402026/10/01 13:01:38 INFO Uploading batch count=222412026/10/01 13:01:38 INFO Uploading batch count=122422026/10/01 13:01:38 ERROR Upload failed error="upload failed" count=122432026/10/01 13:01:38 ERROR Upload failed error="upload failed" count=222442026/10/01 13:01:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1672400496/002/e22452026/10/01 13:01:38 INFO Uploading batch count=122462026/10/01 13:01:38 ERROR Upload failed error="upload failed" count=12247--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22482026/10/01 13:01:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1672400496/002/f22492026/10/01 13:01:38 ERROR Drain finished with paths left in queue remaining=122502026/10/01 13:01:38 ERROR Drain finished with paths left in queue remaining=102251--- PASS: TestDrainIsolatesPoisonPath (0.02s)2252--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2253--- PASS: TestWorkerPrunesClosureDeps (0.04s)2254--- PASS: TestWorkerSkipsGCdPaths (0.04s)2255--- PASS: TestWorkerUploadsAndRemoves (0.04s)2256--- PASS: TestQueueRemoveLargeClosure (0.08s)22572026/10/01 13:01:38 ERROR Upload failed error="context deadline exceeded" count=222582026/10/01 13:01:38 ERROR Drain finished with paths left in queue remaining=42259--- PASS: TestDrainTimeout (0.22s)2260--- PASS: TestQueueConcurrentWriters (0.38s)22612026/10/01 13:01:39 INFO Uploading batch count=122622026/10/01 13:01:39 INFO Uploading batch count=122632026/10/01 13:01:39 INFO Uploading batch count=122642026/10/01 13:01:39 ERROR Upload failed error="upload failed" count=122652026/10/01 13:01:39 INFO Uploading batch count=122662026/10/01 13:01:39 ERROR Upload failed error="upload failed" count=122672026/10/01 13:01:39 INFO Uploading batch count=122682026/10/01 13:01:39 ERROR Upload failed error="upload failed" count=122692026/10/01 13:01:39 INFO Uploading batch count=122702026/10/01 13:01:39 ERROR Upload failed error="upload failed" count=122712026/10/01 13:01:39 ERROR Drain finished with paths left in queue remaining=12272--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2273PASS