niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #356
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestRateLimiterFeedback102=== CONT TestSetClientTLSErrors103=== CONT TestStreamPushGivesUpOnDeadServer104=== CONT TestScriptTokenEmptyCommand105--- PASS: TestScriptTokenEmptyCommand (0.00s)106=== CONT TestStreamPushBatchesUnderLoad107=== CONT TestScriptTokenScriptFails108=== CONT TestScriptTokenBadJSON109=== CONT TestScriptTokenEmptyToken110=== CONT TestScriptTokenCachesUntilRefresh111=== CONT TestScriptTokenNoExpiryRerunsEveryCall1122026/10/04 20:06:39 ERROR Upload failed error="connection refused" count=201132026/10/04 20:06:39 ERROR Server seems unavailable, giving up on batch untried=17114=== CONT TestFileTokenEmpty115=== CONT TestFileTokenMissing116=== CONT TestFileTokenReadsAndCaches117=== CONT TestStaticToken118=== CONT TestDumpPathWriterError119=== CONT TestEncodeNixBase32120=== RUN TestEncodeNixBase32/test_string_hash121=== PAUSE TestEncodeNixBase32/test_string_hash122=== CONT TestResolveStorePath123=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess124=== CONT TestSetClientTLSDoesNotMutateDefaultTransport125=== CONT TestSetClientTLS126=== CONT TestClientSignaturesByStorePath127=== CONT TestStreamPushReportsSignatures128=== CONT TestStreamPushRequestLine129=== CONT TestStreamPushIsolatesFailures130=== RUN TestRateLimiterFeedback/429_enables_limiter131--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)132=== CONT TestUploadMultipart_PartsInParallel133=== CONT TestDumpPathSingleFile1342026/10/04 20:06:39 WARN Rate limiter enabled after throttle name=server-test rate=51352026/10/04 20:06:39 WARN Rate limiter enabled after throttle name=server-test rate=51362026/10/04 20:06:39 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43289137--- PASS: TestStaticToken (0.00s)1382026/10/04 20:06:39 ERROR Upload failed error="bad path" count=3139--- PASS: TestScriptTokenBadJSON (0.00s)140--- PASS: TestScriptTokenScriptFails (0.00s)141--- PASS: TestFileTokenEmpty (0.00s)142--- PASS: TestFileTokenReadsAndCaches (0.00s)143--- PASS: TestScriptTokenEmptyToken (0.01s)144=== RUN TestEncodeNixBase32/empty_input145=== PAUSE TestRateLimiterFeedback/429_enables_limiter146=== CONT TestParsePathInfoJSONMultiplePaths1472026/10/04 20:06:39 ERROR Upload failed error=boom count=1148=== CONT TestParsePathInfoJSON149=== RUN TestRateLimiterFeedback/503_enables_limiter1502026/10/04 20:06:39 ERROR Upload failed error=boom count=1151=== PAUSE TestEncodeNixBase32/empty_input152=== CONT TestPartSizeForNAR153=== CONT TestDumpPathMatchesNix154=== CONT TestPathInfoHashCompatibility155=== CONT TestPathInfoCACompatibility156--- PASS: TestClientSignaturesByStorePath (0.00s)1572026/10/04 20:06:39 WARN Rate limiter backed off name=server-test rate=51582026/10/04 20:06:39 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43289159=== RUN TestSetClientTLSErrors/missing_cert_file160=== PAUSE TestSetClientTLSErrors/missing_cert_file161=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths162=== CONT TestFilterOversizedClosures163=== RUN TestParsePathInfoJSON/Nix_format164=== CONT TestUploadMultipart_SupersededByPeer165=== PAUSE TestRateLimiterFeedback/503_enables_limiter166=== CONT TestConvertHashToNix32167=== CONT TestGetStorePathHash168--- PASS: TestStreamPushIsolatesFailures (0.00s)169=== RUN TestPartSizeForNAR/zero_stays_at_minimum170=== RUN TestFilterOversizedClosures/no_limit_keeps_everything171=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything172=== RUN TestConvertHashToNix32/SRI_format_to_Nix32173=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32174=== RUN TestConvertHashToNix32/already_Nix32_format175=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum176=== CONT TestEncodeNixBase32WithRealHash177=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica178=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped179=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped180=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)181=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)182=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon183=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon184=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI185=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI186=== RUN TestPathInfoCACompatibility/null_ca_field187=== CONT TestCaseHackSuffix188=== RUN TestSetClientTLSErrors/missing_key_file189=== PAUSE TestSetClientTLSErrors/missing_key_file190=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths191=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths192=== PAUSE TestParsePathInfoJSON/Nix_format193=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun194=== RUN TestUploadMultipart_SupersededByPeer/exists195--- PASS: TestDoServerRequestAttachesToken (0.01s)196=== RUN TestGetStorePathHash/valid_store_path197=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter198=== PAUSE TestConvertHashToNix32/already_Nix32_format199=== RUN TestPartSizeForNAR/small_stays_at_minimum200=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512201=== PAUSE TestPathInfoCACompatibility/null_ca_field202=== CONT TestShellSplitErrors203=== RUN TestSetClientTLSErrors/missing_ca_file204=== CONT TestShellSplit205=== PAUSE TestSetClientTLSErrors/missing_ca_file206=== CONT TestRegisterUploadedObjectReusesConnections207=== RUN TestSetClientTLSErrors/invalid_ca_file208=== PAUSE TestSetClientTLSErrors/invalid_ca_file209=== RUN TestSetClientTLS/rejects_connection_without_client_cert210=== RUN TestFilterOversizedClosures/all_closures_skipped211=== RUN TestParsePathInfoJSON/Lix_format212=== PAUSE TestParsePathInfoJSON/Lix_format213=== RUN TestParsePathInfoJSON/empty_input214=== PAUSE TestParsePathInfoJSON/empty_input215=== RUN TestParsePathInfoJSON/whitespace_only216=== PAUSE TestParsePathInfoJSON/whitespace_only217=== RUN TestParsePathInfoJSON/invalid_JSON218=== PAUSE TestParsePathInfoJSON/invalid_JSON219=== PAUSE TestUploadMultipart_SupersededByPeer/exists220=== RUN TestUploadMultipart_SupersededByPeer/missing221=== PAUSE TestUploadMultipart_SupersededByPeer/missing222=== CONT TestEncodeNixBase32/test_string_hash223=== CONT TestSetClientTLSErrors/missing_cert_file224=== CONT TestSetClientTLSErrors/invalid_ca_file225=== CONT TestSetClientTLSErrors/missing_ca_file226=== CONT TestSetClientTLSErrors/missing_key_file227=== CONT TestParsePathInfoJSON/Nix_format228=== CONT TestUploadMultipart_SupersededByPeer/exists2292026/10/04 20:06:39 INFO Garbage collection started230--- PASS: TestStreamPushReportsSignatures (0.00s)2312026/10/04 20:06:39 INFO Garbage collection started232--- PASS: TestFileTokenMissing (0.00s)233--- PASS: TestResolveStorePath (0.00s)234--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)235--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)236--- PASS: TestEncodeNixBase32WithRealHash (0.00s)237--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)238--- PASS: TestShellSplitErrors (0.00s)239--- PASS: TestShellSplit (0.00s)240=== CONT TestEncodeNixBase32/empty_input241--- PASS: TestEncodeNixBase32 (0.00s)242 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)243 --- PASS: TestEncodeNixBase32/empty_input (0.00s)244=== PAUSE TestGetStorePathHash/valid_store_path245=== RUN TestGetStorePathHash/basename_without_hyphen_should_error246=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error247=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error248=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error249=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error250=== CONT TestParsePathInfoJSON/invalid_JSON251=== CONT TestParsePathInfoJSON/whitespace_only252=== CONT TestParsePathInfoJSON/empty_input253=== CONT TestParsePathInfoJSON/Lix_format254--- PASS: TestParsePathInfoJSON (0.03s)255 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)256 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)257 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)258 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)259 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)260=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error261=== CONT TestGetStorePathHash/valid_store_path262=== CONT TestUploadMultipart_SupersededByPeer/missing2632026/10/04 20:06:39 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0264=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error265=== CONT TestGetStorePathHash/basename_without_hyphen_should_error266=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error267=== PAUSE TestPartSizeForNAR/small_stays_at_minimum268=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512269=== RUN TestPathInfoCACompatibility/old_string_format_-_text270=== CONT TestStreamPushReportsEveryPath271=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert272=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)273=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text274=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive275=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive276=== PAUSE TestFilterOversizedClosures/all_closures_skipped277=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter278=== RUN TestConvertHashToNix32/invalid_format279--- PASS: TestGetStorePathHash (0.01s)280 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)281 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)282 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)283 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)284=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum285=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum286=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts287=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts288=== RUN TestPartSizeForNAR/1_TiB289=== PAUSE TestPartSizeForNAR/1_TiB290=== RUN TestPartSizeForNAR/5_TiB_S3_max_object291=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object292=== RUN TestPartSizeForNAR/capped_at_5_GiB293=== PAUSE TestPartSizeForNAR/capped_at_5_GiB294=== PAUSE TestConvertHashToNix32/invalid_format295--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)296 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)297 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)298=== CONT TestPartSizeForNAR/zero_stays_at_minimum299=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512300=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI301=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon302=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA303=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths304=== CONT TestPartSizeForNAR/capped_at_5_GiB305=== CONT TestPartSizeForNAR/5_TiB_S3_max_object306=== CONT TestFilterOversizedClosures/no_limit_keeps_everything307=== CONT TestPartSizeForNAR/1_TiB308=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum309=== RUN TestPathInfoCACompatibility/new_structured_format_-_text310=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter311=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts312--- PASS: TestStreamPushReportsEveryPath (0.00s)313=== CONT TestPartSizeForNAR/small_stays_at_minimum314--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)315=== CONT TestConvertHashToNix32/invalid_format316=== CONT TestConvertHashToNix32/already_Nix32_format317=== CONT TestFilterOversizedClosures/all_closures_skipped318=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths3192026/10/04 20:06:39 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50320=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths321=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text322=== CONT TestConvertHashToNix32/SRI_format_to_Nix32323=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method324=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method325=== CONT TestPathInfoCACompatibility/null_ca_field3262026/10/04 20:06:39 WARN Garbage collection finished on another replica. Its statistics are not available here327=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA328=== CONT TestPathInfoCACompatibility/old_string_format_-_text329=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter330=== RUN TestSetClientTLS/preserves_debug_logging_transport331=== CONT TestRateLimiterFeedback/429_enables_limiter332=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive333=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method334=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3352026/10/04 20:06:39 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=2000336--- PASS: TestSetClientTLSErrors (0.04s)337 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)338 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)339 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)340 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)341=== PAUSE TestSetClientTLS/preserves_debug_logging_transport342=== CONT TestSetClientTLS/rejects_connection_without_client_cert343=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter344=== CONT TestSetClientTLS/preserves_debug_logging_transport345=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3462026/10/04 20:06:39 WARN Rate limiter enabled after throttle name=server-test rate=53472026/10/04 20:06:39 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:42417348=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA349=== CONT TestPathInfoCACompatibility/new_structured_format_-_text3502026/10/04 20:06:39 WARN Rate limiter backed off name=server-test rate=5351=== CONT TestRateLimiterFeedback/503_enables_limiter352--- PASS: TestPathInfoHashCompatibility (0.01s)353 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)354 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)355 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)356 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)357--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)358--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)359--- PASS: TestDumpPathSingleFile (0.05s)3602026/10/04 20:06:39 WARN Rate limiter enabled after throttle name=server-test rate=5361--- PASS: TestPartSizeForNAR (0.01s)362 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)364 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)365 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)368 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)3692026/10/04 20:06:39 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:42023370--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)371 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)372 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)373--- PASS: TestConvertHashToNix32 (0.01s)374 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)375 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)376 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)377--- PASS: TestFilterOversizedClosures (0.01s)378 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)379 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)380 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)381--- PASS: TestPathInfoCACompatibility (0.01s)382 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)383 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)384 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)385 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)386 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)3872026/10/04 20:06:39 WARN Rate limiter backed off name=server-test rate=5388--- PASS: TestRateLimiterFeedback (0.05s)389 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)390 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)391 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)392 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)393--- PASS: TestStreamPushRequestLine (0.06s)3942026/10/04 20:06:39 http: TLS handshake error from 127.0.0.1:40058: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.04s)396 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)397 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)399--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)400--- PASS: TestDumpPathWriterError (0.07s)401--- PASS: TestCaseHackSuffix (0.04s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.09s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres1435357366/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: 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.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres1435357366/data -l logfile start434435/build/postgres1435357366:5432 - no response4362026-10-04 20:06:41.560 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-04 20:06:41.560 UTC [128] LOG: listening on Unix socket "/build/postgres1435357366/.s.PGSQL.5432"4382026-10-04 20:06:41.566 UTC [135] LOG: database system was shut down at 2026-10-04 20:06:41 UTC4392026-10-04 20:06:41.569 UTC [128] LOG: database system is ready to accept connections440/build/postgres1435357366:5432 - accepting connections441{"timestamp":"2026-10-04T20:06:41.866239833Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b39ee4e5-2d9b-4761-939f-364617d617af","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(393)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== RUN TestResolveDBConnectionString481=== PAUSE TestResolveDBConnectionString482=== RUN TestConnectWaitsForAPeerMigration483=== PAUSE TestConnectWaitsForAPeerMigration484=== RUN TestLeadElectsOneAndHandsOver485=== PAUSE TestLeadElectsOneAndHandsOver486=== RUN TestLeadIncumbentWinsAfterRestart4872026/10/04 20:06:42 INFO lead: acquired remote=192.0.2.1:12344882026/10/04 20:06:43 INFO lead: released remote=192.0.2.1:12344892026/10/04 20:06:43 INFO lead: acquired remote=192.0.2.1:12344902026/10/04 20:06:44 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (2.36s)492=== RUN TestLeadEndsOnShutdown493=== PAUSE TestLeadEndsOnShutdown494=== RUN TestLeadEndsWhenItsConnectionHangs4952026/10/04 20:06:44 INFO lead: acquired remote=192.0.2.1:12344962026-10-04 20:06:45.841 UTC [576] FATAL: terminating connection due to administrator command4972026/10/04 20:06:46 INFO lead: acquired remote=192.0.2.1:12344982026/10/04 20:06:47 WARN lead: lock connection lost error="timeout: context deadline exceeded"4992026/10/04 20:06:47 INFO lead: released remote=192.0.2.1:12345002026/10/04 20:06:47 INFO lead: released remote=192.0.2.1:1234501--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)502=== RUN TestGCAdvisoryLockBlocksConcurrentRun503=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun504=== RUN TestGCBugBareHashReferences505=== PAUSE TestGCBugBareHashReferences506=== RUN TestGCMetrics507=== PAUSE TestGCMetrics508=== RUN TestPushDedupSurvivesConcurrentGC509=== PAUSE TestPushDedupSurvivesConcurrentGC510=== RUN TestDeduplicatedObjectsRecordedAsPending511=== PAUSE TestDeduplicatedObjectsRecordedAsPending512=== RUN TestGCSweepSkipsPendingObjects513=== PAUSE TestGCSweepSkipsPendingObjects514=== RUN TestTombstonedObjectOfferedWithoutWaiting515=== PAUSE TestTombstonedObjectOfferedWithoutWaiting516=== RUN TestGCSweepDeliversEachKeyOnce517=== PAUSE TestGCSweepDeliversEachKeyOnce518=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection519=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection520=== RUN TestForceGCDuringPushOffersSweptObject521=== PAUSE TestForceGCDuringPushOffersSweptObject522=== RUN TestFailedS3DeleteKeepsTombstone523=== PAUSE TestFailedS3DeleteKeepsTombstone524=== RUN TestSweepSkipsRowsLockedByPush525=== PAUSE TestSweepSkipsRowsLockedByPush526=== RUN TestRegisterCompletedObjectNeedsPendingRow527=== PAUSE TestRegisterCompletedObjectNeedsPendingRow528=== RUN TestGetExistingObjectsLocksRows529=== PAUSE TestGetExistingObjectsLocksRows530=== RUN TestSweepRechecksPendingAfterLocking531=== PAUSE TestSweepRechecksPendingAfterLocking532=== RUN TestPushWaitsForSweepHoldingRow533=== PAUSE TestPushWaitsForSweepHoldingRow534=== RUN TestCommitRacingPendingCleanupKeepsObjects535=== PAUSE TestCommitRacingPendingCleanupKeepsObjects536=== RUN TestGCEndsOnShutdown537=== PAUSE TestGCEndsOnShutdown538=== RUN TestGCTaskStore_StartNew539=== PAUSE TestGCTaskStore_StartNew540=== RUN TestGCTaskStore_DeduplicateSameParams541=== PAUSE TestGCTaskStore_DeduplicateSameParams542=== RUN TestGCTaskStore_ConflictDifferentParams543=== PAUSE TestGCTaskStore_ConflictDifferentParams544=== RUN TestGCTaskStore_GetEmpty545=== PAUSE TestGCTaskStore_GetEmpty546=== RUN TestGCTaskStore_GetReturnsLatest547=== PAUSE TestGCTaskStore_GetReturnsLatest548=== RUN TestGCTaskStore_CompletedAllowsNewTask549=== PAUSE TestGCTaskStore_CompletedAllowsNewTask550=== RUN TestGCTaskStore_PhaseUpdates551=== PAUSE TestGCTaskStore_PhaseUpdates552=== RUN TestGCTaskStore_Fail553=== PAUSE TestGCTaskStore_Fail554=== RUN TestGracefulShutdownDrainsInflight555=== PAUSE TestGracefulShutdownDrainsInflight556=== RUN TestService_healthCheckHandler557=== PAUSE TestService_healthCheckHandler558=== RUN TestService_readinessHandler559=== PAUSE TestService_readinessHandler560=== RUN TestGenerateLandingPage561=== PAUSE TestGenerateLandingPage562=== RUN TestCacheConfigHandlerMaxNarSize563=== PAUSE TestCacheConfigHandlerMaxNarSize564=== RUN TestCreatePendingClosureRejectsOversizedNAR565=== PAUSE TestCreatePendingClosureRejectsOversizedNAR566=== RUN TestNARDeduplicationMetadataUploadBug567=== PAUSE TestNARDeduplicationMetadataUploadBug568=== RUN TestMetricsInventory569=== PAUSE TestMetricsInventory570=== RUN TestService_NativeMTLS571=== PAUSE TestService_NativeMTLS572=== RUN TestServerTLSConfig573=== PAUSE TestServerTLSConfig574=== RUN TestMultipartCleanup575=== PAUSE TestMultipartCleanup576=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded577=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded578=== RUN TestPendingCleanupUsesOneCutoff579=== PAUSE TestPendingCleanupUsesOneCutoff580=== RUN TestObjectStatsTrigger581=== PAUSE TestObjectStatsTrigger582=== RUN TestOrphanedObjectsGC583=== PAUSE TestOrphanedObjectsGC584=== RUN TestOrphanedObjectsGCStressTest585=== PAUSE TestOrphanedObjectsGCStressTest586=== RUN TestCreatePin_ReservedPins587=== PAUSE TestCreatePin_ReservedPins588=== RUN TestPresentReportsOnlyClosureRoots589=== PAUSE TestPresentReportsOnlyClosureRoots590=== RUN TestPresentNotReportedWhileGCDeletesClosure591=== PAUSE TestPresentNotReportedWhileGCDeletesClosure592=== RUN TestParseSingleRange593=== PAUSE TestParseSingleRange594=== RUN TestProxyHeadersOnlyTrustedOnSocket595=== PAUSE TestProxyHeadersOnlyTrustedOnSocket596=== RUN TestIsValidCachePath597=== PAUSE TestIsValidCachePath598=== RUN TestReadProxyNarinfo599=== PAUSE TestReadProxyNarinfo600=== RUN TestReadProxyNarinfoAlreadyDecompressed601=== PAUSE TestReadProxyNarinfoAlreadyDecompressed602=== RUN TestReadProxyNarStreaming603=== PAUSE TestReadProxyNarStreaming604=== RUN TestReadProxy404605=== PAUSE TestReadProxy404606=== RUN TestReadProxyInvalidPath607=== PAUSE TestReadProxyInvalidPath608=== RUN TestReadProxyHead609=== PAUSE TestReadProxyHead610=== RUN TestReadProxyOutlastsServerWriteTimeout611=== PAUSE TestReadProxyOutlastsServerWriteTimeout612=== RUN TestReadProxyConditionalGet613=== PAUSE TestReadProxyConditionalGet614=== RUN TestReadProxyRootRedirectsToIndexHTML615=== PAUSE TestReadProxyRootRedirectsToIndexHTML616=== RUN TestReadProxyDisabled617=== PAUSE TestReadProxyDisabled618=== RUN TestReadRedirectNar619=== PAUSE TestReadRedirectNar620=== RUN TestReadRedirectKeepsNarinfoProxied621=== PAUSE TestReadRedirectKeepsNarinfoProxied622=== RUN TestReadProxyRangeRequest623=== PAUSE TestReadProxyRangeRequest624=== RUN TestReadRedirectUsesPublicS3URL625=== PAUSE TestReadRedirectUsesPublicS3URL626=== RUN TestPush_OverlappingRootsStoreOneRowPerKey627=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey628=== RUN TestPush_CompleteCommitsEveryRoot629=== PAUSE TestPush_CompleteCommitsEveryRoot630=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit631=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit632=== RUN TestPush_RejectsBadRequests633=== PAUSE TestPush_RejectsBadRequests634=== RUN TestPush_SignsNarinfosOfItsPendingObjects635=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects636=== RUN TestRedundantMultipartUpload637=== PAUSE TestRedundantMultipartUpload638=== RUN TestCompleteMultipartUpload_ErrorButObjectExists639=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists640=== RUN TestCompletedNarNotReofferedAcrossClosures641=== PAUSE TestCompletedNarNotReofferedAcrossClosures642=== RUN TestPresignedUploadRegisteredBeforeCommit643=== PAUSE TestPresignedUploadRegisteredBeforeCommit644=== RUN TestService_Rustfstest645=== PAUSE TestService_Rustfstest646=== RUN TestParseSize647=== PAUSE TestParseSize648=== RUN TestSkippedUploadsHandler649=== PAUSE TestSkippedUploadsHandler650=== RUN TestSystemdListenerNotActivated651--- PASS: TestSystemdListenerNotActivated (0.00s)652=== RUN TestWatchdogBeatsWhenHealthy653--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)654=== RUN TestWatchdogSkipsWhenUnhealthy6552026/10/04 20:06:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/04 20:06:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/04 20:06:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/04 20:06:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/04 20:06:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/04 20:06:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/04 20:06:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/04 20:06:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/04 20:06:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/04 20:06:47 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"665--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)666=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle667=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle668=== RUN TestProxyWriteTimeout669=== PAUSE TestProxyWriteTimeout670=== RUN TestPendingClosureWriteTimeout671=== PAUSE TestPendingClosureWriteTimeout672=== RUN TestIsValidUploadKey673=== PAUSE TestIsValidUploadKey674=== RUN TestUploadHandlersRejectInvalidKeys675=== PAUSE TestUploadHandlersRejectInvalidKeys676=== RUN TestUploadHandlersRejectOversizedBody677=== PAUSE TestUploadHandlersRejectOversizedBody678=== RUN TestService_cleanupPendingClosuresHandler679=== PAUSE TestService_cleanupPendingClosuresHandler680=== RUN TestService_createPendingClosureHandler681=== PAUSE TestService_createPendingClosureHandler682=== RUN TestService_verifyS3Integrity683=== PAUSE TestService_verifyS3Integrity684=== RUN TestCompleteMultipartUnregistered685=== PAUSE TestCompleteMultipartUnregistered686=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT687=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT688=== CONT TestService_AuthMiddleware689=== CONT TestService_createPendingClosureHandler690=== CONT TestDeduplicatedObjectsRecordedAsPending691=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT692=== CONT TestCompleteMultipartUnregistered693=== CONT TestService_verifyS3Integrity694=== CONT TestCacheConfigHandlerMaxNarSize695=== CONT TestGenerateLandingPage696=== CONT TestService_readinessHandler697=== CONT TestService_healthCheckHandler698=== CONT TestGracefulShutdownDrainsInflight6992026/10/04 20:06:47 INFO Starting HTTP server address=127.0.0.1:367697002026/10/04 20:06:47 INFO Shutdown signal received, draining in-flight requests timeout=10s701=== CONT TestGCTaskStore_Fail702=== CONT TestRegisterCompletedObjectNeedsPendingRow703=== CONT TestGCTaskStore_PhaseUpdates704=== CONT TestGCTaskStore_CompletedAllowsNewTask705=== CONT TestFailedS3DeleteKeepsTombstone706=== CONT TestGCTaskStore_GetReturnsLatest707=== CONT TestGCTaskStore_GetEmpty708=== CONT TestGCTaskStore_ConflictDifferentParams709=== CONT TestGCTaskStore_DeduplicateSameParams710=== CONT TestGCTaskStore_StartNew711=== CONT TestGCEndsOnShutdown712=== CONT TestCommitRacingPendingCleanupKeepsObjects713=== CONT TestPushWaitsForSweepHoldingRow714=== CONT TestSweepRechecksPendingAfterLocking715=== CONT TestCreatePendingClosureRejectsOversizedNAR716--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)717=== CONT TestGetExistingObjectsLocksRows718=== CONT TestSweepSkipsRowsLockedByPush719=== CONT TestForceGCDuringPushOffersSweptObject720=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows721=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows722=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check723=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check724=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection725=== CONT TestPushDedupSurvivesConcurrentGC7262026/10/04 20:06:47 INFO Received uploads request method=POST path=/api/pending_closures727--- PASS: TestGCTaskStore_Fail (0.00s)728--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)729=== CONT TestTombstonedObjectOfferedWithoutWaiting730=== CONT TestGCSweepSkipsPendingObjects731=== CONT TestClientSharedPathCommittedMidPush732=== RUN TestGCEndsOnShutdown/before_the_run733=== CONT TestGCSweepDeliversEachKeyOnce734=== CONT TestGCMetrics735=== PAUSE TestGCEndsOnShutdown/before_the_run736=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete737=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete738=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark739=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark740=== CONT TestGCBugBareHashReferences741--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)742--- PASS: TestGenerateLandingPage (0.00s)743--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)744--- PASS: TestGCTaskStore_GetEmpty (0.00s)745--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)746--- PASS: TestGCTaskStore_StartNew (0.00s)747--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)748--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)749--- PASS: TestGracefulShutdownDrainsInflight (0.07s)750=== CONT TestGCAdvisoryLockBlocksConcurrentRun7512026/10/04 20:06:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7522026/10/04 20:06:47 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst753--- PASS: TestCompleteMultipartUnregistered (0.38s)754=== CONT TestLeadEndsOnShutdown7552026/10/04 20:06:47 INFO Received uploads request method=POST path=/api/pending_closures7562026/10/04 20:06:47 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"757--- PASS: TestService_AuthMiddleware (0.43s)758=== CONT TestLeadElectsOneAndHandsOver7592026/10/04 20:06:47 INFO Received uploads request method=POST path=/api/pending_closures760--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.49s)761=== CONT TestConnectWaitsForAPeerMigration7622026/10/04 20:06:47 INFO Received uploads request method=POST path=/api/pending_closures7632026/10/04 20:06:47 INFO Received uploads request method=POST path=/api/pending_closures7642026/10/04 20:06:47 INFO Received uploads request method=POST path=/api/pending_closures7652026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=07662026/10/04 20:06:48 WARN Force mode enabled - objects will be deleted immediately without grace period7672026/10/04 20:06:48 INFO Received uploads request method=POST path=/api/pending_closures7682026/10/04 20:06:48 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=07692026/10/04 20:06:48 INFO Vacuumed table table=pending_closures770--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.56s)771=== CONT TestResolveDBConnectionString7722026/10/04 20:06:48 INFO Vacuumed table table=pending_objects773=== RUN TestResolveDBConnectionString/flag_wins7742026/10/04 20:06:48 INFO Vacuumed table table=multipart_uploads775=== PAUSE TestResolveDBConnectionString/flag_wins776=== RUN TestResolveDBConnectionString/file_when_flag_empty777=== PAUSE TestResolveDBConnectionString/file_when_flag_empty7782026/10/04 20:06:48 INFO Vacuumed table table=closures779=== RUN TestResolveDBConnectionString/missing_file_is_an_error780=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error781=== RUN TestResolveDBConnectionString/PGHOST_allows_empty782=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty783=== RUN TestResolveDBConnectionString/nothing_configured784=== PAUSE TestResolveDBConnectionString/nothing_configured785=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock7862026/10/04 20:06:48 INFO Vacuumed table table=objects787--- PASS: TestSweepRechecksPendingAfterLocking (0.55s)788=== CONT TestClientFallsBackToClosures7892026/10/04 20:06:48 INFO Received uploads request method=POST path=/api/pending_closures7902026/10/04 20:06:48 WARN readiness check failed error="closed pool"791--- PASS: TestService_readinessHandler (0.63s)792=== CONT TestClientPushesUseOnePush7932026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=07942026/10/04 20:06:48 WARN Force mode enabled - objects will be deleted immediately without grace period7952026/10/04 20:06:48 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=07962026/10/04 20:06:48 INFO Vacuumed table table=pending_closures7972026/10/04 20:06:48 INFO Vacuumed table table=pending_objects7982026/10/04 20:06:48 INFO Vacuumed table table=multipart_uploads7992026/10/04 20:06:48 INFO Vacuumed table table=closures8002026/10/04 20:06:48 INFO Vacuumed table table=objects8012026/10/04 20:06:48 INFO Received uploads request method=POST path=/api/pending_closures802--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.66s)803=== CONT TestPinProtectsFromGC8042026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=08052026/10/04 20:06:48 WARN Force mode enabled - objects will be deleted immediately without grace period8062026/10/04 20:06:48 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=08072026/10/04 20:06:48 INFO Vacuumed table table=pending_closures8082026/10/04 20:06:48 INFO Vacuumed table table=pending_objects809--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.71s)8102026/10/04 20:06:48 INFO Vacuumed table table=multipart_uploads811=== CONT TestCacheConfigHandler8122026/10/04 20:06:48 INFO Vacuumed table table=closures813=== RUN TestCacheConfigHandler/full_config,_no_issuer814=== PAUSE TestCacheConfigHandler/full_config,_no_issuer815=== RUN TestCacheConfigHandler/no_cache_url_configured816=== PAUSE TestCacheConfigHandler/no_cache_url_configured817=== RUN TestCacheConfigHandler/no_signing_keys818=== PAUSE TestCacheConfigHandler/no_signing_keys819=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator820=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator821=== CONT TestClientWithDependencies8222026/10/04 20:06:48 INFO Vacuumed table table=objects8232026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=08242026/10/04 20:06:48 WARN Force mode enabled - objects will be deleted immediately without grace period8252026/10/04 20:06:48 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=08262026/10/04 20:06:48 INFO Vacuumed table table=pending_closures8272026/10/04 20:06:48 INFO Vacuumed table table=pending_objects8282026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=08292026/10/04 20:06:48 INFO Vacuumed table table=multipart_uploads8302026/10/04 20:06:48 INFO Vacuumed table table=closures8312026/10/04 20:06:48 WARN Force mode enabled - objects will be deleted immediately without grace period8322026/10/04 20:06:48 INFO Vacuumed table table=objects833--- PASS: TestSweepSkipsRowsLockedByPush (0.74s)834=== CONT TestClientMultipleUploads8352026/10/04 20:06:48 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8362026/10/04 20:06:48 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."837--- PASS: TestFailedS3DeleteKeepsTombstone (0.75s)838=== CONT TestClientIntegration8392026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=08402026/10/04 20:06:48 WARN Force mode enabled - objects will be deleted immediately without grace period841--- PASS: TestGetExistingObjectsLocksRows (0.77s)842=== CONT TestClientErrorHandling843=== RUN TestClientErrorHandling/InvalidStorePath844=== PAUSE TestClientErrorHandling/InvalidStorePath845=== RUN TestClientErrorHandling/InvalidAuthToken846=== PAUSE TestClientErrorHandling/InvalidAuthToken847=== RUN TestClientErrorHandling/ServerNotAvailable848=== PAUSE TestClientErrorHandling/ServerNotAvailable849=== CONT TestClientCADerivations8502026/10/04 20:06:48 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=08512026/10/04 20:06:48 INFO Vacuumed table table=pending_closures8522026/10/04 20:06:48 INFO Vacuumed table table=pending_objects8532026/10/04 20:06:48 INFO Vacuumed table table=multipart_uploads8542026/10/04 20:06:48 INFO Vacuumed table table=closures8552026/10/04 20:06:48 INFO Vacuumed table table=objects856--- PASS: TestGCSweepDeliversEachKeyOnce (0.80s)857=== CONT TestCacheStatsHandler858--- PASS: TestService_healthCheckHandler (0.82s)859=== CONT TestService_AuthMiddleware_OIDC8602026/10/04 20:06:48 INFO Received uploads request method=POST path=/api/pending_closures8612026/10/04 20:06:48 INFO Received uploads request method=POST path=/api/pending_closures8622026/10/04 20:06:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34683/oidc863--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.85s)864=== CONT TestService_ReadScope_PublicByDefault8652026/10/04 20:06:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8662026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=08672026/10/04 20:06:48 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=08682026/10/04 20:06:48 INFO Vacuumed table table=pending_closures8692026/10/04 20:06:48 INFO Vacuumed table table=pending_objects8702026/10/04 20:06:48 INFO Vacuumed table table=multipart_uploads8712026/10/04 20:06:48 INFO Vacuumed table table=closures8722026/10/04 20:06:48 INFO Vacuumed table table=objects8732026/10/04 20:06:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NWNkMGM0ZDktOTk1NS00N2EwLWE5MTUtNzcwMjUwODkxZTQ0LmVhYzg0ZjEwLTYwZTEtNDJmOS05MzYwLTI0MjUwZjk5ZmNlNHgxNzkxMTQ0NDA3ODg5NjgwNTAy parts=108742026/10/04 20:06:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8752026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=08762026/10/04 20:06:48 INFO Completed upload id=18772026/10/04 20:06:48 WARN Force mode enabled - objects will be deleted immediately without grace period8782026/10/04 20:06:48 INFO Received uploads request method=POST path=/api/pending_closures8792026/10/04 20:06:48 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=08802026/10/04 20:06:48 INFO Vacuumed table table=pending_closures8812026/10/04 20:06:48 INFO Received uploads request method=POST path=/api/pending_closures8822026/10/04 20:06:48 INFO Vacuumed table table=pending_objects8832026/10/04 20:06:48 INFO Vacuumed table table=multipart_uploads8842026/10/04 20:06:48 INFO Vacuumed table table=closures8852026/10/04 20:06:48 INFO Vacuumed table table=objects8862026/10/04 20:06:48 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8872026/10/04 20:06:48 WARN Found objects in DB but missing from S3, will re-upload count=1888--- PASS: TestService_verifyS3Integrity (0.94s)889=== CONT TestService_RequireScope_OIDC890--- PASS: TestPushDedupSurvivesConcurrentGC (0.94s)891=== CONT TestReadProxyRootRedirectsToIndexHTML8922026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=08932026/10/04 20:06:48 WARN Force mode enabled - objects will be deleted immediately without grace period8942026/10/04 20:06:48 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=08952026/10/04 20:06:48 INFO Vacuumed table table=pending_closures8962026/10/04 20:06:48 INFO Vacuumed table table=pending_objects8972026/10/04 20:06:48 INFO Vacuumed table table=multipart_uploads8982026/10/04 20:06:48 INFO Vacuumed table table=closures8992026/10/04 20:06:48 INFO Vacuumed table table=objects900--- PASS: TestGCMetrics (0.96s)901=== CONT TestService_cleanupPendingClosuresHandler9022026/10/04 20:06:48 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"903--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.91s)904=== CONT TestUploadHandlersRejectOversizedBody9052026/10/04 20:06:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete906=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure907=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure908=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart909=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart910=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts911=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts912=== CONT TestUploadHandlersRejectInvalidKeys913=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info914=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info915=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal916=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal917=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key918=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key919=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key920=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key921=== CONT TestIsValidUploadKey922=== RUN TestIsValidUploadKey/narinfo923=== PAUSE TestIsValidUploadKey/narinfo924=== RUN TestIsValidUploadKey/nar_zst925=== PAUSE TestIsValidUploadKey/nar_zst926=== RUN TestIsValidUploadKey/nar_xz927=== PAUSE TestIsValidUploadKey/nar_xz928=== RUN TestIsValidUploadKey/nar_plain929=== PAUSE TestIsValidUploadKey/nar_plain930=== RUN TestIsValidUploadKey/listing931=== PAUSE TestIsValidUploadKey/listing932=== RUN TestIsValidUploadKey/build_log933=== PAUSE TestIsValidUploadKey/build_log934=== RUN TestIsValidUploadKey/build_log_home-manager_file935=== PAUSE TestIsValidUploadKey/build_log_home-manager_file936=== RUN TestIsValidUploadKey/build_log_plus_in_name937=== PAUSE TestIsValidUploadKey/build_log_plus_in_name938=== RUN TestIsValidUploadKey/build_log_question_mark939=== PAUSE TestIsValidUploadKey/build_log_question_mark940=== RUN TestIsValidUploadKey/build_log_equals941=== PAUSE TestIsValidUploadKey/build_log_equals942=== RUN TestIsValidUploadKey/realisation943=== PAUSE TestIsValidUploadKey/realisation944=== RUN TestIsValidUploadKey/realisation_plus_in_output945=== PAUSE TestIsValidUploadKey/realisation_plus_in_output946=== RUN TestIsValidUploadKey/nix-cache-info947=== PAUSE TestIsValidUploadKey/nix-cache-info948=== RUN TestIsValidUploadKey/index.html949=== PAUSE TestIsValidUploadKey/index.html950=== RUN TestIsValidUploadKey/narinfo_key,_nar_type951=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type952=== RUN TestIsValidUploadKey/nar_key,_narinfo_type953=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type954=== RUN TestIsValidUploadKey/listing_key,_narinfo_type955=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type956=== RUN TestIsValidUploadKey/traversal957=== PAUSE TestIsValidUploadKey/traversal958=== RUN TestIsValidUploadKey/traversal_nar959=== PAUSE TestIsValidUploadKey/traversal_nar960=== RUN TestIsValidUploadKey/absolute961=== PAUSE TestIsValidUploadKey/absolute962=== RUN TestIsValidUploadKey/empty_key963=== PAUSE TestIsValidUploadKey/empty_key964=== RUN TestIsValidUploadKey/unknown_type965=== PAUSE TestIsValidUploadKey/unknown_type966=== CONT TestPendingClosureWriteTimeout967=== RUN TestPendingClosureWriteTimeout/empty968=== PAUSE TestPendingClosureWriteTimeout/empty969=== RUN TestPendingClosureWriteTimeout/400_objects970=== PAUSE TestPendingClosureWriteTimeout/400_objects971=== RUN TestPendingClosureWriteTimeout/670k_objects972=== PAUSE TestPendingClosureWriteTimeout/670k_objects973=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline974=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline975=== CONT TestProxyWriteTimeout976=== RUN TestProxyWriteTimeout/narinfo977=== PAUSE TestProxyWriteTimeout/narinfo978=== RUN TestProxyWriteTimeout/1_GiB_nar979=== PAUSE TestProxyWriteTimeout/1_GiB_nar980=== RUN TestProxyWriteTimeout/10_GiB_nar981=== PAUSE TestProxyWriteTimeout/10_GiB_nar982=== RUN TestProxyWriteTimeout/unknown_size983=== PAUSE TestProxyWriteTimeout/unknown_size984=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9852026/10/04 20:06:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36765/oidc9862026/10/04 20:06:48 INFO Received uploads request method=POST path=/api/pending_closures987--- PASS: TestPushWaitsForSweepHoldingRow (1.41s)988=== CONT TestSkippedUploadsHandler9892026/10/04 20:06:48 INFO Client skipped oversized paths paths=3 nar_bytes=50000000009902026/10/04 20:06:48 INFO Received push request method=POST path=/api/pushes991--- PASS: TestSkippedUploadsHandler (0.01s)992=== CONT TestParseSize993--- PASS: TestParseSize (0.00s)994=== CONT TestService_Rustfstest9952026/10/04 20:06:48 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NWNkMGM0ZDktOTk1NS00N2EwLWE5MTUtNzcwMjUwODkxZTQ0LmY1OTc3ZWI2LWExZDktNGRjYy1iNjllLTk2MzE5NWZlMTllNngxNzkxMTQ0NDA3OTc1NDkzMTQz parts=109962026/10/04 20:06:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9972026/10/04 20:06:48 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)9982026/10/04 20:06:48 INFO Uploading d54lznjr5fp147pn5bfp5nr5mhadacsj-shared-dep (136B)9992026/10/04 20:06:48 INFO Uploading d68x4sp3ybcw5yqkxd7sfx410i8hy2m9-top (224B)10002026/10/04 20:06:48 INFO Completed upload id=110012026/10/04 20:06:48 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010022026/10/04 20:06:48 INFO Received uploads request method=POST path=/api/pending_closures10032026/10/04 20:06:48 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10042026/10/04 20:06:48 WARN Failed to register uploaded object key=d54lznjr5fp147pn5bfp5nr5mhadacsj.ls error="server returned 404: 404 page not found\n"10052026/10/04 20:06:48 WARN Failed to register uploaded object key=nar/0sac2ssdl13i7s418ihfi5qc9564s61ybx0m58msh1yjldp1pwh3.nar.zst error="server returned 404: 404 page not found\n"10062026/10/04 20:06:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10072026/10/04 20:06:48 WARN Failed to register uploaded object key=d68x4sp3ybcw5yqkxd7sfx410i8hy2m9.ls error="server returned 404: 404 page not found\n"10082026/10/04 20:06:48 INFO Signed narinfos id=1 count=210092026/10/04 20:06:48 INFO Uploading 2 narinfos10102026/10/04 20:06:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures10112026/10/04 20:06:48 WARN Failed to register uploaded object key=d68x4sp3ybcw5yqkxd7sfx410i8hy2m9.narinfo error="server returned 404: 404 page not found\n"10122026/10/04 20:06:48 INFO Received complete push request method=POST path=/api/pushes/1/complete10132026/10/04 20:06:48 WARN Failed to register uploaded object key=d54lznjr5fp147pn5bfp5nr5mhadacsj.narinfo error="server returned 404: 404 page not found\n"10142026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=010152026/10/04 20:06:48 INFO Upload complete. (306ms)10162026/10/04 20:06:48 INFO Received uploads request method=POST path=/api/pending_closures1017=== NAME TestClientSharedPathCommittedMidPush1018 client_integration_test.go:680: Retrieved narinfo from S3:1019 StorePath: /build/TestClientSharedPathCommittedMidPush3371750811/001/store/d54lznjr5fp147pn5bfp5nr5mhadacsj-shared-dep1020 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1021 Compression: zstd1022 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821023 NarSize: 1361024 References: 1025 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1026 client_integration_test.go:680: Retrieved narinfo from S3:1027 StorePath: /build/TestClientSharedPathCommittedMidPush3371750811/001/store/d68x4sp3ybcw5yqkxd7sfx410i8hy2m9-top1028 URL: nar/0sac2ssdl13i7s418ihfi5qc9564s61ybx0m58msh1yjldp1pwh3.nar.zst1029 Compression: zstd1030 NarHash: sha256:0sac2ssdl13i7s418ihfi5qc9564s61ybx0m58msh1yjldp1pwh31031 NarSize: 2241032 References: /build/TestClientSharedPathCommittedMidPush3371750811/001/store/d54lznjr5fp147pn5bfp5nr5mhadacsj-shared-dep1033 CA: text:sha256:0lgasck093hgbp8mnyjlkcqrj3alr3hmjcr9r5jdx2ssksq62hf810342026/10/04 20:06:48 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=010352026/10/04 20:06:48 INFO Vacuumed table table=pending_closures1036--- PASS: TestClientSharedPathCommittedMidPush (1.46s)1037=== CONT TestPresignedUploadRegisteredBeforeCommit10382026/10/04 20:06:48 INFO Vacuumed table table=pending_objects10392026/10/04 20:06:48 INFO Vacuumed table table=multipart_uploads10402026/10/04 20:06:48 INFO Vacuumed table table=closures10412026/10/04 20:06:48 INFO Vacuumed table table=objects10422026/10/04 20:06:48 INFO Aborted multipart uploads count=0 kept=010432026/10/04 20:06:48 WARN Force mode enabled - objects will be deleted immediately without grace period10442026/10/04 20:06:48 INFO lead: acquired remote=192.0.2.1:123410452026/10/04 20:06:48 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=010462026/10/04 20:06:48 INFO Vacuumed table table=pending_closures10472026/10/04 20:06:48 INFO Vacuumed table table=pending_objects10482026/10/04 20:06:48 INFO Vacuumed table table=multipart_uploads10492026/10/04 20:06:48 INFO Vacuumed table table=closures10502026/10/04 20:06:48 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001051--- PASS: TestService_createPendingClosureHandler (1.50s)1052=== CONT TestCompletedNarNotReofferedAcrossClosures10532026/10/04 20:06:48 INFO Vacuumed table table=objects1054--- PASS: TestGCSweepSkipsPendingObjects (1.50s)1055=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10562026/10/04 20:06:48 INFO lead: acquired remote=192.0.2.1:12341057--- PASS: TestGCBugBareHashReferences (1.53s)1058=== CONT TestRedundantMultipartUpload1059--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.62s)1060=== CONT TestPush_SignsNarinfosOfItsPendingObjects1061=== NAME TestPinProtectsFromGC1062 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1322494980/001/store/4zd5mpjql3mmvk5x1086r0qgzkdbjghi-pinned-file.txt1063 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1322494980/001/store/qw35nrwp3zshk3ynr67mxj6yb86p6xvx-unpinned-file.txt1064=== NAME TestClientMultipleUploads1065 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2250299181/001/store/867lq9hskbvmnilbqbppknkpc4v0q2yn-test-file-0.txt1066=== NAME TestClientWithDependencies1067 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies4039063349/001/store/mzjpl7aah0sbdvpa8sfimqd3l6mgjiyv-test-script10682026/10/04 20:06:49 INFO Received uploads request method=POST path=/api/pending_closures10692026/10/04 20:06:49 INFO Received uploads request method=POST path=/api/pending_closures10702026/10/04 20:06:49 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10712026/10/04 20:06:49 INFO Uploading 1xsahncd88n6ajw8qlxvych7vklfyvma-shared-dep (136B)10722026/10/04 20:06:49 INFO Uploading gj88x09xna78308gklmpn966d5idqjrz-a (216B)1073=== NAME TestClientMultipleUploads1074 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2250299181/001/store/9mhrh8zqx0050g17g677yrk8vg822kzn-test-file-1.txt10752026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10762026/10/04 20:06:49 WARN Failed to register uploaded object key=fxiqx0s4i91g9hfinrpfzfrdbyqcaj0i.ls error="server returned 404: 404 page not found\n"10772026/10/04 20:06:49 WARN Failed to register uploaded object key=1xsahncd88n6ajw8qlxvych7vklfyvma.ls error="server returned 404: 404 page not found\n"10782026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/1s7a6ha2r78z4l5j0jkf9pwmjhhpcd4h5sabcpz98da0l2v0s19y.nar.zst error="server returned 404: 404 page not found\n"1079=== NAME TestClientIntegration1080 client_integration_test.go:286: Created store path: /build/TestClientIntegration3497180207/002/store/lh9daiz805bdfbqna1dy64mi5fnip2l7-test-file.txt1081=== NAME TestClientWithDependencies1082 client_integration_test.go:615: Found 1 dependencies (including self)10832026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes10842026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes1085--- PASS: TestCacheStatsHandler (1.00s)1086=== CONT TestPush_RejectsBadRequests1087--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.25s)10882026/10/04 20:06:49 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1089=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit10902026/10/04 20:06:49 INFO Uploading isrr48f64f7z4x9mfr0a93lff2ifsmlm-shared-dep (136B)10912026/10/04 20:06:49 INFO Uploading qqymw9w3qxz4z6swc59va2xj7gql597h-a (208B)10922026/10/04 20:06:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10932026/10/04 20:06:49 INFO Uploading 4zd5mpjql3mmvk5x1086r0qgzkdbjghi-pinned-file.txt (128B)10942026/10/04 20:06:49 WARN Failed to register uploaded object key=m51qf2dvbnb0q0rf5kh6z6crcidrnmp1.ls error="server returned 404: 404 page not found\n"10952026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10962026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/05895m78k0z9s5p5g124lqcb6myhw8c647c19dq0hah4djv93hls.nar.zst error="server returned 404: 404 page not found\n"10972026/10/04 20:06:49 WARN Failed to register uploaded object key=isrr48f64f7z4x9mfr0a93lff2ifsmlm.ls error="server returned 404: 404 page not found\n"10982026/10/04 20:06:49 WARN Failed to register uploaded object key=qqymw9w3qxz4z6swc59va2xj7gql597h.ls error="server returned 404: 404 page not found\n"10992026/10/04 20:06:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11002026/10/04 20:06:49 INFO Signed narinfos id=1 count=311012026/10/04 20:06:49 INFO Uploading 3 narinfos1102=== NAME TestClientMultipleUploads1103 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2250299181/001/store/nxi609sz2a8krz136jfzhzanxz3av1x8-test-file-2.txt11042026/10/04 20:06:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11052026/10/04 20:06:49 WARN Failed to register uploaded object key=gj88x09xna78308gklmpn966d5idqjrz.ls error="server returned 404: 404 page not found\n"11062026/10/04 20:06:49 WARN Failed to register uploaded object key=4zd5mpjql3mmvk5x1086r0qgzkdbjghi.ls error="server returned 404: 404 page not found\n"11072026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11082026/10/04 20:06:49 INFO Signed narinfos id=1 count=211092026/10/04 20:06:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11102026/10/04 20:06:49 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11112026/10/04 20:06:49 INFO Signed narinfos id=1 count=111122026/10/04 20:06:49 INFO Uploading 1 narinfos11132026/10/04 20:06:49 INFO Signed narinfos id=2 count=211142026/10/04 20:06:49 INFO Uploading 4 narinfos1115=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1116=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1117=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1118=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1119=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1120=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1121=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1122=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1123=== CONT TestPush_CompleteCommitsEveryRoot11242026/10/04 20:06:49 WARN Failed to register uploaded object key=isrr48f64f7z4x9mfr0a93lff2ifsmlm.narinfo error="server returned 404: 404 page not found\n"11252026/10/04 20:06:49 WARN Failed to register uploaded object key=qqymw9w3qxz4z6swc59va2xj7gql597h.narinfo error="server returned 404: 404 page not found\n"11262026/10/04 20:06:49 INFO Received complete push request method=POST path=/api/pushes/1/complete11272026/10/04 20:06:49 WARN Failed to register uploaded object key=m51qf2dvbnb0q0rf5kh6z6crcidrnmp1.narinfo error="server returned 404: 404 page not found\n"11282026/10/04 20:06:49 INFO Received complete push request method=POST path=/api/pushes/1/complete11292026/10/04 20:06:49 WARN Failed to register uploaded object key=4zd5mpjql3mmvk5x1086r0qgzkdbjghi.narinfo error="server returned 404: 404 page not found\n"11302026/10/04 20:06:49 WARN Failed to register uploaded object key=fxiqx0s4i91g9hfinrpfzfrdbyqcaj0i.narinfo error="server returned 404: 404 page not found\n"11312026/10/04 20:06:49 WARN Failed to register uploaded object key=1xsahncd88n6ajw8qlxvych7vklfyvma.narinfo error="server returned 404: 404 page not found\n"11322026/10/04 20:06:49 WARN Failed to register uploaded object key=gj88x09xna78308gklmpn966d5idqjrz.narinfo error="server returned 404: 404 page not found\n"11332026/10/04 20:06:49 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11342026/10/04 20:06:49 WARN Failed to register uploaded object key=1xsahncd88n6ajw8qlxvych7vklfyvma.narinfo error="server returned 404: 404 page not found\n"11352026/10/04 20:06:49 INFO Upload complete. (63ms)11362026/10/04 20:06:49 INFO Upload complete. (69ms)1137=== NAME TestClientPushesUseOnePush1138 client_pushes_test.go:97: Retrieved narinfo from S3:1139 StorePath: /build/TestClientPushesUseOnePush631825387/001/store/isrr48f64f7z4x9mfr0a93lff2ifsmlm-shared-dep1140 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1141 Compression: zstd1142 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821143 NarSize: 1361144 References: 1145 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11462026/10/04 20:06:49 INFO Completed upload id=211472026/10/04 20:06:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1148 client_pushes_test.go:97: Retrieved narinfo from S3:1149 StorePath: /build/TestClientPushesUseOnePush631825387/001/store/qqymw9w3qxz4z6swc59va2xj7gql597h-a1150 URL: nar/05895m78k0z9s5p5g124lqcb6myhw8c647c19dq0hah4djv93hls.nar.zst1151 Compression: zstd1152 NarHash: sha256:05895m78k0z9s5p5g124lqcb6myhw8c647c19dq0hah4djv93hls1153 NarSize: 2081154 References: /build/TestClientPushesUseOnePush631825387/001/store/isrr48f64f7z4x9mfr0a93lff2ifsmlm-shared-dep1155 CA: text:sha256:0cg7pnhri671ym6k5qffrpwq89lq3wv3cja7nii4p6j8krqc2pzh1156 client_pushes_test.go:97: Retrieved narinfo from S3:1157 StorePath: /build/TestClientPushesUseOnePush631825387/001/store/m51qf2dvbnb0q0rf5kh6z6crcidrnmp1-b1158 URL: nar/05895m78k0z9s5p5g124lqcb6myhw8c647c19dq0hah4djv93hls.nar.zst1159 Compression: zstd1160 NarHash: sha256:05895m78k0z9s5p5g124lqcb6myhw8c647c19dq0hah4djv93hls1161 NarSize: 2081162 References: /build/TestClientPushesUseOnePush631825387/001/store/isrr48f64f7z4x9mfr0a93lff2ifsmlm-shared-dep1163 CA: text:sha256:0cg7pnhri671ym6k5qffrpwq89lq3wv3cja7nii4p6j8krqc2pzh1164--- PASS: TestService_ReadScope_PublicByDefault (0.99s)1165=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1166--- PASS: TestClientPushesUseOnePush (1.23s)1167=== CONT TestReadRedirectUsesPublicS3URL11682026/10/04 20:06:49 INFO Completed upload id=111692026/10/04 20:06:49 INFO Upload complete. (120ms)1170=== NAME TestClientCADerivations1171 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations243810619/001/store/zsa9ks2hgypxhw5ms4rw9m7rh60mkc7m-ca-test1172=== NAME TestClientFallsBackToClosures1173 client_pushes_test.go:112: Retrieved narinfo from S3:1174 StorePath: /build/TestClientFallsBackToClosures164277987/001/store/1xsahncd88n6ajw8qlxvych7vklfyvma-shared-dep1175 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1176 Compression: zstd1177 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821178 NarSize: 1361179 References: 1180 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1181 client_pushes_test.go:112: Retrieved narinfo from S3:1182 StorePath: /build/TestClientFallsBackToClosures164277987/001/store/gj88x09xna78308gklmpn966d5idqjrz-a1183 URL: nar/1s7a6ha2r78z4l5j0jkf9pwmjhhpcd4h5sabcpz98da0l2v0s19y.nar.zst1184 Compression: zstd1185 NarHash: sha256:1s7a6ha2r78z4l5j0jkf9pwmjhhpcd4h5sabcpz98da0l2v0s19y1186 NarSize: 2161187 References: /build/TestClientFallsBackToClosures164277987/001/store/1xsahncd88n6ajw8qlxvych7vklfyvma-shared-dep1188 CA: text:sha256:0qrkl7326mscnxd8k7rbnigglcdcb9bjl0kkdz7b3kay8b93yh2x11892026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes1190 client_pushes_test.go:112: Retrieved narinfo from S3:1191 StorePath: /build/TestClientFallsBackToClosures164277987/001/store/fxiqx0s4i91g9hfinrpfzfrdbyqcaj0i-b1192 URL: nar/1s7a6ha2r78z4l5j0jkf9pwmjhhpcd4h5sabcpz98da0l2v0s19y.nar.zst1193 Compression: zstd1194 NarHash: sha256:1s7a6ha2r78z4l5j0jkf9pwmjhhpcd4h5sabcpz98da0l2v0s19y1195 NarSize: 2161196 References: /build/TestClientFallsBackToClosures164277987/001/store/1xsahncd88n6ajw8qlxvych7vklfyvma-shared-dep1197 CA: text:sha256:0qrkl7326mscnxd8k7rbnigglcdcb9bjl0kkdz7b3kay8b93yh2x11982026/10/04 20:06:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11992026/10/04 20:06:49 INFO Uploading lh9daiz805bdfbqna1dy64mi5fnip2l7-test-file.txt (152B)12002026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes1201--- PASS: TestClientFallsBackToClosures (1.31s)1202=== CONT TestReadProxyRangeRequest12032026/10/04 20:06:49 WARN Failed to register uploaded object key=lh9daiz805bdfbqna1dy64mi5fnip2l7.ls error="server returned 404: 404 page not found\n"12042026/10/04 20:06:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12052026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12062026/10/04 20:06:49 INFO Signed narinfos id=1 count=112072026/10/04 20:06:49 INFO Uploading 1 narinfos12082026/10/04 20:06:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12092026/10/04 20:06:49 INFO Uploading mzjpl7aah0sbdvpa8sfimqd3l6mgjiyv-test-script (136B)12102026/10/04 20:06:49 INFO Received cleanup request method=DELETE path=/api/pending_closures12112026/10/04 20:06:49 INFO Received complete push request method=POST path=/api/pushes/1/complete12122026/10/04 20:06:49 WARN Failed to register uploaded object key=lh9daiz805bdfbqna1dy64mi5fnip2l7.narinfo error="server returned 404: 404 page not found\n"12132026/10/04 20:06:49 INFO Aborted multipart uploads count=0 kept=012142026/10/04 20:06:49 INFO Received uploads request method=POST path=/api/pending_closures12152026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12162026/10/04 20:06:49 WARN Failed to register uploaded object key=mzjpl7aah0sbdvpa8sfimqd3l6mgjiyv.ls error="server returned 404: 404 page not found\n"12172026/10/04 20:06:49 WARN Failed to register uploaded object key=log/3k8zqkhnxlwpvdwr90738kgli068f9rw-test-script.drv error="server returned 404: 404 page not found\n"12182026/10/04 20:06:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12192026/10/04 20:06:49 INFO Signed narinfos id=1 count=112202026/10/04 20:06:49 INFO Uploading 1 narinfos1221=== NAME TestClientCADerivations1222 client_ca_test.go:139: Found 1 dependencies (including self)12232026/10/04 20:06:49 INFO Received complete push request method=POST path=/api/pushes/1/complete12242026/10/04 20:06:49 INFO Upload complete. (66ms)12252026/10/04 20:06:49 WARN Failed to register uploaded object key=mzjpl7aah0sbdvpa8sfimqd3l6mgjiyv.narinfo error="server returned 404: 404 page not found\n"12262026/10/04 20:06:49 INFO Received cleanup request method=DELETE path=/api/pending_closures12272026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes12282026/10/04 20:06:49 INFO Aborted multipart uploads count=1 kept=012292026/10/04 20:06:49 INFO Upload complete. (69ms)12302026/10/04 20:06:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12312026-10-04 20:06:49.377 UTC [802] ERROR: Closure does not exist: id=112322026-10-04 20:06:49.377 UTC [802] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE12332026-10-04 20:06:49.377 UTC [802] STATEMENT: -- name: CommitPendingClosure :exec1234 SELECT commit_pending_closure($1::bigint)1235 1236--- PASS: TestService_cleanupPendingClosuresHandler (0.93s)1237=== CONT TestReadRedirectKeepsNarinfoProxied1238=== NAME TestClientWithDependencies1239 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4039063349/001/store) requires matching store prefix12402026/10/04 20:06:49 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12412026/10/04 20:06:49 INFO Uploading 867lq9hskbvmnilbqbppknkpc4v0q2yn-test-file-0.txt (160B)12422026/10/04 20:06:49 INFO Uploading 9mhrh8zqx0050g17g677yrk8vg822kzn-test-file-1.txt (160B)12432026/10/04 20:06:49 INFO Uploading nxi609sz2a8krz136jfzhzanxz3av1x8-test-file-2.txt (160B)12442026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes1245--- PASS: TestClientWithDependencies (1.19s)1246=== CONT TestReadRedirectNar12472026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1248--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.97s)1249=== CONT TestReadProxyDisabled12502026/10/04 20:06:49 WARN Failed to register uploaded object key=867lq9hskbvmnilbqbppknkpc4v0q2yn.ls error="server returned 404: 404 page not found\n"12512026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12522026/10/04 20:06:49 WARN Failed to register uploaded object key=9mhrh8zqx0050g17g677yrk8vg822kzn.ls error="server returned 404: 404 page not found\n"12532026/10/04 20:06:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12542026/10/04 20:06:49 INFO Uploading qw35nrwp3zshk3ynr67mxj6yb86p6xvx-unpinned-file.txt (128B)12552026/10/04 20:06:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12562026/10/04 20:06:49 WARN Failed to register uploaded object key=nxi609sz2a8krz136jfzhzanxz3av1x8.ls error="server returned 404: 404 page not found\n"12572026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12582026/10/04 20:06:49 INFO Signed narinfos id=1 count=312592026/10/04 20:06:49 INFO Uploading 3 narinfos12602026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12612026/10/04 20:06:49 WARN Failed to register uploaded object key=qw35nrwp3zshk3ynr67mxj6yb86p6xvx.ls error="server returned 404: 404 page not found\n"12622026/10/04 20:06:49 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12632026/10/04 20:06:49 INFO Signed narinfos id=2 count=112642026/10/04 20:06:49 INFO Uploading 1 narinfos12652026/10/04 20:06:49 WARN Failed to register uploaded object key=9mhrh8zqx0050g17g677yrk8vg822kzn.narinfo error="server returned 404: 404 page not found\n"12662026/10/04 20:06:49 INFO Received complete push request method=POST path=/api/pushes/1/complete12672026/10/04 20:06:49 WARN Failed to register uploaded object key=nxi609sz2a8krz136jfzhzanxz3av1x8.narinfo error="server returned 404: 404 page not found\n"12682026/10/04 20:06:49 WARN Failed to register uploaded object key=867lq9hskbvmnilbqbppknkpc4v0q2yn.narinfo error="server returned 404: 404 page not found\n"12692026/10/04 20:06:49 INFO Received complete push request method=POST path=/api/pushes/2/complete12702026/10/04 20:06:49 WARN Failed to register uploaded object key=qw35nrwp3zshk3ynr67mxj6yb86p6xvx.narinfo error="server returned 404: 404 page not found\n"12712026/10/04 20:06:49 INFO Upload complete. (56ms)12722026/10/04 20:06:49 INFO All 1 paths already cached12732026/10/04 20:06:49 INFO Upload complete. (76ms)1274=== NAME TestClientMultipleUploads1275 client_integration_test.go:369: Uploaded 3 paths in 109.792089ms1276=== NAME TestClientIntegration1277 client_integration_test.go:312: Retrieved narinfo from S3:1278 StorePath: /build/TestClientIntegration3497180207/002/store/lh9daiz805bdfbqna1dy64mi5fnip2l7-test-file.txt1279 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1280 Compression: zstd1281 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11282 NarSize: 1521283 References: 1284 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11285 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1286 client_integration_test.go:313: Decompressed .ls content (64 bytes):1287 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1288 client_integration_test.go:316: Testing garbage collection...1289--- PASS: TestClientMultipleUploads (1.19s)1290=== CONT TestPresentNotReportedWhileGCDeletesClosure1291=== RUN TestService_RequireScope_OIDC/builder_may_write1292=== PAUSE TestService_RequireScope_OIDC/builder_may_write1293=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1294=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1295=== RUN TestService_RequireScope_OIDC/ops_may_admin1296=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1297=== RUN TestService_RequireScope_OIDC/ops_may_not_write1298=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1299=== RUN TestService_RequireScope_OIDC/reader_may_not_write1300=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1301=== RUN TestService_RequireScope_OIDC/static_token_may_admin1302=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1303=== RUN TestService_RequireScope_OIDC/static_token_may_write1304=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1305=== RUN TestService_RequireScope_OIDC/reader_may_read1306=== PAUSE TestService_RequireScope_OIDC/reader_may_read1307=== RUN TestService_RequireScope_OIDC/writer_implies_read1308=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1309=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1310=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1311=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1312=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1313=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1314=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1315=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1316=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1317=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1318=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1319=== CONT TestReadProxyConditionalGet13202026/10/04 20:06:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures13212026/10/04 20:06:49 INFO Garbage collection started1322--- PASS: TestService_Rustfstest (0.54s)1323=== CONT TestReadProxyOutlastsServerWriteTimeout13242026/10/04 20:06:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures13252026/10/04 20:06:49 INFO Garbage collection started13262026/10/04 20:06:49 INFO Aborted multipart uploads count=0 kept=013272026/10/04 20:06:49 INFO Aborted multipart uploads count=0 kept=013282026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes13292026/10/04 20:06:49 WARN Force mode enabled - objects will be deleted immediately without grace period13302026/10/04 20:06:49 WARN Force mode enabled - objects will be deleted immediately without grace period13312026/10/04 20:06:49 INFO Received uploads request method=POST path=/api/pending_closures13322026/10/04 20:06:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13332026/10/04 20:06:49 INFO Uploading zsa9ks2hgypxhw5ms4rw9m7rh60mkc7m-ca-test (144B)13342026/10/04 20:06:49 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13352026/10/04 20:06:49 WARN Failed to register uploaded object key=zsa9ks2hgypxhw5ms4rw9m7rh60mkc7m.ls error="server returned 404: 404 page not found\n"13362026/10/04 20:06:49 WARN Failed to register uploaded object key=log/3di7ln2z3hn8lnddda0xfkippylp1c0s-ca-test.drv error="server returned 404: 404 page not found\n"13372026/10/04 20:06:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13382026/10/04 20:06:49 INFO Signed narinfos id=1 count=113392026/10/04 20:06:49 INFO Uploading 1 narinfos13402026/10/04 20:06:49 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=013412026/10/04 20:06:49 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=013422026/10/04 20:06:49 INFO Received complete push request method=POST path=/api/pushes/1/complete13432026/10/04 20:06:49 WARN Failed to register uploaded object key=zsa9ks2hgypxhw5ms4rw9m7rh60mkc7m.narinfo error="server returned 404: 404 page not found\n"13442026/10/04 20:06:49 INFO Vacuumed table table=pending_closures13452026/10/04 20:06:49 INFO Vacuumed table table=pending_closures13462026/10/04 20:06:49 INFO Vacuumed table table=pending_objects13472026/10/04 20:06:49 INFO Vacuumed table table=pending_objects13482026/10/04 20:06:49 INFO Vacuumed table table=multipart_uploads13492026/10/04 20:06:49 INFO Vacuumed table table=multipart_uploads13502026/10/04 20:06:49 INFO Upload complete. (105ms)13512026/10/04 20:06:49 INFO Vacuumed table table=closures13522026/10/04 20:06:49 INFO Vacuumed table table=closures1353=== NAME TestClientCADerivations1354 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations243810619/001/store/zsa9ks2hgypxhw5ms4rw9m7rh60mkc7m-ca-test1355 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1356 Compression: zstd1357 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1358 NarSize: 1441359 References: 1360 Deriver: /build/TestClientCADerivations243810619/001/store/3di7ln2z3hn8lnddda0xfkippylp1c0s-ca-test.drv1361 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1362 client_ca_test.go:185: Checking for realisation files in S3...13632026/10/04 20:06:49 INFO Vacuumed table table=objects13642026/10/04 20:06:49 INFO Received uploads request method=POST path=/api/pending_closures1365 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1366 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13672026/10/04 20:06:49 INFO Vacuumed table table=objects13682026/10/04 20:06:49 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13692026/10/04 20:06:49 INFO Received uploads request method=POST path=/api/pending_closures13702026/10/04 20:06:49 INFO Received uploads request method=POST path=/api/pending_closures1371--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.59s)1372=== CONT TestReadProxyHead13732026/10/04 20:06:49 INFO Received uploads request method=POST path=/api/pending_closures13742026/10/04 20:06:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13752026/10/04 20:06:49 INFO Received uploads request method=POST path=/api/pending_closures1376=== NAME TestClientCADerivations1377 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1378 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1379 error: binary cache 's3://bucket36?endpoint=http://localhost:46315®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations243810619/001/store'1380 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11381--- PASS: TestClientCADerivations (1.38s)1382=== CONT TestReadProxyInvalidPath13832026/10/04 20:06:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13842026/10/04 20:06:49 INFO Received uploads request method=POST path=/api/pending_closures13852026/10/04 20:06:49 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWNkMGM0ZDktOTk1NS00N2EwLWE5MTUtNzcwMjUwODkxZTQ0LjA1MjNmYTY2LTJkN2UtNDZmMy05YTRmLWVhNWY3MTQzNjM5MXgxNzkxMTQ0NDA5NTc1NjIzMzk413862026/10/04 20:06:49 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWNkMGM0ZDktOTk1NS00N2EwLWE5MTUtNzcwMjUwODkxZTQ0LjA1MjNmYTY2LTJkN2UtNDZmMy05YTRmLWVhNWY3MTQzNjM5MXgxNzkxMTQ0NDA5NTc1NjIzMzk4 parts=11387--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.77s)1388=== CONT TestReadProxy40413892026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes13902026/10/04 20:06:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13912026/10/04 20:06:49 INFO Signed narinfos id=1 count=11392--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.68s)1393=== CONT TestIsValidCachePath1394=== RUN TestIsValidCachePath/narinfo1395=== PAUSE TestIsValidCachePath/narinfo1396=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1397=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1398=== RUN TestIsValidCachePath/nar_zst1399=== PAUSE TestIsValidCachePath/nar_zst1400=== RUN TestIsValidCachePath/nar_xz1401=== PAUSE TestIsValidCachePath/nar_xz1402=== RUN TestIsValidCachePath/nar_bz21403=== PAUSE TestIsValidCachePath/nar_bz21404=== RUN TestIsValidCachePath/nar_uncompressed1405=== PAUSE TestIsValidCachePath/nar_uncompressed1406=== RUN TestIsValidCachePath/ls1407=== PAUSE TestIsValidCachePath/ls1408=== RUN TestIsValidCachePath/log1409=== PAUSE TestIsValidCachePath/log1410=== RUN TestIsValidCachePath/realisation1411=== PAUSE TestIsValidCachePath/realisation1412=== RUN TestIsValidCachePath/nix-cache-info1413=== PAUSE TestIsValidCachePath/nix-cache-info1414=== RUN TestIsValidCachePath/index.html1415=== PAUSE TestIsValidCachePath/index.html1416=== RUN TestIsValidCachePath/traversal_parent1417=== PAUSE TestIsValidCachePath/traversal_parent1418=== RUN TestIsValidCachePath/traversal_in_middle1419=== PAUSE TestIsValidCachePath/traversal_in_middle1420=== RUN TestIsValidCachePath/invalid_char_e1421=== PAUSE TestIsValidCachePath/invalid_char_e1422=== RUN TestIsValidCachePath/invalid_char_u1423=== PAUSE TestIsValidCachePath/invalid_char_u1424=== RUN TestIsValidCachePath/random_path1425=== PAUSE TestIsValidCachePath/random_path1426=== RUN TestIsValidCachePath/empty1427=== PAUSE TestIsValidCachePath/empty1428=== RUN TestIsValidCachePath/leading_slash1429=== PAUSE TestIsValidCachePath/leading_slash1430=== RUN TestIsValidCachePath/wrong_extension1431=== PAUSE TestIsValidCachePath/wrong_extension1432=== RUN TestIsValidCachePath/short_hash1433=== PAUSE TestIsValidCachePath/short_hash1434=== CONT TestProxyHeadersOnlyTrustedOnSocket1435=== RUN TestPush_RejectsBadRequests/bad_root1436=== PAUSE TestPush_RejectsBadRequests/bad_root1437=== RUN TestPush_RejectsBadRequests/root_not_in_objects1438=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1439=== RUN TestPush_RejectsBadRequests/no_roots1440=== PAUSE TestPush_RejectsBadRequests/no_roots1441=== RUN TestPush_RejectsBadRequests/no_objects1442=== PAUSE TestPush_RejectsBadRequests/no_objects1443=== CONT TestParseSingleRange1444=== RUN TestParseSingleRange/none1445=== PAUSE TestParseSingleRange/none1446=== RUN TestParseSingleRange/unknown_unit1447=== PAUSE TestParseSingleRange/unknown_unit1448=== RUN TestParseSingleRange/multi-range_ignored1449=== PAUSE TestParseSingleRange/multi-range_ignored1450=== RUN TestParseSingleRange/malformed_no_dash1451=== PAUSE TestParseSingleRange/malformed_no_dash1452=== RUN TestParseSingleRange/malformed_both_empty1453=== PAUSE TestParseSingleRange/malformed_both_empty1454=== RUN TestParseSingleRange/malformed_end_before_start1455=== PAUSE TestParseSingleRange/malformed_end_before_start1456=== RUN TestParseSingleRange/closed1457=== PAUSE TestParseSingleRange/closed1458=== RUN TestParseSingleRange/open-ended1459=== PAUSE TestParseSingleRange/open-ended1460=== RUN TestParseSingleRange/end_clamped_to_size1461=== PAUSE TestParseSingleRange/end_clamped_to_size1462=== RUN TestParseSingleRange/suffix1463=== PAUSE TestParseSingleRange/suffix1464=== RUN TestParseSingleRange/suffix_exceeds_size1465=== PAUSE TestParseSingleRange/suffix_exceeds_size1466=== RUN TestParseSingleRange/single_byte1467=== PAUSE TestParseSingleRange/single_byte1468=== RUN TestParseSingleRange/start_past_EOF1469=== PAUSE TestParseSingleRange/start_past_EOF1470=== RUN TestParseSingleRange/start_far_past_EOF1471=== PAUSE TestParseSingleRange/start_far_past_EOF1472=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14732026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes14742026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes14752026/10/04 20:06:49 INFO Received complete push request method=POST path=/api/pushes/1/complete14762026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes14772026/10/04 20:06:49 INFO Received complete push request method=POST path=/api/pushes/1/complete14782026/10/04 20:06:49 INFO Received push request method=POST path=/api/pushes1479--- PASS: TestPush_CompleteCommitsEveryRoot (0.64s)1480=== CONT TestService_ReadAuthMiddleware1481--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.63s)1482=== CONT TestService_AuthMiddleware_MTLSProxyHeader14832026/10/04 20:06:49 INFO Aborted multipart uploads count=0 kept=01484--- PASS: TestReadRedirectUsesPublicS3URL (0.66s)1485=== CONT TestPendingCleanupUsesOneCutoff14862026/10/04 20:06:49 WARN Force mode enabled - objects will be deleted immediately without grace period14872026/10/04 20:06:50 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=014882026/10/04 20:06:50 INFO Vacuumed table table=pending_closures14892026/10/04 20:06:50 INFO lead: released remote=192.0.2.1:12341490--- PASS: TestLeadEndsOnShutdown (2.15s)1491=== CONT TestPresentReportsOnlyClosureRoots1492--- PASS: TestReadProxyRangeRequest (0.66s)1493=== CONT TestCreatePin_ReservedPins14942026/10/04 20:06:50 INFO Vacuumed table table=pending_objects14952026/10/04 20:06:50 INFO Vacuumed table table=multipart_uploads14962026/10/04 20:06:50 INFO Vacuumed table table=closures14972026/10/04 20:06:50 INFO Vacuumed table table=objects1498--- PASS: TestReadRedirectKeepsNarinfoProxied (0.66s)1499=== CONT TestOrphanedObjectsGCStressTest15002026/10/04 20:06:50 INFO Received complete push request method=POST path=/api/pushes/2/complete1501--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.76s)1502=== CONT TestOrphanedObjectsGC1503--- PASS: TestReadRedirectNar (0.69s)1504=== CONT TestObjectStatsTrigger1505--- PASS: TestReadProxyDisabled (0.71s)1506=== CONT TestServerTLSConfig1507=== RUN TestServerTLSConfig/no_client_CA1508=== PAUSE TestServerTLSConfig/no_client_CA1509=== RUN TestServerTLSConfig/missing_CA_file1510=== PAUSE TestServerTLSConfig/missing_CA_file1511=== RUN TestServerTLSConfig/not_a_PEM_file1512=== PAUSE TestServerTLSConfig/not_a_PEM_file1513=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded15142026/10/04 20:06:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41971/oidc1515--- PASS: TestReadProxyConditionalGet (0.74s)1516=== CONT TestMultipartCleanup15172026/10/04 20:06:50 INFO lead: released remote=192.0.2.1:123415182026/10/04 20:06:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1519--- PASS: TestReadProxyHead (0.70s)1520=== CONT TestMetricsInventory15212026/10/04 20:06:50 INFO lead: acquired remote=192.0.2.1:123415222026/10/04 20:06:50 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NWNkMGM0ZDktOTk1NS00N2EwLWE5MTUtNzcwMjUwODkxZTQ0Ljk3ODRmZThiLTg2OWItNDk3Mi05NDhiLTUyZjExZTU4NGE4YXgxNzkxMTQ0NDA5NTQ3NjE2MzMz parts=1215232026/10/04 20:06:50 INFO Received uploads request method=POST path=/api/pending_closures1524--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.27s)1525=== CONT TestService_NativeMTLS1526--- PASS: TestReadProxyInvalidPath (0.63s)1527=== CONT TestNARDeduplicationMetadataUploadBug15282026/10/04 20:06:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1529--- PASS: TestReadProxy404 (0.55s)1530=== CONT TestReadProxyNarStreaming15312026/10/04 20:06:50 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15322026/10/04 20:06:50 WARN mTLS auth: bound subjects configured but subject DN unavailable15332026/10/04 20:06:50 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1534--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.52s)1535=== CONT TestReadProxyNarinfoAlreadyDecompressed15362026/10/04 20:06:50 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1766761390/001/proxy.sock15372026/10/04 20:06:50 INFO Starting HTTP server address=127.0.0.1:4218915382026/10/04 20:06:50 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15392026/10/04 20:06:50 INFO Shutdown signal received, draining in-flight requests timeout=10s1540--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.56s)1541=== CONT TestReadProxyNarinfo15422026/10/04 20:06:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NWNkMGM0ZDktOTk1NS00N2EwLWE5MTUtNzcwMjUwODkxZTQ0LjVhMjRiMDAzLTRjOGMtNDc2NC05MDFkLWJjYWY1NzhhMTBjMngxNzkxMTQ0NDA5NzM1NDY2Mzgx parts=1215432026/10/04 20:06:50 INFO Received uploads request method=POST path=/api/pending_closures15442026/10/04 20:06:50 INFO Received uploads request method=POST path=/api/pending_closures1545--- PASS: TestService_ReadAuthMiddleware (0.43s)1546=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1547--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.45s)1548=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15492026/10/04 20:06:50 INFO Received uploads request method=POST path=/api/pending_closures15502026/10/04 20:06:50 INFO Received uploads request method=POST path=/api/pending_closures15512026/10/04 20:06:50 INFO Received cleanup request method=DELETE path=/api/pending_closures1552--- PASS: TestPresentReportsOnlyClosureRoots (0.49s)1553=== CONT TestGCEndsOnShutdown/before_the_run1554--- PASS: TestObjectStatsTrigger (0.52s)1555=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15562026/10/04 20:06:50 INFO Received uploads request method=POST path=/api/pending_closures1557--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.53s)1558=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15592026/10/04 20:06:50 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15602026/10/04 20:06:50 WARN Refused reserved pin name=worker-x86_64-linux15612026/10/04 20:06:50 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15622026/10/04 20:06:50 INFO Received create pin request method=POST path=/api/pins/my-app15632026/10/04 20:06:50 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1564--- PASS: TestCreatePin_ReservedPins (0.64s)1565=== CONT TestResolveDBConnectionString/flag_wins1566=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1567=== CONT TestResolveDBConnectionString/nothing_configured1568=== CONT TestResolveDBConnectionString/missing_file_is_an_error1569=== CONT TestResolveDBConnectionString/file_when_flag_empty1570=== CONT TestCacheConfigHandler/full_config,_no_issuer1571=== CONT TestCacheConfigHandler/no_signing_keys1572=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1573=== CONT TestCacheConfigHandler/no_cache_url_configured1574--- PASS: TestCacheConfigHandler (0.00s)1575 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1576 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1577 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1578 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1579--- PASS: TestResolveDBConnectionString (0.00s)1580 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1581 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1582 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1583 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1584 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1585=== CONT TestClientErrorHandling/InvalidStorePath1586--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.23s)1587=== CONT TestClientErrorHandling/ServerNotAvailable15882026/10/04 20:06:50 INFO Received uploads request method=POST path=/api/pending_closures15892026/10/04 20:06:50 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/present1590--- PASS: TestMetricsInventory (0.49s)1591=== CONT TestClientErrorHandling/InvalidAuthToken15922026/10/04 20:06:50 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15932026/10/04 20:06:50 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1594--- PASS: TestService_NativeMTLS (0.48s)1595=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15962026/10/04 20:06:50 INFO Received uploads request method=POST path=/15972026/10/04 20:06:50 INFO Received cleanup request method=DELETE path=/api/pending_closures15982026/10/04 20:06:50 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket76/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15992026/10/04 20:06:50 INFO Aborted multipart uploads count=0 kept=11600--- PASS: TestReadProxyNarStreaming (0.48s)1601=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16022026/10/04 20:06:50 INFO Received request for more parts method=POST path=/16032026/10/04 20:06:50 INFO Received cleanup request method=DELETE path=/api/pending_closures16042026/10/04 20:06:50 INFO Aborted multipart uploads count=1 kept=01605=== NAME TestNARDeduplicationMetadataUploadBug1606 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2854895937/001/store/n962h66ivjap2xrl3p2cpwp5g4ggk8wh-file1.txt1607--- PASS: TestMultipartCleanup (0.64s)1608=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16092026/10/04 20:06:50 INFO Received complete multipart upload request method=POST path=/1610--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.50s)1611=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16122026/10/04 20:06:50 INFO Received uploads request method=POST path=/1613=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16142026/10/04 20:06:50 INFO Received complete multipart upload request method=POST path=/1615=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16162026/10/04 20:06:50 INFO Received request for more parts method=POST path=/1617=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16182026/10/04 20:06:50 INFO Received uploads request method=POST path=/1619--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1620 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1621 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1622 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1623 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1624=== CONT TestIsValidUploadKey/narinfo1625=== CONT TestIsValidUploadKey/realisation_plus_in_output1626=== CONT TestIsValidUploadKey/unknown_type1627=== CONT TestIsValidUploadKey/empty_key1628=== CONT TestIsValidUploadKey/absolute1629=== CONT TestIsValidUploadKey/traversal_nar1630=== CONT TestIsValidUploadKey/traversal1631=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1632=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1633=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1634=== CONT TestIsValidUploadKey/index.html1635=== CONT TestIsValidUploadKey/nix-cache-info1636=== CONT TestIsValidUploadKey/build_log_equals1637=== CONT TestIsValidUploadKey/realisation1638=== CONT TestIsValidUploadKey/build_log_question_mark1639=== CONT TestIsValidUploadKey/nar_plain1640=== CONT TestIsValidUploadKey/build_log1641=== CONT TestIsValidUploadKey/build_log_home-manager_file1642=== CONT TestIsValidUploadKey/listing1643=== CONT TestIsValidUploadKey/build_log_plus_in_name1644=== CONT TestIsValidUploadKey/nar_zst1645=== CONT TestIsValidUploadKey/nar_xz1646--- PASS: TestIsValidUploadKey (0.00s)1647 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1648 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1649 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1650 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1651 --- PASS: TestIsValidUploadKey/absolute (0.00s)1652 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1653 --- PASS: TestIsValidUploadKey/traversal (0.00s)1654 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1655 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1656 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1657 --- PASS: TestIsValidUploadKey/index.html (0.00s)1658 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1659 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1660 --- PASS: TestIsValidUploadKey/realisation (0.00s)1661 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1662 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1663 --- PASS: TestIsValidUploadKey/build_log (0.00s)1664 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1665 --- PASS: TestIsValidUploadKey/listing (0.00s)1666 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1667 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1668 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1669=== CONT TestPendingClosureWriteTimeout/empty1670=== CONT TestPendingClosureWriteTimeout/670k_objects1671=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline16722026/10/04 20:06:50 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.511977ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1673=== CONT TestPendingClosureWriteTimeout/400_objects1674=== CONT TestProxyWriteTimeout/narinfo1675=== CONT TestProxyWriteTimeout/10_GiB_nar1676=== CONT TestProxyWriteTimeout/unknown_size1677=== CONT TestProxyWriteTimeout/1_GiB_nar1678--- PASS: TestProxyWriteTimeout (0.00s)1679 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1680 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1681 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1682 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1683=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1684=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16852026/10/04 20:06:50 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]1686=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1687=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16882026/10/04 20:06:50 WARN Authentication failed token_preview=eyJhbGciOi...Z9E9oUCgsg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1689=== CONT TestService_RequireScope_OIDC/builder_may_write1690--- PASS: TestService_AuthMiddleware_OIDC (1.01s)1691 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1692 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1693 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1694 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1695=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read16962026/10/04 20:06:50 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1697=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1698=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1699=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1700=== CONT TestService_RequireScope_OIDC/writer_implies_read1701=== CONT TestService_RequireScope_OIDC/reader_may_read1702=== CONT TestService_RequireScope_OIDC/static_token_may_write1703=== CONT TestService_RequireScope_OIDC/static_token_may_admin1704=== CONT TestService_RequireScope_OIDC/reader_may_not_write1705=== CONT TestService_RequireScope_OIDC/ops_may_not_write1706=== CONT TestService_RequireScope_OIDC/ops_may_admin1707=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1708=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1709=== CONT TestIsValidCachePath/narinfo1710=== CONT TestIsValidCachePath/traversal_parent1711=== CONT TestIsValidCachePath/index.html1712=== CONT TestIsValidCachePath/nix-cache-info1713=== CONT TestIsValidCachePath/realisation1714=== CONT TestIsValidCachePath/log1715=== CONT TestIsValidCachePath/ls1716=== CONT TestIsValidCachePath/nar_uncompressed1717=== CONT TestIsValidCachePath/nar_bz21718=== CONT TestIsValidCachePath/traversal_in_middle1719=== CONT TestIsValidCachePath/nar_xz1720=== CONT TestIsValidCachePath/nar_zst1721--- PASS: TestService_RequireScope_OIDC (1.01s)1722 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1723 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1724 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1725 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1726 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1727 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1728 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1729 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1730 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1731 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1732 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1733 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1734 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1735 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1736=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1737=== CONT TestIsValidCachePath/empty1738=== CONT TestIsValidCachePath/short_hash1739=== CONT TestIsValidCachePath/wrong_extension1740=== CONT TestIsValidCachePath/leading_slash1741=== CONT TestIsValidCachePath/invalid_char_u1742=== CONT TestIsValidCachePath/random_path1743=== CONT TestIsValidCachePath/invalid_char_e1744--- PASS: TestIsValidCachePath (0.00s)1745 --- PASS: TestIsValidCachePath/narinfo (0.00s)1746 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1747 --- PASS: TestIsValidCachePath/index.html (0.00s)1748 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1749 --- PASS: TestIsValidCachePath/realisation (0.00s)1750 --- PASS: TestIsValidCachePath/log (0.00s)1751 --- PASS: TestIsValidCachePath/ls (0.00s)1752 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1753 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1754 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1755 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1756 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1757 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1758 --- PASS: TestIsValidCachePath/empty (0.00s)1759 --- PASS: TestIsValidCachePath/short_hash (0.00s)1760 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1761 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1762 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1763 --- PASS: TestIsValidCachePath/random_path (0.00s)1764 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1765=== CONT TestPush_RejectsBadRequests/bad_root17662026/10/04 20:06:50 INFO Received push request method=POST path=/api/pushes1767=== CONT TestPush_RejectsBadRequests/no_roots17682026/10/04 20:06:50 INFO Received push request method=POST path=/api/pushes1769=== CONT TestPush_RejectsBadRequests/no_objects17702026/10/04 20:06:50 INFO Received push request method=POST path=/api/pushes1771=== CONT TestPush_RejectsBadRequests/root_not_in_objects17722026/10/04 20:06:50 INFO Received push request method=POST path=/api/pushes1773=== CONT TestParseSingleRange/none1774--- PASS: TestPush_RejectsBadRequests (0.51s)1775 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1776 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1777 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1778 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1779=== CONT TestParseSingleRange/open-ended1780=== CONT TestParseSingleRange/start_far_past_EOF1781=== CONT TestParseSingleRange/start_past_EOF1782=== CONT TestParseSingleRange/single_byte1783=== CONT TestParseSingleRange/suffix_exceeds_size1784=== CONT TestParseSingleRange/suffix1785=== CONT TestParseSingleRange/end_clamped_to_size1786=== CONT TestParseSingleRange/malformed_both_empty1787=== CONT TestParseSingleRange/closed1788=== CONT TestParseSingleRange/multi-range_ignored1789=== CONT TestParseSingleRange/malformed_no_dash1790=== CONT TestParseSingleRange/unknown_unit1791=== CONT TestParseSingleRange/malformed_end_before_start1792--- PASS: TestParseSingleRange (0.00s)1793 --- PASS: TestParseSingleRange/none (0.00s)1794 --- PASS: TestParseSingleRange/open-ended (0.00s)1795 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1796 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1797 --- PASS: TestParseSingleRange/single_byte (0.00s)1798 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1799 --- PASS: TestParseSingleRange/suffix (0.00s)1800 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1801 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1802 --- PASS: TestParseSingleRange/closed (0.00s)1803 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1804 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1805 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1806 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1807=== CONT TestServerTLSConfig/no_client_CA1808=== CONT TestServerTLSConfig/not_a_PEM_file1809=== CONT TestServerTLSConfig/missing_CA_file1810--- PASS: TestServerTLSConfig (0.00s)1811 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1812 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1813 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)18142026/10/04 20:06:50 INFO Received push request method=POST path=/api/pushes18152026/10/04 20:06:50 INFO Received uploads request method=POST path=/api/pending_closures18162026/10/04 20:06:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18172026/10/04 20:06:50 INFO Uploading n962h66ivjap2xrl3p2cpwp5g4ggk8wh-file1.txt (160B)18182026/10/04 20:06:50 INFO Aborted multipart uploads count=0 kept=018192026/10/04 20:06:50 WARN Force mode enabled - objects will be deleted immediately without grace period18202026/10/04 20:06:50 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18212026/10/04 20:06:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18222026/10/04 20:06:50 WARN Failed to register uploaded object key=n962h66ivjap2xrl3p2cpwp5g4ggk8wh.ls error="server returned 404: 404 page not found\n"18232026/10/04 20:06:50 INFO Signed narinfos id=1 count=118242026/10/04 20:06:50 INFO Uploading 1 narinfos18252026/10/04 20:06:50 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"18262026/10/04 20:06:50 INFO Received complete push request method=POST path=/api/pushes/1/complete18272026/10/04 20:06:50 WARN Failed to register uploaded object key=n962h66ivjap2xrl3p2cpwp5g4ggk8wh.narinfo error="server returned 404: 404 page not found\n"1828=== NAME TestOrphanedObjectsGC1829 orphaned_objects_gc_test.go:290: GC Test Summary:1830 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1831 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1832 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1833 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1834 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1835--- PASS: TestOrphanedObjectsGC (0.85s)18362026/10/04 20:06:50 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=018372026/10/04 20:06:50 INFO Vacuumed table table=pending_closures18382026/10/04 20:06:50 INFO Vacuumed table table=pending_objects18392026/10/04 20:06:50 INFO Vacuumed table table=multipart_uploads18402026/10/04 20:06:50 INFO Vacuumed table table=closures18412026/10/04 20:06:50 INFO Upload complete. (66ms)1842=== NAME TestNARDeduplicationMetadataUploadBug1843 metadata_upload_test.go:54: Retrieved narinfo from S3:1844 StorePath: /build/TestNARDeduplicationMetadataUploadBug2854895937/001/store/n962h66ivjap2xrl3p2cpwp5g4ggk8wh-file1.txt1845 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1846 Compression: zstd1847 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1848 NarSize: 1601849 References: 1850 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf18512026/10/04 20:06:50 INFO Vacuumed table table=objects1852 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1853 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1854 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18552026/10/04 20:06:50 INFO Received uploads request method=POST path=/api/pending_closures18562026/10/04 20:06:50 INFO Aborted multipart uploads count=0 kept=018572026/10/04 20:06:50 WARN Force mode enabled - objects will be deleted immediately without grace period18582026/10/04 20:06:50 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=018592026/10/04 20:06:50 INFO Vacuumed table table=pending_closures18602026/10/04 20:06:50 INFO Vacuumed table table=pending_objects18612026/10/04 20:06:50 INFO Vacuumed table table=multipart_uploads18622026/10/04 20:06:50 INFO Vacuumed table table=closures18632026/10/04 20:06:50 INFO Vacuumed table table=objects18642026/10/04 20:06:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1865 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2854895937/001/store/3gvzp4j5lhg9misxp3h41xjklb1s7i5l-file2.txt1866--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1867 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.55s)1868 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.54s)18692026/10/04 20:06:50 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NWNkMGM0ZDktOTk1NS00N2EwLWE5MTUtNzcwMjUwODkxZTQ0LjYyMDE0MGRhLThmMjYtNDVhZi1iYzg4LWVkNDM0MmZkZDgyM3gxNzkxMTQ0NDEwMzY1MjU2NDM0 error="Get \"http://127.0.0.1:1/bucket48/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"18702026/10/04 20:06:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NWNkMGM0ZDktOTk1NS00N2EwLWE5MTUtNzcwMjUwODkxZTQ0LjdlMTQ2ODZkLWVhYjgtNDllZC1hOTc3LTU1MjcyODY3ODM5MXgxNzkxMTQ0NDEwMzU0MDc3ODA1 parts=1218712026/10/04 20:06:50 INFO Received cleanup request method=DELETE path=/api/pending_closures18722026/10/04 20:06:50 INFO Aborted multipart uploads count=1 kept=01873--- PASS: TestRedundantMultipartUpload (1.96s)18742026/10/04 20:06:50 INFO Aborted multipart uploads count=0 kept=018752026/10/04 20:06:50 WARN Force mode enabled - objects will be deleted immediately without grace period18762026/10/04 20:06:51 INFO Aborted multipart uploads count=0 kept=018772026/10/04 20:06:51 WARN Force mode enabled - objects will be deleted immediately without grace period18782026/10/04 20:06:51 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:46315/bucket87/?delete=\": context canceled"1879--- PASS: TestGCEndsOnShutdown (0.00s)1880 --- PASS: TestGCEndsOnShutdown/before_the_run (0.44s)1881 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.40s)1882 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.38s)18832026/10/04 20:06:51 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=364.473835ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18842026/10/04 20:06:51 INFO Received push request method=POST path=/api/pushes18852026/10/04 20:06:51 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18862026/10/04 20:06:51 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18872026/10/04 20:06:51 INFO Signed narinfos id=2 count=118882026/10/04 20:06:51 WARN Failed to register uploaded object key=3gvzp4j5lhg9misxp3h41xjklb1s7i5l.ls error="server returned 404: 404 page not found\n"18892026/10/04 20:06:51 INFO Uploading 1 narinfos18902026/10/04 20:06:51 INFO Received complete push request method=POST path=/api/pushes/2/complete18912026/10/04 20:06:51 WARN Failed to register uploaded object key=3gvzp4j5lhg9misxp3h41xjklb1s7i5l.narinfo error="server returned 404: 404 page not found\n"18922026/10/04 20:06:51 INFO Upload complete. (49ms)1893=== NAME TestNARDeduplicationMetadataUploadBug1894 metadata_upload_test.go:76: Retrieved narinfo from S3:1895 StorePath: /build/TestNARDeduplicationMetadataUploadBug2854895937/001/store/3gvzp4j5lhg9misxp3h41xjklb1s7i5l-file2.txt1896 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1897 Compression: zstd1898 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1899 NarSize: 1601900 References: 1901 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1902 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1903 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1904 {"version":1,"root":{"type":"regular","size":44}}1905--- PASS: TestNARDeduplicationMetadataUploadBug (0.78s)19062026/10/04 20:06:51 INFO Received uploads request method=POST path=/api/pending_closures19072026/10/04 20:06:51 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19082026/10/04 20:06:51 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161909--- PASS: TestReadProxyNarinfo (0.79s)19102026/10/04 20:06:51 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19112026/10/04 20:06:51 INFO lead: released remote=192.0.2.1:12341912--- PASS: TestLeadElectsOneAndHandsOver (3.44s)19132026/10/04 20:06:51 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=782.234924ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19142026/10/04 20:06:51 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019152026/10/04 20:06:51 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019162026/10/04 20:06:51 INFO Received create pin request method=POST path=/api/pins/myapp1917=== NAME TestClientIntegration1918 client_integration_test.go:323: Objects in database after GC:1919 client_integration_test.go:323: Successfully deleted all objects with GC --force19202026/10/04 20:06:51 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1322494980/001/store/4zd5mpjql3mmvk5x1086r0qgzkdbjghi-pinned-file.txt narinfo_key=4zd5mpjql3mmvk5x1086r0qgzkdbjghi.narinfo19212026/10/04 20:06:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures19222026/10/04 20:06:51 INFO Garbage collection started1923--- PASS: TestClientIntegration (3.22s)19242026/10/04 20:06:51 INFO Aborted multipart uploads count=0 kept=019252026/10/04 20:06:51 WARN Force mode enabled - objects will be deleted immediately without grace period19262026/10/04 20:06:51 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=019272026/10/04 20:06:51 INFO Vacuumed table table=pending_closures19282026/10/04 20:06:51 INFO Vacuumed table table=pending_objects19292026/10/04 20:06:51 INFO Vacuumed table table=multipart_uploads19302026/10/04 20:06:51 INFO Vacuumed table table=closures19312026/10/04 20:06:51 INFO Vacuumed table table=objects1932--- PASS: TestUploadHandlersRejectOversizedBody (0.29s)1933 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1934 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1935 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.82s)1936--- PASS: TestPendingClosureWriteTimeout (0.00s)1937 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1938 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1939 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1940 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.06s)1941=== NAME TestOrphanedObjectsGCStressTest1942 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1943 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19442026/10/04 20:06:52 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.538310982s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1945 orphaned_objects_gc_test.go:509: Stress test completed successfully:1946 orphaned_objects_gc_test.go:510: - Active objects preserved: 201947 orphaned_objects_gc_test.go:511: - Objects deleted: 2101948 orphaned_objects_gc_test.go:512: - Total GC'd: 2101949--- PASS: TestOrphanedObjectsGCStressTest (2.43s)1950--- PASS: TestConnectWaitsForAPeerMigration (5.15s)19512026/10/04 20:06:53 WARN Rate limiter enabled after throttle name=s3-test rate=519522026/10/04 20:06:53 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1953=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1954 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101955 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001956--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.44s)1957=== NAME TestPinProtectsFromGC1958 client_integration_test.go:840: Pin successfully protected closure from garbage collection1959--- PASS: TestPinProtectsFromGC (5.33s)19602026/10/04 20:06:53 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-config19612026/10/04 20:06:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.256448ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19622026/10/04 20:06:54 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=389.785162ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1963--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.97s)19642026/10/04 20:06:54 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=741.611615ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19652026/10/04 20:06:55 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.566791752s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19662026/10/04 20:06:56 INFO Aborted multipart uploads count=1 kept=019672026/10/04 20:06:56 INFO Received cleanup request method=DELETE path=/api/pending_closures19682026/10/04 20:06:56 INFO Aborted multipart uploads count=1 kept=01969--- PASS: TestPendingCleanupUsesOneCutoff (6.52s)19702026/10/04 20:06:56 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"19712026/10/04 20:06:56 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-config19722026/10/04 20:06:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.530853ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19732026/10/04 20:06:57 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=431.050958ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19742026/10/04 20:06:57 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=725.659047ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19752026/10/04 20:06:58 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.745891711s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19762026/10/04 20:06:59 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_closures19772026/10/04 20:07:00 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.522177ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19782026/10/04 20:07:00 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=410.156717ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19792026/10/04 20:07:00 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=770.082312ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19802026/10/04 20:07:01 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.591753415s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1981--- PASS: TestClientErrorHandling (0.00s)1982 --- PASS: TestClientErrorHandling/InvalidStorePath (0.40s)1983 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.44s)1984 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.42s)1985PASS1986{"timestamp":"2026-10-04T20:07:03.075130626Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:38046","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(394)"}1987{"timestamp":"2026-10-04T20:07:03.075507635Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:38392","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(393)"}19882026-10-04 20:07:03.425 UTC [128] LOG: received smart shutdown request19892026-10-04 20:07:03.431 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 119902026-10-04 20:07:03.441 UTC [133] LOG: shutting down19912026-10-04 20:07:03.442 UTC [133] LOG: checkpoint starting: shutdown immediate19922026-10-04 20:07:05.661 UTC [133] LOG: checkpoint complete: wrote 11139 buffers (68.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.242 s, sync=1.918 s, total=2.220 s; sync files=30664, longest=0.029 s, average=0.001 s; distance=423950 kB, estimate=423950 kB; lsn=0/1B569730, redo lsn=0/1B56973019932026-10-04 20:07:05.741 UTC [128] LOG: database system is shut down1994Running OIDC tests...1995=== RUN TestAudienceForIssuer1996=== PAUSE TestAudienceForIssuer1997=== RUN TestGlobMatch1998=== PAUSE TestGlobMatch1999=== RUN TestValidateToken_ValidToken2000=== PAUSE TestValidateToken_ValidToken2001=== RUN TestValidateToken_WrongAudience2002=== PAUSE TestValidateToken_WrongAudience2003=== RUN TestValidateToken_Expired2004=== PAUSE TestValidateToken_Expired2005=== RUN TestValidateToken_BoundClaimsMismatch2006=== PAUSE TestValidateToken_BoundClaimsMismatch2007=== RUN TestValidateToken_BoundSubjectMismatch2008=== PAUSE TestValidateToken_BoundSubjectMismatch2009=== RUN TestValidateToken_MultipleProviders2010=== PAUSE TestValidateToken_MultipleProviders2011=== RUN TestValidateToken_NoMatchingProvider2012=== PAUSE TestValidateToken_NoMatchingProvider2013=== RUN TestValidateToken_KubernetesServiceAccount2014=== PAUSE TestValidateToken_KubernetesServiceAccount2015=== RUN TestNewValidator_KubernetesRequiresCA2016=== PAUSE TestNewValidator_KubernetesRequiresCA2017=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2018=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2019=== RUN TestPins_ReservedForMatchingRule2020=== PAUSE TestPins_ReservedForMatchingRule2021=== RUN TestPins_TopLevelShorthand2022=== PAUSE TestPins_TopLevelShorthand2023=== RUN TestPins_ConfigValidation2024=== PAUSE TestPins_ConfigValidation2025=== RUN TestScopes_LegacyProviderDefaultsToWrite2026=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2027=== RUN TestScopes_Rules2028=== PAUSE TestScopes_Rules2029=== RUN TestScopes_ConfigValidation2030=== PAUSE TestScopes_ConfigValidation2031=== CONT TestAudienceForIssuer2032=== CONT TestValidateToken_KubernetesServiceAccount2033=== CONT TestValidateToken_BoundClaimsMismatch2034=== CONT TestValidateToken_NoMatchingProvider2035=== CONT TestValidateToken_MultipleProviders2036=== CONT TestValidateToken_BoundSubjectMismatch2037=== CONT TestValidateToken_WrongAudience2038--- PASS: TestAudienceForIssuer (0.00s)2039=== CONT TestValidateToken_ValidToken2040=== CONT TestGlobMatch2041=== RUN TestGlobMatch/foo_foo2042=== PAUSE TestGlobMatch/foo_foo2043=== RUN TestGlobMatch/foo_bar2044=== PAUSE TestGlobMatch/foo_bar2045=== RUN TestGlobMatch/*_2046=== PAUSE TestGlobMatch/*_2047=== RUN TestGlobMatch/*_anything2048=== CONT TestPins_ReservedForMatchingRule2049=== CONT TestPins_TopLevelShorthand2050=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2051=== CONT TestScopes_Rules2052=== CONT TestScopes_ConfigValidation2053=== CONT TestScopes_LegacyProviderDefaultsToWrite2054=== CONT TestValidateToken_Expired2055=== CONT TestNewValidator_KubernetesRequiresCA2056=== CONT TestPins_ConfigValidation2057=== PAUSE TestGlobMatch/*_anything2058=== RUN TestGlobMatch/foo*_foo2059=== PAUSE TestGlobMatch/foo*_foo2060=== RUN TestGlobMatch/foo*_foobar2061=== PAUSE TestGlobMatch/foo*_foobar2062=== RUN TestGlobMatch/foo*_bar2063=== PAUSE TestGlobMatch/foo*_bar2064=== RUN TestGlobMatch/*bar_bar2065=== PAUSE TestGlobMatch/*bar_bar2066=== RUN TestGlobMatch/*bar_foobar2067=== PAUSE TestGlobMatch/*bar_foobar2068=== RUN TestGlobMatch/*bar_foo2069=== PAUSE TestGlobMatch/*bar_foo2070=== RUN TestGlobMatch/foo*bar_foobar2071=== PAUSE TestGlobMatch/foo*bar_foobar2072=== RUN TestGlobMatch/foo*bar_foo123bar2073=== PAUSE TestGlobMatch/foo*bar_foo123bar2074=== RUN TestGlobMatch/foo*bar_foobarbaz2075=== PAUSE TestGlobMatch/foo*bar_foobarbaz2076=== RUN TestGlobMatch/*/*_foo/bar2077=== PAUSE TestGlobMatch/*/*_foo/bar2078=== RUN TestGlobMatch/*/*_foo2079=== PAUSE TestGlobMatch/*/*_foo2080=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2081=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2082=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02083=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02084=== RUN TestGlobMatch/refs/*/main_refs/heads/main2085=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2086=== RUN TestGlobMatch/fo?_foo2087=== PAUSE TestGlobMatch/fo?_foo2088=== RUN TestGlobMatch/fo?_fo2089=== PAUSE TestGlobMatch/fo?_fo2090=== RUN TestGlobMatch/fo?_fooo2091=== PAUSE TestGlobMatch/fo?_fooo2092=== RUN TestGlobMatch/?oo_foo2093=== PAUSE TestGlobMatch/?oo_foo2094=== RUN TestGlobMatch/?oo_boo2095=== PAUSE TestGlobMatch/?oo_boo2096=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2097=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2098=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2099=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2100=== CONT TestGlobMatch/foo_foo2101=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2102=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2103=== CONT TestGlobMatch/?oo_boo2104=== CONT TestGlobMatch/?oo_foo2105=== CONT TestGlobMatch/fo?_fooo2106=== CONT TestGlobMatch/fo?_fo2107=== CONT TestGlobMatch/fo?_foo2108=== CONT TestGlobMatch/refs/*/main_refs/heads/main2109=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02110=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2111=== CONT TestGlobMatch/*/*_foo2112=== CONT TestGlobMatch/*/*_foo/bar2113=== CONT TestGlobMatch/foo*bar_foobarbaz2114=== CONT TestGlobMatch/foo*bar_foo123bar2115=== CONT TestGlobMatch/foo*bar_foobar2116=== CONT TestGlobMatch/*bar_foo2117=== CONT TestGlobMatch/*bar_foobar2118=== CONT TestGlobMatch/*bar_bar2119=== CONT TestGlobMatch/foo*_bar2120=== CONT TestGlobMatch/foo*_foobar2121=== CONT TestGlobMatch/foo*_foo2122=== CONT TestGlobMatch/*_anything2123=== CONT TestGlobMatch/*_2124=== CONT TestGlobMatch/foo_bar2125--- PASS: TestGlobMatch (0.00s)2126 --- PASS: TestGlobMatch/foo_foo (0.00s)2127 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2128 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2129 --- PASS: TestGlobMatch/?oo_boo (0.00s)2130 --- PASS: TestGlobMatch/?oo_foo (0.00s)2131 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2132 --- PASS: TestGlobMatch/fo?_fo (0.00s)2133 --- PASS: TestGlobMatch/fo?_foo (0.00s)2134 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2135 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2136 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2137 --- PASS: TestGlobMatch/*/*_foo (0.00s)2138 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2139 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2140 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2141 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2142 --- PASS: TestGlobMatch/*bar_foo (0.00s)2143 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2144 --- PASS: TestGlobMatch/*bar_bar (0.00s)2145 --- PASS: TestGlobMatch/foo*_bar (0.00s)2146 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2147 --- PASS: TestGlobMatch/foo*_foo (0.00s)2148 --- PASS: TestGlobMatch/*_anything (0.00s)2149 --- PASS: TestGlobMatch/*_ (0.00s)2150 --- PASS: TestGlobMatch/foo_bar (0.00s)2151--- PASS: TestPins_ConfigValidation (0.00s)2152--- PASS: TestScopes_ConfigValidation (0.00s)21532026/10/04 20:07:07 http: TLS handshake error from 127.0.0.1:40340: remote error: tls: bad certificate2154--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)21552026/10/04 20:07:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39285/oidc2156--- PASS: TestPins_TopLevelShorthand (0.03s)21572026/10/04 20:07:07 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:441712158--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)21592026/10/04 20:07:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40327/oidc21602026/10/04 20:07:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33507/oidc2161--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)2162--- PASS: TestValidateToken_Expired (0.07s)21632026/10/04 20:07:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36893/oidc2164--- PASS: TestScopes_Rules (0.08s)21652026/10/04 20:07:07 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232166--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)21672026/10/04 20:07:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40939/oidc2168--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.10s)21692026/10/04 20:07:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44099/oidc2170--- PASS: TestValidateToken_ValidToken (0.10s)21712026/10/04 20:07:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45589/oidc2172--- PASS: TestValidateToken_BoundSubjectMismatch (0.12s)21732026/10/04 20:07:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40753/oidc2174--- PASS: TestValidateToken_WrongAudience (0.13s)21752026/10/04 20:07:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34549/oidc2176--- PASS: TestPins_ReservedForMatchingRule (0.14s)21772026/10/04 20:07:07 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41383/oidc2178--- PASS: TestValidateToken_NoMatchingProvider (0.18s)21792026/10/04 20:07:07 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43037/oidc21802026/10/04 20:07:07 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38443/oidc2181--- PASS: TestValidateToken_MultipleProviders (0.22s)2182PASS2183Running hook tests...2184=== RUN TestSendPathsEmpty2185=== PAUSE TestSendPathsEmpty2186=== RUN TestQueueEnqueueAndFetch2187=== PAUSE TestQueueEnqueueAndFetch2188=== RUN TestQueueDeduplication2189=== PAUSE TestQueueDeduplication2190=== RUN TestQueueRemove2191=== PAUSE TestQueueRemove2192=== RUN TestQueueFetchBatchLimit2193=== PAUSE TestQueueFetchBatchLimit2194=== RUN TestQueueRetryMovesToBack2195=== PAUSE TestQueueRetryMovesToBack2196=== RUN TestQueueFetchRemoveLifecycle2197=== PAUSE TestQueueFetchRemoveLifecycle2198=== RUN TestQueueConcurrentWriters2199=== PAUSE TestQueueConcurrentWriters2200=== RUN TestQueueRemoveLargeClosure2201=== PAUSE TestQueueRemoveLargeClosure2202=== RUN TestServerClientIntegration2203=== PAUSE TestServerClientIntegration2204=== RUN TestServerQueueError2205=== PAUSE TestServerQueueError2206=== RUN TestGetListenerSocketActivation2207 server_test.go:210: === RUN TestGetListenerSocketActivation2208 --- PASS: TestGetListenerSocketActivation (0.00s)2209 PASS2210 2211--- PASS: TestGetListenerSocketActivation (0.01s)2212=== RUN TestDrainIsolatesPoisonPath2213=== PAUSE TestDrainIsolatesPoisonPath2214=== RUN TestRunNotBlockedByPoisonHead2215=== PAUSE TestRunNotBlockedByPoisonHead2216=== RUN TestDrainGivesUpWhenServerDown2217=== PAUSE TestDrainGivesUpWhenServerDown2218=== RUN TestFailedPathPrunedByLaterClosure2219=== PAUSE TestFailedPathPrunedByLaterClosure2220=== RUN TestWorkerUploadsAndRemoves2221=== PAUSE TestWorkerUploadsAndRemoves2222=== RUN TestWorkerSkipsGCdPaths2223=== PAUSE TestWorkerSkipsGCdPaths2224=== RUN TestWorkerPrunesClosureDeps2225=== PAUSE TestWorkerPrunesClosureDeps2226=== RUN TestDrainTimeout2227=== PAUSE TestDrainTimeout2228=== CONT TestSendPathsEmpty2229=== CONT TestDrainTimeout2230=== CONT TestFailedPathPrunedByLaterClosure2231=== CONT TestWorkerPrunesClosureDeps2232--- PASS: TestSendPathsEmpty (0.00s)2233=== CONT TestServerQueueError2234=== CONT TestWorkerSkipsGCdPaths2235=== CONT TestQueueFetchBatchLimit2236=== CONT TestQueueRemove2237=== CONT TestQueueDeduplication2238=== CONT TestWorkerUploadsAndRemoves2239=== CONT TestQueueEnqueueAndFetch22402026/10/04 20:07:07 ERROR Failed to queue paths error="permission denied" count=12241=== CONT TestRunNotBlockedByPoisonHead2242=== CONT TestQueueRemoveLargeClosure2243=== CONT TestDrainGivesUpWhenServerDown2244=== CONT TestServerClientIntegration2245=== CONT TestQueueFetchRemoveLifecycle2246=== CONT TestQueueConcurrentWriters2247=== CONT TestDrainIsolatesPoisonPath2248=== CONT TestQueueRetryMovesToBack2249--- PASS: TestServerQueueError (0.00s)2250--- PASS: TestServerClientIntegration (0.00s)22512026/10/04 20:07:07 INFO Upload queue status pending=322522026/10/04 20:07:07 INFO Uploading batch count=122532026/10/04 20:07:07 ERROR Upload failed error="upload failed" count=122542026/10/04 20:07:07 INFO Upload queue status pending=222552026/10/04 20:07:07 INFO Upload queue status pending=222562026/10/04 20:07:07 INFO Uploading batch count=122572026/10/04 20:07:07 ERROR Upload failed error="upload failed" count=122582026/10/04 20:07:07 INFO Uploading batch count=222592026/10/04 20:07:07 INFO Uploading batch count=122602026/10/04 20:07:07 INFO Uploading batch count=222612026/10/04 20:07:07 INFO Uploading batch count=222622026/10/04 20:07:07 ERROR Upload failed error="upload failed" count=222632026/10/04 20:07:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3911701816/002/a22642026/10/04 20:07:07 INFO Uploading batch count=42265--- PASS: TestQueueDeduplication (0.02s)22662026/10/04 20:07:07 ERROR Upload failed error="upload failed" count=422672026/10/04 20:07:07 INFO Upload queue status pending=22268--- PASS: TestQueueFetchBatchLimit (0.02s)2269--- PASS: TestQueueRetryMovesToBack (0.02s)22702026/10/04 20:07:07 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2653525960/002/nonexistent22712026/10/04 20:07:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3668221508/002/bbb22722026/10/04 20:07:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3911701816/002/b2273--- PASS: TestQueueEnqueueAndFetch (0.02s)22742026/10/04 20:07:07 INFO Uploading batch count=122752026/10/04 20:07:07 INFO Uploading batch count=12276--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22772026/10/04 20:07:07 INFO Uploading batch count=122782026/10/04 20:07:07 INFO Uploading batch count=222792026/10/04 20:07:07 ERROR Upload failed error="upload failed" count=222802026/10/04 20:07:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3911701816/002/c2281--- PASS: TestQueueRemove (0.02s)22822026/10/04 20:07:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3911701816/002/d22832026/10/04 20:07:07 INFO Uploading batch count=122842026/10/04 20:07:07 ERROR Upload failed error="upload failed" count=122852026/10/04 20:07:07 INFO Uploading batch count=222862026/10/04 20:07:07 ERROR Upload failed error="upload failed" count=222872026/10/04 20:07:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3911701816/002/e22882026/10/04 20:07:07 INFO Uploading batch count=122892026/10/04 20:07:07 ERROR Upload failed error="upload failed" count=12290--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22912026/10/04 20:07:07 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3911701816/002/f22922026/10/04 20:07:07 INFO Uploading batch count=122932026/10/04 20:07:07 ERROR Upload failed error="upload failed" count=122942026/10/04 20:07:07 ERROR Drain finished with paths left in queue remaining=1022952026/10/04 20:07:07 ERROR Drain finished with paths left in queue remaining=12296--- PASS: TestDrainIsolatesPoisonPath (0.02s)2297--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2298--- PASS: TestWorkerUploadsAndRemoves (0.04s)2299--- PASS: TestWorkerPrunesClosureDeps (0.04s)2300--- PASS: TestWorkerSkipsGCdPaths (0.04s)2301--- PASS: TestQueueRemoveLargeClosure (0.10s)23022026/10/04 20:07:08 ERROR Upload failed error="context deadline exceeded" count=223032026/10/04 20:07:08 ERROR Drain finished with paths left in queue remaining=42304--- PASS: TestDrainTimeout (0.22s)2305--- PASS: TestQueueConcurrentWriters (0.38s)23062026/10/04 20:07:08 INFO Uploading batch count=123072026/10/04 20:07:08 INFO Uploading batch count=123082026/10/04 20:07:08 INFO Uploading batch count=123092026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=123102026/10/04 20:07:08 INFO Uploading batch count=123112026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=123122026/10/04 20:07:08 INFO Uploading batch count=123132026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=123142026/10/04 20:07:08 INFO Uploading batch count=123152026/10/04 20:07:08 ERROR Upload failed error="upload failed" count=123162026/10/04 20:07:08 ERROR Drain finished with paths left in queue remaining=12317--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2318PASS