niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #347
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestShellSplit97--- PASS: TestShellSplit (0.00s)98=== CONT TestEncodeNixBase32WithRealHash99=== CONT TestDoWithRetry_BodyReplayedViaGetBody100--- PASS: TestEncodeNixBase32WithRealHash (0.00s)101=== CONT TestScriptTokenScriptFails102=== CONT TestResolveStorePath103=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess104=== CONT TestRateLimiterFeedback105=== CONT TestPathInfoHashCompatibility106=== CONT TestGetStorePathHash107=== RUN TestGetStorePathHash/valid_store_path108=== PAUSE TestGetStorePathHash/valid_store_path109=== CONT TestConvertHashToNix32110=== CONT TestUploadMultipart_SupersededByPeer1112026/10/01 13:03:34 WARN Rate limiter enabled after throttle name=server-test rate=5112=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)113=== CONT TestEncodeNixBase32114=== CONT TestDumpPathWriterError115=== RUN TestUploadMultipart_SupersededByPeer/exists116=== PAUSE TestUploadMultipart_SupersededByPeer/exists117=== RUN TestUploadMultipart_SupersededByPeer/missing118=== RUN TestConvertHashToNix32/SRI_format_to_Nix32119=== RUN TestEncodeNixBase32/test_string_hash120=== PAUSE TestEncodeNixBase32/test_string_hash121=== RUN TestEncodeNixBase32/empty_input122=== CONT TestDumpPathMatchesNix123=== CONT TestPathInfoCACompatibility124=== PAUSE TestEncodeNixBase32/empty_input125=== CONT TestParsePathInfoJSONMultiplePaths126=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths127=== CONT TestStreamPushRequestLine128=== CONT TestSetClientTLSDoesNotMutateDefaultTransport129=== CONT TestSetClientTLS130=== CONT TestClientSignaturesByStorePath131=== CONT TestParsePathInfoJSON132=== CONT TestStreamPushReportsSignatures133=== CONT TestSetClientTLSErrors134=== CONT TestScriptTokenCachesUntilRefresh135=== RUN TestRateLimiterFeedback/429_enables_limiter136=== RUN TestGetStorePathHash/basename_without_hyphen_should_error137=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)138=== CONT TestDumpPathSingleFile139--- PASS: TestScriptTokenScriptFails (0.00s)140=== PAUSE TestUploadMultipart_SupersededByPeer/missing141=== RUN TestParsePathInfoJSON/Nix_format142=== CONT TestScriptTokenEmptyCommand143=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32144=== RUN TestPathInfoCACompatibility/null_ca_field145=== CONT TestScriptTokenBadJSON146=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths147=== PAUSE TestRateLimiterFeedback/429_enables_limiter148=== CONT TestScriptTokenEmptyToken149--- PASS: TestScriptTokenEmptyCommand (0.00s)150=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error151=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon152=== RUN TestConvertHashToNix32/already_Nix32_format153--- PASS: TestResolveStorePath (0.01s)154=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error1552026/10/01 13:03:34 ERROR Upload failed error=boom count=1156--- PASS: TestStreamPushReportsSignatures (0.00s)157=== CONT TestScriptTokenNoExpiryRerunsEveryCall158=== PAUSE TestPathInfoCACompatibility/null_ca_field159=== RUN TestPathInfoCACompatibility/old_string_format_-_text160=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text161=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive162=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive163=== RUN TestPathInfoCACompatibility/new_structured_format_-_text164=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text165=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method166=== RUN TestRateLimiterFeedback/503_enables_limiter167=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method168=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths169=== CONT TestStreamPushBatchesUnderLoad170=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1712026/10/01 13:03:34 WARN Rate limiter enabled after throttle name=server-test rate=5172--- PASS: TestClientSignaturesByStorePath (0.00s)173=== CONT TestFileTokenMissing174=== PAUSE TestRateLimiterFeedback/503_enables_limiter175=== PAUSE TestParsePathInfoJSON/Nix_format176=== CONT TestFilterOversizedClosures177=== CONT TestFileTokenEmpty178=== CONT TestPartSizeForNAR179=== RUN TestParsePathInfoJSON/Lix_format180=== RUN TestPartSizeForNAR/zero_stays_at_minimum181=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum182=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter1832026/10/01 13:03:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35757184=== PAUSE TestParsePathInfoJSON/Lix_format185--- PASS: TestDoServerRequestAttachesToken (0.01s)186=== RUN TestFilterOversizedClosures/no_limit_keeps_everything187=== RUN TestPartSizeForNAR/small_stays_at_minimum188=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon189=== CONT TestFileTokenReadsAndCaches190=== RUN TestParsePathInfoJSON/empty_input191--- PASS: TestScriptTokenEmptyToken (0.00s)192--- PASS: TestFileTokenMissing (0.00s)193--- PASS: TestFileTokenEmpty (0.00s)194=== CONT TestStreamPushIsolatesFailures195=== CONT TestStaticToken196=== PAUSE TestPartSizeForNAR/small_stays_at_minimum197=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum198=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum199=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts200=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts201=== RUN TestPartSizeForNAR/1_TiB202=== PAUSE TestPartSizeForNAR/1_TiB203=== RUN TestPartSizeForNAR/5_TiB_S3_max_object2042026/10/01 13:03:34 ERROR Upload failed error="bad path" count=3205--- PASS: TestStaticToken (0.00s)206=== PAUSE TestConvertHashToNix32/already_Nix32_format207=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything208=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped209=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error210=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter2112026/10/01 13:03:34 ERROR Upload failed error=boom count=1212=== CONT TestStreamPushReportsEveryPath213=== CONT TestStreamPushGivesUpOnDeadServer214=== PAUSE TestParsePathInfoJSON/empty_input215=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object216=== RUN TestConvertHashToNix32/invalid_format217--- PASS: TestScriptTokenBadJSON (0.00s)218--- PASS: TestStreamPushIsolatesFailures (0.00s)219=== CONT TestShellSplitErrors220--- PASS: TestShellSplitErrors (0.00s)221=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter2222026/10/01 13:03:34 WARN Rate limiter backed off name=server-test rate=5223=== RUN TestPartSizeForNAR/capped_at_5_GiB2242026/10/01 13:03:34 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35757225=== PAUSE TestPartSizeForNAR/capped_at_5_GiB226=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped227=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter228=== CONT TestCaseHackSuffix229=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI230--- PASS: TestStreamPushReportsEveryPath (0.00s)231=== CONT TestRegisterUploadedObjectReusesConnections232=== RUN TestParsePathInfoJSON/whitespace_only2332026/10/01 13:03:34 ERROR Upload failed error="connection refused" count=20234=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error235=== CONT TestUploadMultipart_PartsInParallel236=== CONT TestEncodeNixBase32/test_string_hash237=== RUN TestFilterOversizedClosures/all_closures_skipped238=== CONT TestEncodeNixBase32/empty_input239=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI240=== RUN TestSetClientTLSErrors/missing_cert_file241--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)242--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)243=== CONT TestUploadMultipart_SupersededByPeer/exists244=== PAUSE TestParsePathInfoJSON/whitespace_only245=== CONT TestUploadMultipart_SupersededByPeer/missing246=== RUN TestParsePathInfoJSON/invalid_JSON247=== CONT TestPathInfoCACompatibility/null_ca_field248=== PAUSE TestSetClientTLSErrors/missing_cert_file249=== RUN TestSetClientTLSErrors/missing_key_file2502026/10/01 13:03:34 ERROR Server seems unavailable, giving up on batch untried=17251=== PAUSE TestSetClientTLSErrors/missing_key_file252=== RUN TestSetClientTLSErrors/missing_ca_file253=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method254=== PAUSE TestFilterOversizedClosures/all_closures_skipped255=== PAUSE TestParsePathInfoJSON/invalid_JSON256=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive257=== CONT TestPathInfoCACompatibility/new_structured_format_-_text258--- PASS: TestStreamPushGivesUpOnDeadServer (0.04s)259=== CONT TestPartSizeForNAR/zero_stays_at_minimum260=== CONT TestPartSizeForNAR/1_TiB261=== CONT TestPartSizeForNAR/capped_at_5_GiB262=== CONT TestPartSizeForNAR/5_TiB_S3_max_object263=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts264=== CONT TestPartSizeForNAR/small_stays_at_minimum265=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum266--- PASS: TestPartSizeForNAR (0.00s)267 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)268 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)269 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)270 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)271 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)272 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)273 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)274=== CONT TestRateLimiterFeedback/429_enables_limiter275--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)276=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter277--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)278=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2792026/10/01 13:03:34 WARN Rate limiter enabled after throttle name=server-test rate=52802026/10/01 13:03:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:37607281=== CONT TestRateLimiterFeedback/503_enables_limiter282=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512283=== RUN TestSetClientTLS/rejects_connection_without_client_cert2842026/10/01 13:03:34 WARN Rate limiter backed off name=server-test rate=5285=== PAUSE TestConvertHashToNix32/invalid_format286=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert287=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512288--- PASS: TestEncodeNixBase32 (0.00s)289 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)290 --- PASS: TestEncodeNixBase32/empty_input (0.00s)291=== CONT TestParsePathInfoJSON/Nix_format292=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2932026/10/01 13:03:34 WARN Rate limiter enabled after throttle name=server-test rate=52942026/10/01 13:03:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43633295=== PAUSE TestSetClientTLSErrors/missing_ca_file296=== CONT TestConvertHashToNix32/SRI_format_to_Nix32297=== RUN TestSetClientTLSErrors/invalid_ca_file298=== PAUSE TestSetClientTLSErrors/invalid_ca_file299=== CONT TestParsePathInfoJSON/invalid_JSON300=== CONT TestConvertHashToNix32/invalid_format301=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3022026/10/01 13:03:34 WARN Rate limiter backed off name=server-test rate=5303=== CONT TestParsePathInfoJSON/whitespace_only304=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512305=== CONT TestConvertHashToNix32/already_Nix32_format306=== CONT TestSetClientTLSErrors/missing_cert_file307=== CONT TestSetClientTLSErrors/invalid_ca_file308=== CONT TestParsePathInfoJSON/empty_input309=== CONT TestSetClientTLSErrors/missing_ca_file310=== CONT TestPathInfoCACompatibility/old_string_format_-_text311=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA312=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA313=== RUN TestSetClientTLS/preserves_debug_logging_transport314=== PAUSE TestSetClientTLS/preserves_debug_logging_transport315=== CONT TestSetClientTLS/rejects_connection_without_client_cert316=== CONT TestSetClientTLS/preserves_debug_logging_transport317=== CONT TestSetClientTLSErrors/missing_key_file318=== CONT TestParsePathInfoJSON/Lix_format319=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error320=== CONT TestGetStorePathHash/valid_store_path321=== CONT TestFilterOversizedClosures/no_limit_keeps_everything322=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA323--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)324 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.03s)325 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)326=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths327--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)328 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)329 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)330=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped331=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon332=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI333=== CONT TestFilterOversizedClosures/all_closures_skipped334=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error335=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error336=== CONT TestGetStorePathHash/basename_without_hyphen_should_error337--- PASS: TestFileTokenReadsAndCaches (0.04s)338--- PASS: TestDumpPathSingleFile (0.05s)339--- PASS: TestParsePathInfoJSON (0.02s)340 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)341 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)342 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)343 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)344 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)345--- PASS: TestCaseHackSuffix (0.05s)346--- PASS: TestPathInfoCACompatibility (0.01s)347 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)348 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)349 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)350 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.03s)351 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)352--- PASS: TestRateLimiterFeedback (0.01s)353 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)354 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)355 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)356 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)357--- PASS: TestConvertHashToNix32 (0.05s)358 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)359 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)360 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)3612026/10/01 13:03:34 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=20003622026/10/01 13:03:34 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50363--- PASS: TestFilterOversizedClosures (0.02s)364 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)365 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)366 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)367--- PASS: TestPathInfoHashCompatibility (0.05s)368 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)369 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)370 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)371 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)372--- PASS: TestGetStorePathHash (0.05s)373 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)374 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)375 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)376 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)377--- PASS: TestSetClientTLSErrors (0.05s)378 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)380 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)381 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3822026/10/01 13:03:34 http: TLS handshake error from 127.0.0.1:44302: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.05s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)385 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)387--- PASS: TestStreamPushRequestLine (0.07s)388--- PASS: TestRegisterUploadedObjectReusesConnections (0.07s)389--- PASS: TestDumpPathWriterError (0.10s)390--- PASS: TestStreamPushBatchesUnderLoad (0.11s)391--- PASS: TestDumpPathMatchesNix (0.13s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres2345609390/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres2345609390/data -l logfile start422423/build/postgres2345609390:5432 - no response4242026-10-01 13:03:36.681 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 13:03:36.681 UTC [128] LOG: listening on Unix socket "/build/postgres2345609390/.s.PGSQL.5432"4262026-10-01 13:03:36.686 UTC [135] LOG: database system was shut down at 2026-10-01 13:03:36 UTC4272026-10-01 13:03:36.690 UTC [128] LOG: database system is ready to accept connections428/build/postgres2345609390:5432 - accepting connections429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock466=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== RUN TestResolveDBConnectionString468=== PAUSE TestResolveDBConnectionString469=== RUN TestConnectWaitsForAPeerMigration470=== PAUSE TestConnectWaitsForAPeerMigration471=== RUN TestLeadElectsOneAndHandsOver472=== PAUSE TestLeadElectsOneAndHandsOver473=== RUN TestLeadIncumbentWinsAfterRestart4742026/10/01 13:03:37 INFO lead: acquired remote=192.0.2.1:12344752026/10/01 13:03:38 INFO lead: released remote=192.0.2.1:12344762026/10/01 13:03:38 INFO lead: acquired remote=192.0.2.1:12344772026/10/01 13:03:39 INFO lead: released remote=192.0.2.1:1234478--- PASS: TestLeadIncumbentWinsAfterRestart (2.36s)479=== RUN TestLeadEndsOnShutdown480=== PAUSE TestLeadEndsOnShutdown481=== RUN TestLeadEndsWhenItsConnectionHangs4822026/10/01 13:03:39 INFO lead: acquired remote=192.0.2.1:12344832026-10-01 13:03:40.976 UTC [574] FATAL: terminating connection due to administrator command4842026/10/01 13:03:41 INFO lead: acquired remote=192.0.2.1:12344852026/10/01 13:03:42 WARN lead: lock connection lost error="timeout: context deadline exceeded"4862026/10/01 13:03:42 INFO lead: released remote=192.0.2.1:12344872026/10/01 13:03:42 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadEndsWhenItsConnectionHangs (2.92s)489=== RUN TestGCAdvisoryLockBlocksConcurrentRun490=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun491=== RUN TestGCBugBareHashReferences492=== PAUSE TestGCBugBareHashReferences493=== RUN TestGCMetrics494=== PAUSE TestGCMetrics495=== RUN TestPushDedupSurvivesConcurrentGC496=== PAUSE TestPushDedupSurvivesConcurrentGC497=== RUN TestDeduplicatedObjectsRecordedAsPending498=== PAUSE TestDeduplicatedObjectsRecordedAsPending499=== RUN TestGCSweepSkipsPendingObjects500=== PAUSE TestGCSweepSkipsPendingObjects501=== RUN TestTombstonedObjectOfferedWithoutWaiting502=== PAUSE TestTombstonedObjectOfferedWithoutWaiting503=== RUN TestGCSweepDeliversEachKeyOnce504=== PAUSE TestGCSweepDeliversEachKeyOnce505=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection506=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection507=== RUN TestForceGCDuringPushOffersSweptObject508=== PAUSE TestForceGCDuringPushOffersSweptObject509=== RUN TestFailedS3DeleteKeepsTombstone510=== PAUSE TestFailedS3DeleteKeepsTombstone511=== RUN TestSweepSkipsRowsLockedByPush512=== PAUSE TestSweepSkipsRowsLockedByPush513=== RUN TestRegisterCompletedObjectNeedsPendingRow514=== PAUSE TestRegisterCompletedObjectNeedsPendingRow515=== RUN TestGetExistingObjectsLocksRows516=== PAUSE TestGetExistingObjectsLocksRows517=== RUN TestSweepRechecksPendingAfterLocking518=== PAUSE TestSweepRechecksPendingAfterLocking519=== RUN TestPushWaitsForSweepHoldingRow520=== PAUSE TestPushWaitsForSweepHoldingRow521=== RUN TestCommitRacingPendingCleanupKeepsObjects522=== PAUSE TestCommitRacingPendingCleanupKeepsObjects523=== RUN TestGCEndsOnShutdown524=== PAUSE TestGCEndsOnShutdown525=== RUN TestGCTaskStore_StartNew526=== PAUSE TestGCTaskStore_StartNew527=== RUN TestGCTaskStore_DeduplicateSameParams528=== PAUSE TestGCTaskStore_DeduplicateSameParams529=== RUN TestGCTaskStore_ConflictDifferentParams530=== PAUSE TestGCTaskStore_ConflictDifferentParams531=== RUN TestGCTaskStore_GetEmpty532=== PAUSE TestGCTaskStore_GetEmpty533=== RUN TestGCTaskStore_GetReturnsLatest534=== PAUSE TestGCTaskStore_GetReturnsLatest535=== RUN TestGCTaskStore_CompletedAllowsNewTask536=== PAUSE TestGCTaskStore_CompletedAllowsNewTask537=== RUN TestGCTaskStore_PhaseUpdates538=== PAUSE TestGCTaskStore_PhaseUpdates539=== RUN TestGCTaskStore_Fail540=== PAUSE TestGCTaskStore_Fail541=== RUN TestGracefulShutdownDrainsInflight542=== PAUSE TestGracefulShutdownDrainsInflight543=== RUN TestService_healthCheckHandler544=== PAUSE TestService_healthCheckHandler545=== RUN TestService_readinessHandler546=== PAUSE TestService_readinessHandler547=== RUN TestGenerateLandingPage548=== PAUSE TestGenerateLandingPage549=== RUN TestCacheConfigHandlerMaxNarSize550=== PAUSE TestCacheConfigHandlerMaxNarSize551=== RUN TestCreatePendingClosureRejectsOversizedNAR552=== PAUSE TestCreatePendingClosureRejectsOversizedNAR553=== RUN TestNARDeduplicationMetadataUploadBug554=== PAUSE TestNARDeduplicationMetadataUploadBug555=== RUN TestMetricsInventory556=== PAUSE TestMetricsInventory557=== RUN TestService_NativeMTLS558=== PAUSE TestService_NativeMTLS559=== RUN TestServerTLSConfig560=== PAUSE TestServerTLSConfig561=== RUN TestMultipartCleanup562=== PAUSE TestMultipartCleanup563=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded564=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded565=== RUN TestPendingCleanupUsesOneCutoff566=== PAUSE TestPendingCleanupUsesOneCutoff567=== RUN TestObjectStatsTrigger568=== PAUSE TestObjectStatsTrigger569=== RUN TestOrphanedObjectsGC570=== PAUSE TestOrphanedObjectsGC571=== RUN TestOrphanedObjectsGCStressTest572=== PAUSE TestOrphanedObjectsGCStressTest573=== RUN TestCreatePin_ReservedPins574=== PAUSE TestCreatePin_ReservedPins575=== RUN TestPresentReportsOnlyClosureRoots576=== PAUSE TestPresentReportsOnlyClosureRoots577=== RUN TestPresentNotReportedWhileGCDeletesClosure578=== PAUSE TestPresentNotReportedWhileGCDeletesClosure579=== RUN TestParseSingleRange580=== PAUSE TestParseSingleRange581=== RUN TestProxyHeadersOnlyTrustedOnSocket582=== PAUSE TestProxyHeadersOnlyTrustedOnSocket583=== RUN TestIsValidCachePath584=== PAUSE TestIsValidCachePath585=== RUN TestReadProxyNarinfo586=== PAUSE TestReadProxyNarinfo587=== RUN TestReadProxyNarinfoAlreadyDecompressed588=== PAUSE TestReadProxyNarinfoAlreadyDecompressed589=== RUN TestReadProxyNarStreaming590=== PAUSE TestReadProxyNarStreaming591=== RUN TestReadProxy404592=== PAUSE TestReadProxy404593=== RUN TestReadProxyInvalidPath594=== PAUSE TestReadProxyInvalidPath595=== RUN TestReadProxyHead596=== PAUSE TestReadProxyHead597=== RUN TestReadProxyOutlastsServerWriteTimeout598=== PAUSE TestReadProxyOutlastsServerWriteTimeout599=== RUN TestReadProxyConditionalGet600=== PAUSE TestReadProxyConditionalGet601=== RUN TestReadProxyRootRedirectsToIndexHTML602=== PAUSE TestReadProxyRootRedirectsToIndexHTML603=== RUN TestReadProxyDisabled604=== PAUSE TestReadProxyDisabled605=== RUN TestReadRedirectNar606=== PAUSE TestReadRedirectNar607=== RUN TestReadRedirectKeepsNarinfoProxied608=== PAUSE TestReadRedirectKeepsNarinfoProxied609=== RUN TestReadProxyRangeRequest610=== PAUSE TestReadProxyRangeRequest611=== RUN TestReadRedirectUsesPublicS3URL612=== PAUSE TestReadRedirectUsesPublicS3URL613=== RUN TestPush_OverlappingRootsStoreOneRowPerKey614=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey615=== RUN TestPush_CompleteCommitsEveryRoot616=== PAUSE TestPush_CompleteCommitsEveryRoot617=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit618=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit619=== RUN TestPush_RejectsBadRequests620=== PAUSE TestPush_RejectsBadRequests621=== RUN TestPush_SignsNarinfosOfItsPendingObjects622=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects623=== RUN TestRedundantMultipartUpload624=== PAUSE TestRedundantMultipartUpload625=== RUN TestCompleteMultipartUpload_ErrorButObjectExists626=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists627=== RUN TestCompletedNarNotReofferedAcrossClosures628=== PAUSE TestCompletedNarNotReofferedAcrossClosures629=== RUN TestPresignedUploadRegisteredBeforeCommit630=== PAUSE TestPresignedUploadRegisteredBeforeCommit631=== RUN TestService_Rustfstest632=== PAUSE TestService_Rustfstest633=== RUN TestParseSize634=== PAUSE TestParseSize635=== RUN TestSkippedUploadsHandler636=== PAUSE TestSkippedUploadsHandler637=== RUN TestSystemdListenerNotActivated638--- PASS: TestSystemdListenerNotActivated (0.00s)639=== RUN TestWatchdogBeatsWhenHealthy640--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)641=== RUN TestWatchdogSkipsWhenUnhealthy6422026/10/01 13:03:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6432026/10/01 13:03:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 13:03:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/01 13:03:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/01 13:03:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 13:03:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 13:03:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 13:03:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 13:03:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/01 13:03:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"652--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)653=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle654=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle655=== RUN TestProxyWriteTimeout656=== PAUSE TestProxyWriteTimeout657=== RUN TestPendingClosureWriteTimeout658=== PAUSE TestPendingClosureWriteTimeout659=== RUN TestIsValidUploadKey660=== PAUSE TestIsValidUploadKey661=== RUN TestUploadHandlersRejectInvalidKeys662=== PAUSE TestUploadHandlersRejectInvalidKeys663=== RUN TestUploadHandlersRejectOversizedBody664=== PAUSE TestUploadHandlersRejectOversizedBody665=== RUN TestService_cleanupPendingClosuresHandler666=== PAUSE TestService_cleanupPendingClosuresHandler667=== RUN TestService_createPendingClosureHandler668=== PAUSE TestService_createPendingClosureHandler669=== RUN TestService_verifyS3Integrity670=== PAUSE TestService_verifyS3Integrity671=== RUN TestCompleteMultipartUnregistered672=== PAUSE TestCompleteMultipartUnregistered673=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT674=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT675=== CONT TestService_AuthMiddleware676=== CONT TestIsValidUploadKey677=== CONT TestCreatePendingClosureRejectsOversizedNAR678=== CONT TestReadProxyOutlastsServerWriteTimeout679=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT680=== CONT TestCompleteMultipartUnregistered6812026/10/01 13:03:42 INFO Received uploads request method=POST path=/api/pending_closures682=== CONT TestService_verifyS3Integrity683=== CONT TestService_createPendingClosureHandler684=== CONT TestService_cleanupPendingClosuresHandler685=== CONT TestUploadHandlersRejectOversizedBody686=== CONT TestUploadHandlersRejectInvalidKeys687=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info688=== CONT TestPendingClosureWriteTimeout689=== CONT TestProxyWriteTimeout690=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle691=== CONT TestSkippedUploadsHandler692=== CONT TestParseSize693=== CONT TestService_Rustfstest694=== CONT TestPresignedUploadRegisteredBeforeCommit695=== CONT TestCompletedNarNotReofferedAcrossClosures696=== CONT TestCompleteMultipartUpload_ErrorButObjectExists697=== CONT TestRedundantMultipartUpload698=== CONT TestPush_SignsNarinfosOfItsPendingObjects699=== CONT TestPush_RejectsBadRequests700=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit701=== RUN TestIsValidUploadKey/narinfo702--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)703=== CONT TestPush_CompleteCommitsEveryRoot704=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info705=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal706=== RUN TestPendingClosureWriteTimeout/empty707=== RUN TestProxyWriteTimeout/narinfo708=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal709=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key710=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key711=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key712=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key713=== PAUSE TestProxyWriteTimeout/narinfo714=== RUN TestProxyWriteTimeout/1_GiB_nar715=== CONT TestPush_OverlappingRootsStoreOneRowPerKey716--- PASS: TestParseSize (0.00s)717=== CONT TestReadRedirectUsesPublicS3URL718=== PAUSE TestPendingClosureWriteTimeout/empty7192026/10/01 13:03:42 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000720=== PAUSE TestIsValidUploadKey/narinfo721=== PAUSE TestProxyWriteTimeout/1_GiB_nar722=== RUN TestProxyWriteTimeout/10_GiB_nar723=== PAUSE TestProxyWriteTimeout/10_GiB_nar724=== RUN TestProxyWriteTimeout/unknown_size725=== PAUSE TestProxyWriteTimeout/unknown_size726=== RUN TestIsValidUploadKey/nar_zst727=== PAUSE TestIsValidUploadKey/nar_zst728=== RUN TestIsValidUploadKey/nar_xz729=== PAUSE TestIsValidUploadKey/nar_xz730=== RUN TestIsValidUploadKey/nar_plain731=== PAUSE TestIsValidUploadKey/nar_plain732=== RUN TestIsValidUploadKey/listing733=== PAUSE TestIsValidUploadKey/listing734=== RUN TestIsValidUploadKey/build_log735=== CONT TestReadProxyRangeRequest736=== RUN TestPendingClosureWriteTimeout/400_objects737=== PAUSE TestPendingClosureWriteTimeout/400_objects738=== RUN TestPendingClosureWriteTimeout/670k_objects739=== PAUSE TestPendingClosureWriteTimeout/670k_objects740=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline741=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline742=== CONT TestReadRedirectKeepsNarinfoProxied743=== PAUSE TestIsValidUploadKey/build_log744=== RUN TestIsValidUploadKey/build_log_home-manager_file745=== PAUSE TestIsValidUploadKey/build_log_home-manager_file746=== RUN TestIsValidUploadKey/build_log_plus_in_name747=== PAUSE TestIsValidUploadKey/build_log_plus_in_name748=== RUN TestIsValidUploadKey/build_log_question_mark749=== PAUSE TestIsValidUploadKey/build_log_question_mark750=== RUN TestIsValidUploadKey/build_log_equals751=== PAUSE TestIsValidUploadKey/build_log_equals752=== RUN TestIsValidUploadKey/realisation753=== PAUSE TestIsValidUploadKey/realisation754=== RUN TestIsValidUploadKey/realisation_plus_in_output755=== PAUSE TestIsValidUploadKey/realisation_plus_in_output756=== RUN TestIsValidUploadKey/nix-cache-info757=== PAUSE TestIsValidUploadKey/nix-cache-info758=== RUN TestIsValidUploadKey/index.html759=== PAUSE TestIsValidUploadKey/index.html760=== RUN TestIsValidUploadKey/narinfo_key,_nar_type761=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type762=== RUN TestIsValidUploadKey/nar_key,_narinfo_type763=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type764=== RUN TestIsValidUploadKey/listing_key,_narinfo_type765=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type766=== RUN TestIsValidUploadKey/traversal767=== PAUSE TestIsValidUploadKey/traversal768=== RUN TestIsValidUploadKey/traversal_nar769=== PAUSE TestIsValidUploadKey/traversal_nar770=== RUN TestIsValidUploadKey/absolute771=== PAUSE TestIsValidUploadKey/absolute772=== RUN TestIsValidUploadKey/empty_key773=== PAUSE TestIsValidUploadKey/empty_key774=== RUN TestIsValidUploadKey/unknown_type775=== PAUSE TestIsValidUploadKey/unknown_type776=== CONT TestReadRedirectNar777--- PASS: TestSkippedUploadsHandler (0.07s)778=== CONT TestReadProxyDisabled779=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure780=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure781=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart782=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart783=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts784=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts785=== CONT TestReadProxyRootRedirectsToIndexHTML7862026/10/01 13:03:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7872026/10/01 13:03:43 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst788--- PASS: TestCompleteMultipartUnregistered (0.41s)789=== CONT TestReadProxyConditionalGet7902026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures791--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.45s)792=== CONT TestPresentReportsOnlyClosureRoots7932026/10/01 13:03:43 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"794--- PASS: TestService_AuthMiddleware (0.46s)795=== CONT TestReadProxyHead7962026/10/01 13:03:43 INFO Received cleanup request method=DELETE path=/api/pending_closures7972026/10/01 13:03:43 INFO Aborted multipart uploads count=0 kept=07982026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures7992026/10/01 13:03:43 INFO Received cleanup request method=DELETE path=/api/pending_closures8002026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures8012026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures8022026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures8032026/10/01 13:03:43 INFO Aborted multipart uploads count=1 kept=08042026/10/01 13:03:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8052026-10-01 13:03:43.133 UTC [643] ERROR: Closure does not exist: id=18062026-10-01 13:03:43.133 UTC [643] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8072026-10-01 13:03:43.133 UTC [643] STATEMENT: -- name: CommitPendingClosure :exec808 SELECT commit_pending_closure($1::bigint)809 810--- PASS: TestService_cleanupPendingClosuresHandler (0.52s)811=== CONT TestReadProxyInvalidPath8122026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures813--- PASS: TestReadRedirectUsesPublicS3URL (0.58s)814=== CONT TestReadProxy4048152026/10/01 13:03:43 INFO Received push request method=POST path=/api/pushes8162026/10/01 13:03:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign817=== RUN TestPush_RejectsBadRequests/no_roots818=== PAUSE TestPush_RejectsBadRequests/no_roots819=== RUN TestPush_RejectsBadRequests/no_objects820=== PAUSE TestPush_RejectsBadRequests/no_objects8212026/10/01 13:03:43 INFO Signed narinfos id=1 count=1822=== RUN TestPush_RejectsBadRequests/bad_root823=== PAUSE TestPush_RejectsBadRequests/bad_root824=== RUN TestPush_RejectsBadRequests/root_not_in_objects825=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects826=== CONT TestReadProxyNarStreaming827--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.64s)828=== CONT TestReadProxyNarinfoAlreadyDecompressed8292026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures8302026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures8312026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures8322026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures8332026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures8342026/10/01 13:03:43 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8352026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures836--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.78s)837=== CONT TestReadProxyNarinfo8382026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures839--- PASS: TestReadRedirectNar (0.75s)840=== CONT TestIsValidCachePath841=== RUN TestIsValidCachePath/narinfo842=== PAUSE TestIsValidCachePath/narinfo843=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars844=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars845=== RUN TestIsValidCachePath/nar_zst846=== PAUSE TestIsValidCachePath/nar_zst847=== RUN TestIsValidCachePath/nar_xz848=== PAUSE TestIsValidCachePath/nar_xz849=== RUN TestIsValidCachePath/nar_bz2850=== PAUSE TestIsValidCachePath/nar_bz2851=== RUN TestIsValidCachePath/nar_uncompressed852=== PAUSE TestIsValidCachePath/nar_uncompressed853=== RUN TestIsValidCachePath/ls854=== PAUSE TestIsValidCachePath/ls855=== RUN TestIsValidCachePath/log856=== PAUSE TestIsValidCachePath/log857=== RUN TestIsValidCachePath/realisation858=== PAUSE TestIsValidCachePath/realisation859=== RUN TestIsValidCachePath/nix-cache-info860=== PAUSE TestIsValidCachePath/nix-cache-info861=== RUN TestIsValidCachePath/index.html862=== PAUSE TestIsValidCachePath/index.html863=== RUN TestIsValidCachePath/traversal_parent864=== PAUSE TestIsValidCachePath/traversal_parent865=== RUN TestIsValidCachePath/traversal_in_middle866=== PAUSE TestIsValidCachePath/traversal_in_middle867=== RUN TestIsValidCachePath/invalid_char_e868=== PAUSE TestIsValidCachePath/invalid_char_e869=== RUN TestIsValidCachePath/invalid_char_u870=== PAUSE TestIsValidCachePath/invalid_char_u871=== RUN TestIsValidCachePath/random_path872=== PAUSE TestIsValidCachePath/random_path873=== RUN TestIsValidCachePath/empty874=== PAUSE TestIsValidCachePath/empty875=== RUN TestIsValidCachePath/leading_slash876=== PAUSE TestIsValidCachePath/leading_slash877=== RUN TestIsValidCachePath/wrong_extension878=== PAUSE TestIsValidCachePath/wrong_extension879=== RUN TestIsValidCachePath/short_hash880=== PAUSE TestIsValidCachePath/short_hash881=== CONT TestProxyHeadersOnlyTrustedOnSocket8822026/10/01 13:03:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8832026/10/01 13:03:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8842026/10/01 13:03:43 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTQ2ZWZmNTUtYjRiNS00OGE1LWEyZWYtNzhlMTgwY2U3Y2EwLmQ5MGVlYWQyLWQ2YTctNDA5Yi04ZjAxLWIzOTU3MjcyMWJlNngxNzkwODU5ODIzNDA5MDc5Nzkx885--- PASS: TestReadProxyDisabled (0.76s)886=== CONT TestParseSingleRange887=== RUN TestParseSingleRange/none888=== PAUSE TestParseSingleRange/none889=== RUN TestParseSingleRange/unknown_unit890=== PAUSE TestParseSingleRange/unknown_unit891=== RUN TestParseSingleRange/multi-range_ignored892=== PAUSE TestParseSingleRange/multi-range_ignored893=== RUN TestParseSingleRange/malformed_no_dash894=== PAUSE TestParseSingleRange/malformed_no_dash895=== RUN TestParseSingleRange/malformed_both_empty896=== PAUSE TestParseSingleRange/malformed_both_empty897=== RUN TestParseSingleRange/malformed_end_before_start898=== PAUSE TestParseSingleRange/malformed_end_before_start899=== RUN TestParseSingleRange/closed900=== PAUSE TestParseSingleRange/closed901=== RUN TestParseSingleRange/open-ended902=== PAUSE TestParseSingleRange/open-ended903=== RUN TestParseSingleRange/end_clamped_to_size904=== PAUSE TestParseSingleRange/end_clamped_to_size905=== RUN TestParseSingleRange/suffix906=== PAUSE TestParseSingleRange/suffix9072026/10/01 13:03:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTQ2ZWZmNTUtYjRiNS00OGE1LWEyZWYtNzhlMTgwY2U3Y2EwLmQ5MGVlYWQyLWQ2YTctNDA5Yi04ZjAxLWIzOTU3MjcyMWJlNngxNzkwODU5ODIzNDA5MDc5Nzkx parts=1908=== RUN TestParseSingleRange/suffix_exceeds_size909=== PAUSE TestParseSingleRange/suffix_exceeds_size910=== RUN TestParseSingleRange/single_byte911=== PAUSE TestParseSingleRange/single_byte912=== RUN TestParseSingleRange/start_past_EOF913=== PAUSE TestParseSingleRange/start_past_EOF914=== RUN TestParseSingleRange/start_far_past_EOF915=== PAUSE TestParseSingleRange/start_far_past_EOF916=== CONT TestPresentNotReportedWhileGCDeletesClosure917--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.77s)918=== CONT TestService_NativeMTLS919--- PASS: TestReadRedirectKeepsNarinfoProxied (0.81s)920=== CONT TestMultipartCleanup921--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.76s)922=== CONT TestServerTLSConfig923=== RUN TestServerTLSConfig/no_client_CA924=== PAUSE TestServerTLSConfig/no_client_CA925=== RUN TestServerTLSConfig/missing_CA_file926=== PAUSE TestServerTLSConfig/missing_CA_file927=== RUN TestServerTLSConfig/not_a_PEM_file928=== PAUSE TestServerTLSConfig/not_a_PEM_file929=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded930--- PASS: TestReadProxyRangeRequest (0.87s)931=== CONT TestMetricsInventory9322026/10/01 13:03:43 INFO Received push request method=POST path=/api/pushes9332026/10/01 13:03:43 INFO Received push request method=POST path=/api/pushes9342026/10/01 13:03:43 INFO Received complete push request method=POST path=/api/pushes/1/complete935--- PASS: TestPush_CompleteCommitsEveryRoot (0.93s)936=== CONT TestCreatePin_ReservedPins9372026/10/01 13:03:43 INFO Received complete push request method=POST path=/api/pushes/1/complete9382026/10/01 13:03:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete939--- PASS: TestService_Rustfstest (0.95s)940=== CONT TestNARDeduplicationMetadataUploadBug9412026/10/01 13:03:43 INFO Received push request method=POST path=/api/pushes9422026/10/01 13:03:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9432026/10/01 13:03:43 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OTQ2ZWZmNTUtYjRiNS00OGE1LWEyZWYtNzhlMTgwY2U3Y2EwLjdkN2Y0ZTE0LWMzZjMtNGE5Mi1hZDQ3LTM2NjE3OTg5ZGEzY3gxNzkwODU5ODIzMTM4MzUxNjEx parts=109442026/10/01 13:03:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9452026/10/01 13:03:43 INFO Received push request method=POST path=/api/pushes9462026/10/01 13:03:43 INFO Completed upload id=19472026/10/01 13:03:43 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009482026/10/01 13:03:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46389/oidc9492026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures9502026/10/01 13:03:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures9512026/10/01 13:03:43 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OTQ2ZWZmNTUtYjRiNS00OGE1LWEyZWYtNzhlMTgwY2U3Y2EwLjc2NzdjZWI4LWU3MmEtNDlmYS1hMDZlLTY3OTc3YjkzMWI0MXgxNzkwODU5ODIzMTYxMjU0OTQ2 parts=109522026/10/01 13:03:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9532026/10/01 13:03:43 INFO Completed upload id=19542026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures9552026/10/01 13:03:43 INFO Aborted multipart uploads count=0 kept=09562026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures9572026/10/01 13:03:43 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9582026/10/01 13:03:43 WARN Found objects in DB but missing from S3, will re-upload count=1959--- PASS: TestService_verifyS3Integrity (1.07s)960=== CONT TestOrphanedObjectsGCStressTest961--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.00s)962=== CONT TestOrphanedObjectsGC9632026/10/01 13:03:43 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=0964--- PASS: TestReadProxyConditionalGet (0.67s)965=== CONT TestDeduplicatedObjectsRecordedAsPending9662026/10/01 13:03:43 INFO Aborted multipart uploads count=0 kept=09672026/10/01 13:03:43 INFO Vacuumed table table=pending_closures9682026/10/01 13:03:43 WARN Force mode enabled - objects will be deleted immediately without grace period9692026/10/01 13:03:43 INFO Vacuumed table table=pending_objects9702026/10/01 13:03:43 INFO Vacuumed table table=multipart_uploads9712026/10/01 13:03:43 INFO Vacuumed table table=closures9722026/10/01 13:03:43 INFO Vacuumed table table=objects9732026/10/01 13:03:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=09742026/10/01 13:03:43 INFO Vacuumed table table=pending_closures9752026/10/01 13:03:43 INFO Vacuumed table table=pending_objects976--- PASS: TestPresentReportsOnlyClosureRoots (0.67s)977=== CONT TestObjectStatsTrigger9782026/10/01 13:03:43 INFO Vacuumed table table=multipart_uploads9792026/10/01 13:03:43 INFO Vacuumed table table=closures9802026/10/01 13:03:43 INFO Vacuumed table table=objects9812026/10/01 13:03:43 INFO Received complete push request method=POST path=/api/pushes/2/complete982--- PASS: TestReadProxyHead (0.68s)983=== CONT TestCacheConfigHandlerMaxNarSize984--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)985=== CONT TestPendingCleanupUsesOneCutoff986--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.07s)987=== CONT TestGenerateLandingPage988--- PASS: TestGenerateLandingPage (0.00s)989=== CONT TestService_readinessHandler9902026/10/01 13:03:43 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000991--- PASS: TestService_createPendingClosureHandler (1.15s)992=== CONT TestService_healthCheckHandler993--- PASS: TestReadProxyInvalidPath (0.63s)994=== CONT TestClientSharedPathCommittedMidPush995--- PASS: TestReadProxy404 (0.63s)996=== CONT TestGracefulShutdownDrainsInflight9972026/10/01 13:03:43 INFO Starting HTTP server address=127.0.0.1:453419982026/10/01 13:03:43 INFO Shutdown signal received, draining in-flight requests timeout=10s999--- PASS: TestReadProxyNarStreaming (0.58s)1000=== CONT TestGCTaskStore_Fail1001--- PASS: TestGCTaskStore_Fail (0.00s)1002=== CONT TestPushDedupSurvivesConcurrentGC1003--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.60s)1004=== CONT TestGCTaskStore_PhaseUpdates1005--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1006=== CONT TestGCTaskStore_CompletedAllowsNewTask1007--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1008=== CONT TestGCMetrics10092026/10/01 13:03:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1010--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1011=== CONT TestGCBugBareHashReferences10122026/10/01 13:03:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OTQ2ZWZmNTUtYjRiNS00OGE1LWEyZWYtNzhlMTgwY2U3Y2EwLjhmMGE3MDFlLWM5ZDAtNGM0Mi1hNTUyLTAzZjllOGUxMDlkMXgxNzkwODU5ODIzMzAxNjQ3NTY5 parts=1210132026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures10142026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures10152026/10/01 13:03:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10162026/10/01 13:03:43 INFO Starting HTTP server address=127.0.0.1:4108710172026/10/01 13:03:43 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1057308676/001/proxy.sock10182026/10/01 13:03:43 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10192026/10/01 13:03:43 INFO Shutdown signal received, draining in-flight requests timeout=10s1020--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.49s)1021=== CONT TestGCTaskStore_GetReturnsLatest1022--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1023=== CONT TestGCAdvisoryLockBlocksConcurrentRun10242026/10/01 13:03:43 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"10252026/10/01 13:03:43 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OTQ2ZWZmNTUtYjRiNS00OGE1LWEyZWYtNzhlMTgwY2U3Y2EwLjJiMGRhMTM1LTAxMTUtNDVlMy1hNDhmLTMyMmIyZTAwM2E2N3gxNzkwODU5ODIzMzUxMTQyNjgx parts=1210262026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures1027--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.36s)1028=== CONT TestGCTaskStore_GetEmpty1029--- PASS: TestGCTaskStore_GetEmpty (0.00s)1030=== CONT TestLeadEndsOnShutdown10312026/10/01 13:03:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10322026/10/01 13:03:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1033--- PASS: TestService_NativeMTLS (0.53s)1034=== CONT TestGCTaskStore_ConflictDifferentParams1035--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1036=== CONT TestGCTaskStore_DeduplicateSameParams1037--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1038=== CONT TestLeadElectsOneAndHandsOver10392026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures10402026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures1041--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.58s)1042=== CONT TestGCTaskStore_StartNew1043--- PASS: TestGCTaskStore_StartNew (0.00s)1044=== CONT TestConnectWaitsForAPeerMigration1045--- PASS: TestMetricsInventory (0.57s)1046=== CONT TestResolveDBConnectionString1047=== RUN TestResolveDBConnectionString/flag_wins1048=== PAUSE TestResolveDBConnectionString/flag_wins1049=== RUN TestResolveDBConnectionString/file_when_flag_empty1050=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1051=== RUN TestResolveDBConnectionString/missing_file_is_an_error1052=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1053=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1054=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1055=== RUN TestResolveDBConnectionString/nothing_configured1056=== PAUSE TestResolveDBConnectionString/nothing_configured1057=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10582026/10/01 13:03:44 INFO Received cleanup request method=DELETE path=/api/pending_closures10592026/10/01 13:03:44 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket38/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10602026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=110612026/10/01 13:03:44 INFO Received cleanup request method=DELETE path=/api/pending_closures10622026/10/01 13:03:44 INFO Aborted multipart uploads count=1 kept=010632026/10/01 13:03:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10642026/10/01 13:03:44 WARN Refused reserved pin name=worker-x86_64-linux10652026/10/01 13:03:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10662026/10/01 13:03:44 INFO Received create pin request method=POST path=/api/pins/my-app10672026/10/01 13:03:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1068--- PASS: TestCreatePin_ReservedPins (0.55s)1069=== CONT TestGCEndsOnShutdown1070--- PASS: TestMultipartCleanup (0.67s)1071=== CONT TestClientFallsBackToClosures1072=== NAME TestNARDeduplicationMetadataUploadBug1073 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2152991251/001/store/kdismrjsi70gx3m4dqq61pxrnys0fz05-file1.txt10742026/10/01 13:03:44 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161075--- PASS: TestReadProxyNarinfo (0.84s)1076=== CONT TestClientPushesUseOnePush10772026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes10782026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures10792026/10/01 13:03:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10802026/10/01 13:03:44 INFO Uploading kdismrjsi70gx3m4dqq61pxrnys0fz05-file1.txt (160B)1081--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.57s)1082=== CONT TestCommitRacingPendingCleanupKeepsObjects10832026/10/01 13:03:44 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10842026/10/01 13:03:44 WARN Failed to register uploaded object key=kdismrjsi70gx3m4dqq61pxrnys0fz05.ls error="server returned 404: 404 page not found\n"10852026/10/01 13:03:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10862026/10/01 13:03:44 INFO Signed narinfos id=1 count=110872026/10/01 13:03:44 INFO Uploading 1 narinfos10882026/10/01 13:03:44 INFO Received complete push request method=POST path=/api/pushes/1/complete10892026/10/01 13:03:44 WARN Failed to register uploaded object key=kdismrjsi70gx3m4dqq61pxrnys0fz05.narinfo error="server returned 404: 404 page not found\n"10902026/10/01 13:03:44 INFO Upload complete. (75ms)1091=== NAME TestNARDeduplicationMetadataUploadBug1092 metadata_upload_test.go:54: Retrieved narinfo from S3:1093 StorePath: /build/TestNARDeduplicationMetadataUploadBug2152991251/001/store/kdismrjsi70gx3m4dqq61pxrnys0fz05-file1.txt1094 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1095 Compression: zstd1096 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1097 NarSize: 1601098 References: 1099 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1100 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1101 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1102 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1103--- PASS: TestObjectStatsTrigger (0.57s)1104=== CONT TestPinProtectsFromGC11052026/10/01 13:03:44 WARN readiness check failed error="closed pool"1106--- PASS: TestService_readinessHandler (0.55s)1107=== CONT TestPushWaitsForSweepHoldingRow1108=== NAME TestNARDeduplicationMetadataUploadBug1109 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2152991251/001/store/mwv5ixsa4hsxjx5rvw91dy097hfd43kg-file2.txt11102026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures11122026/10/01 13:03:44 INFO Received cleanup request method=DELETE path=/api/pending_closures1113--- PASS: TestService_healthCheckHandler (0.59s)1114=== CONT TestSweepRechecksPendingAfterLocking11152026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes11162026/10/01 13:03:44 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11172026/10/01 13:03:44 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11182026/10/01 13:03:44 INFO Signed narinfos id=2 count=111192026/10/01 13:03:44 WARN Failed to register uploaded object key=mwv5ixsa4hsxjx5rvw91dy097hfd43kg.ls error="server returned 404: 404 page not found\n"11202026/10/01 13:03:44 INFO Uploading 1 narinfos11212026/10/01 13:03:44 INFO Received complete push request method=POST path=/api/pushes/2/complete11222026/10/01 13:03:44 WARN Failed to register uploaded object key=mwv5ixsa4hsxjx5rvw91dy097hfd43kg.narinfo error="server returned 404: 404 page not found\n"11232026/10/01 13:03:44 INFO Upload complete. (53ms)1124=== NAME TestNARDeduplicationMetadataUploadBug1125 metadata_upload_test.go:76: Retrieved narinfo from S3:1126 StorePath: /build/TestNARDeduplicationMetadataUploadBug2152991251/001/store/mwv5ixsa4hsxjx5rvw91dy097hfd43kg-file2.txt1127 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1128 Compression: zstd1129 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1130 NarSize: 1601131 References: 1132 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1133 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1134 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1135 {"version":1,"root":{"type":"regular","size":44}}1136--- PASS: TestNARDeduplicationMetadataUploadBug (0.79s)1137=== CONT TestGetExistingObjectsLocksRows11382026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures11392026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=011402026/10/01 13:03:44 WARN Force mode enabled - objects will be deleted immediately without grace period11412026/10/01 13:03:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011422026/10/01 13:03:44 INFO Vacuumed table table=pending_closures11432026/10/01 13:03:44 INFO Vacuumed table table=pending_objects11442026/10/01 13:03:44 INFO Vacuumed table table=multipart_uploads11452026/10/01 13:03:44 INFO Vacuumed table table=closures11462026/10/01 13:03:44 INFO Vacuumed table table=objects1147--- PASS: TestGCMetrics (0.61s)1148=== CONT TestCacheConfigHandler1149=== RUN TestCacheConfigHandler/full_config,_no_issuer1150=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1151=== RUN TestCacheConfigHandler/no_cache_url_configured1152=== PAUSE TestCacheConfigHandler/no_cache_url_configured1153=== RUN TestCacheConfigHandler/no_signing_keys1154=== PAUSE TestCacheConfigHandler/no_signing_keys1155=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1156=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1157=== CONT TestRegisterCompletedObjectNeedsPendingRow1158--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.02s)1159=== CONT TestClientWithDependencies1160--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.58s)1161=== CONT TestSweepSkipsRowsLockedByPush11622026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=011632026/10/01 13:03:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11642026/10/01 13:03:44 INFO lead: acquired remote=192.0.2.1:123411652026/10/01 13:03:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01166=== NAME TestOrphanedObjectsGC1167 orphaned_objects_gc_test.go:290: GC Test Summary:1168 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1169 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1170 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1171 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1172 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1173--- PASS: TestOrphanedObjectsGC (0.86s)1174=== CONT TestClientMultipleUploads11752026/10/01 13:03:44 INFO Vacuumed table table=pending_closures11762026/10/01 13:03:44 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTQ2ZWZmNTUtYjRiNS00OGE1LWEyZWYtNzhlMTgwY2U3Y2EwLjQxN2Q3NjNjLTlkMTYtNDIxMS1iOTdmLTMwMGVlYjFiYzdkYngxNzkwODU5ODIzOTIwNTk1OTQz error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11772026/10/01 13:03:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTQ2ZWZmNTUtYjRiNS00OGE1LWEyZWYtNzhlMTgwY2U3Y2EwLjFmOWNhZWZiLTI1MzUtNDYxYS04ZmIxLTgyMjM5ODFiZWEzM3gxNzkwODU5ODIzOTEwODYyNDU3 parts=1211782026/10/01 13:03:44 INFO Vacuumed table table=pending_objects11792026/10/01 13:03:44 INFO Vacuumed table table=multipart_uploads11802026/10/01 13:03:44 INFO Received cleanup request method=DELETE path=/api/pending_closures11812026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes11822026/10/01 13:03:44 INFO Vacuumed table table=closures11832026/10/01 13:03:44 INFO Aborted multipart uploads count=1 kept=011842026/10/01 13:03:44 INFO Vacuumed table table=objects11852026/10/01 13:03:44 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11862026/10/01 13:03:44 INFO Uploading yq9fwifhj959r5yx5j4hvnbj6kvrjiys-shared-dep (136B)11872026/10/01 13:03:44 INFO Uploading v1rqkmq467gykfhksbay9031hwbw94dc-top (224B)11882026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=01189--- PASS: TestRedundantMultipartUpload (1.94s)1190=== CONT TestFailedS3DeleteKeepsTombstone11912026/10/01 13:03:44 WARN Force mode enabled - objects will be deleted immediately without grace period11922026/10/01 13:03:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011932026/10/01 13:03:44 INFO lead: acquired remote=192.0.2.1:123411942026/10/01 13:03:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11952026/10/01 13:03:44 WARN Failed to register uploaded object key=nar/19vivbwc363axs8430ckjsikkraapnn5hzy6sn9ibqf6qg1q7dw1.nar.zst error="server returned 404: 404 page not found\n"11962026/10/01 13:03:44 WARN Failed to register uploaded object key=yq9fwifhj959r5yx5j4hvnbj6kvrjiys.ls error="server returned 404: 404 page not found\n"11972026/10/01 13:03:44 INFO Vacuumed table table=pending_closures11982026/10/01 13:03:44 INFO Vacuumed table table=pending_objects11992026/10/01 13:03:44 WARN Failed to register uploaded object key=v1rqkmq467gykfhksbay9031hwbw94dc.ls error="server returned 404: 404 page not found\n"12002026/10/01 13:03:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12012026/10/01 13:03:44 INFO Vacuumed table table=multipart_uploads12022026/10/01 13:03:44 INFO Signed narinfos id=1 count=212032026/10/01 13:03:44 INFO Uploading 2 narinfos12042026/10/01 13:03:44 INFO Vacuumed table table=closures12052026/10/01 13:03:44 INFO Vacuumed table table=objects1206--- PASS: TestPushDedupSurvivesConcurrentGC (0.74s)1207=== CONT TestForceGCDuringPushOffersSweptObject1208=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1209=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1210=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1211=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1212=== CONT TestClientIntegration12132026/10/01 13:03:44 WARN Failed to register uploaded object key=yq9fwifhj959r5yx5j4hvnbj6kvrjiys.narinfo error="server returned 404: 404 page not found\n"12142026/10/01 13:03:44 INFO Received complete push request method=POST path=/api/pushes/1/complete12152026/10/01 13:03:44 WARN Failed to register uploaded object key=v1rqkmq467gykfhksbay9031hwbw94dc.narinfo error="server returned 404: 404 page not found\n"12162026/10/01 13:03:44 INFO Upload complete. (87ms)1217=== NAME TestClientSharedPathCommittedMidPush1218 client_integration_test.go:680: Retrieved narinfo from S3:1219 StorePath: /build/TestClientSharedPathCommittedMidPush247131140/001/store/yq9fwifhj959r5yx5j4hvnbj6kvrjiys-shared-dep1220 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1221 Compression: zstd1222 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821223 NarSize: 1361224 References: 1225 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1226 client_integration_test.go:680: Retrieved narinfo from S3:1227 StorePath: /build/TestClientSharedPathCommittedMidPush247131140/001/store/v1rqkmq467gykfhksbay9031hwbw94dc-top1228 URL: nar/19vivbwc363axs8430ckjsikkraapnn5hzy6sn9ibqf6qg1q7dw1.nar.zst1229 Compression: zstd1230 NarHash: sha256:19vivbwc363axs8430ckjsikkraapnn5hzy6sn9ibqf6qg1q7dw11231 NarSize: 2241232 References: /build/TestClientSharedPathCommittedMidPush247131140/001/store/yq9fwifhj959r5yx5j4hvnbj6kvrjiys-shared-dep1233 CA: text:sha256:0j3kbndss2xjnk9ach9k3i2pn0l1n4a2zjrdb4bqsqlpmxnh96cj1234--- PASS: TestClientSharedPathCommittedMidPush (0.83s)1235=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1236--- PASS: TestGCEndsOnShutdown (0.50s)1237=== CONT TestClientErrorHandling1238=== RUN TestClientErrorHandling/InvalidStorePath1239=== PAUSE TestClientErrorHandling/InvalidStorePath1240=== RUN TestClientErrorHandling/InvalidAuthToken1241=== PAUSE TestClientErrorHandling/InvalidAuthToken1242=== RUN TestClientErrorHandling/ServerNotAvailable1243=== PAUSE TestClientErrorHandling/ServerNotAvailable1244=== CONT TestClientCADerivations1245--- PASS: TestGCBugBareHashReferences (0.82s)1246=== CONT TestGCSweepDeliversEachKeyOnce12472026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=012482026/10/01 13:03:44 WARN Force mode enabled - objects will be deleted immediately without grace period12492026/10/01 13:03:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012502026/10/01 13:03:44 INFO Vacuumed table table=pending_closures12512026/10/01 13:03:44 INFO Vacuumed table table=pending_objects12522026/10/01 13:03:44 INFO Vacuumed table table=multipart_uploads12532026/10/01 13:03:44 INFO Vacuumed table table=closures12542026/10/01 13:03:44 INFO Vacuumed table table=objects12552026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures1256--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.53s)1257=== CONT TestCacheStatsHandler12582026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=012592026/10/01 13:03:44 WARN Force mode enabled - objects will be deleted immediately without grace period12602026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures12612026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures1262=== NAME TestPinProtectsFromGC1263 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1548693068/001/store/3wy2ngdrygyyx6bfy42fpd6m9l57k8qi-pinned-file.txt1264 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1548693068/001/store/6n00rzx5vj2nprp9s31q7h5nijgr3rpn-unpinned-file.txt12652026/10/01 13:03:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12662026/10/01 13:03:44 INFO Uploading jarmdzhhrcr2v0jyvi4fcc4za6igyh6j-a (216B)12672026/10/01 13:03:44 INFO Uploading 6mv28wn0ng0v05074vagj1c2a176r72j-shared-dep (136B)12682026/10/01 13:03:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012692026/10/01 13:03:44 WARN Failed to register uploaded object key=nar/1iq9f71i8q0bsjdjkayv2a813f40m6mc8g4zlfrlga430npdrkzn.nar.zst error="server returned 404: 404 page not found\n"12702026/10/01 13:03:44 WARN Failed to register uploaded object key=d252fwlzh612l1jbxmx5xrq35ljvlxsb.ls error="server returned 404: 404 page not found\n"12712026/10/01 13:03:44 WARN Failed to register uploaded object key=jarmdzhhrcr2v0jyvi4fcc4za6igyh6j.ls error="server returned 404: 404 page not found\n"12722026/10/01 13:03:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1273--- PASS: TestGetExistingObjectsLocksRows (0.42s)1274=== CONT TestTombstonedObjectOfferedWithoutWaiting12752026/10/01 13:03:44 INFO Vacuumed table table=pending_closures12762026/10/01 13:03:44 WARN Failed to register uploaded object key=6mv28wn0ng0v05074vagj1c2a176r72j.ls error="server returned 404: 404 page not found\n"12772026/10/01 13:03:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12782026/10/01 13:03:44 INFO Signed narinfos id=1 count=212792026/10/01 13:03:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12802026/10/01 13:03:44 INFO Signed narinfos id=2 count=212812026/10/01 13:03:44 INFO Uploading 4 narinfos12822026/10/01 13:03:44 INFO Vacuumed table table=pending_objects12832026/10/01 13:03:44 INFO Vacuumed table table=multipart_uploads12842026/10/01 13:03:44 INFO Vacuumed table table=closures12852026/10/01 13:03:44 INFO Vacuumed table table=objects12862026/10/01 13:03:44 WARN Failed to register uploaded object key=d252fwlzh612l1jbxmx5xrq35ljvlxsb.narinfo error="server returned 404: 404 page not found\n"12872026/10/01 13:03:44 WARN Failed to register uploaded object key=6mv28wn0ng0v05074vagj1c2a176r72j.narinfo error="server returned 404: 404 page not found\n"12882026/10/01 13:03:44 WARN Failed to register uploaded object key=jarmdzhhrcr2v0jyvi4fcc4za6igyh6j.narinfo error="server returned 404: 404 page not found\n"1289--- PASS: TestSweepRechecksPendingAfterLocking (0.49s)1290=== CONT TestGCSweepSkipsPendingObjects12912026/10/01 13:03:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12922026/10/01 13:03:44 WARN Failed to register uploaded object key=6mv28wn0ng0v05074vagj1c2a176r72j.narinfo error="server returned 404: 404 page not found\n"12932026/10/01 13:03:44 INFO Completed upload id=112942026/10/01 13:03:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12952026/10/01 13:03:44 INFO Completed upload id=212962026/10/01 13:03:44 INFO Upload complete. (99ms)1297=== NAME TestClientFallsBackToClosures1298 client_pushes_test.go:112: Retrieved narinfo from S3:1299 StorePath: /build/TestClientFallsBackToClosures1216313615/001/store/6mv28wn0ng0v05074vagj1c2a176r72j-shared-dep1300 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1301 Compression: zstd1302 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821303 NarSize: 1361304 References: 1305 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13062026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes1307 client_pushes_test.go:112: Retrieved narinfo from S3:1308 StorePath: /build/TestClientFallsBackToClosures1216313615/001/store/jarmdzhhrcr2v0jyvi4fcc4za6igyh6j-a1309 URL: nar/1iq9f71i8q0bsjdjkayv2a813f40m6mc8g4zlfrlga430npdrkzn.nar.zst1310 Compression: zstd1311 NarHash: sha256:1iq9f71i8q0bsjdjkayv2a813f40m6mc8g4zlfrlga430npdrkzn1312 NarSize: 2161313 References: /build/TestClientFallsBackToClosures1216313615/001/store/6mv28wn0ng0v05074vagj1c2a176r72j-shared-dep1314 CA: text:sha256:09kbxxygsp3agmvkkyhzbqk4smyiaf3dnr3sakrzb5qa39qhvc711315--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.41s)1316=== CONT TestService_AuthMiddleware_OIDC1317=== NAME TestClientFallsBackToClosures1318 client_pushes_test.go:112: Retrieved narinfo from S3:1319 StorePath: /build/TestClientFallsBackToClosures1216313615/001/store/d252fwlzh612l1jbxmx5xrq35ljvlxsb-b1320 URL: nar/1iq9f71i8q0bsjdjkayv2a813f40m6mc8g4zlfrlga430npdrkzn.nar.zst1321 Compression: zstd1322 NarHash: sha256:1iq9f71i8q0bsjdjkayv2a813f40m6mc8g4zlfrlga430npdrkzn1323 NarSize: 2161324 References: /build/TestClientFallsBackToClosures1216313615/001/store/6mv28wn0ng0v05074vagj1c2a176r72j-shared-dep1325 CA: text:sha256:09kbxxygsp3agmvkkyhzbqk4smyiaf3dnr3sakrzb5qa39qhvc7113262026/10/01 13:03:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13272026/10/01 13:03:44 INFO Uploading ijngafafl1h246xgb2h129bgfcyqand1-a (216B)13282026/10/01 13:03:44 INFO Uploading sbqi6mk3g07y1p34h61m6xh2cwf5syfx-shared-dep (136B)13292026/10/01 13:03:44 WARN Failed to register uploaded object key=70gbxzrh4jvkn1c5hdacqppbhzlgai8b.ls error="server returned 404: 404 page not found\n"13302026/10/01 13:03:44 WARN Failed to register uploaded object key=sbqi6mk3g07y1p34h61m6xh2cwf5syfx.ls error="server returned 404: 404 page not found\n"13312026/10/01 13:03:44 WARN Failed to register uploaded object key=ijngafafl1h246xgb2h129bgfcyqand1.ls error="server returned 404: 404 page not found\n"13322026/10/01 13:03:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13332026/10/01 13:03:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13342026/10/01 13:03:44 WARN Failed to register uploaded object key=nar/04qgd6wj7a56c9x6ziimq39mlhi4azg2k9h00pr588gnq0m28naj.nar.zst error="server returned 404: 404 page not found\n"13352026/10/01 13:03:44 INFO Signed narinfos id=1 count=313362026/10/01 13:03:44 INFO Uploading 3 narinfos1337--- PASS: TestClientFallsBackToClosures (0.73s)1338=== CONT TestService_ReadScope_PublicByDefault13392026/10/01 13:03:44 WARN Failed to register uploaded object key=ijngafafl1h246xgb2h129bgfcyqand1.narinfo error="server returned 404: 404 page not found\n"13402026/10/01 13:03:44 WARN Failed to register uploaded object key=sbqi6mk3g07y1p34h61m6xh2cwf5syfx.narinfo error="server returned 404: 404 page not found\n"13412026/10/01 13:03:44 INFO Received complete push request method=POST path=/api/pushes/1/complete13422026/10/01 13:03:44 WARN Failed to register uploaded object key=70gbxzrh4jvkn1c5hdacqppbhzlgai8b.narinfo error="server returned 404: 404 page not found\n"13432026/10/01 13:03:44 INFO Upload complete. (70ms)1344=== NAME TestClientPushesUseOnePush1345 client_pushes_test.go:97: Retrieved narinfo from S3:1346 StorePath: /build/TestClientPushesUseOnePush2778851621/001/store/sbqi6mk3g07y1p34h61m6xh2cwf5syfx-shared-dep1347 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1348 Compression: zstd1349 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821350 NarSize: 1361351 References: 1352 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13532026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes1354 client_pushes_test.go:97: Retrieved narinfo from S3:1355 StorePath: /build/TestClientPushesUseOnePush2778851621/001/store/ijngafafl1h246xgb2h129bgfcyqand1-a1356 URL: nar/04qgd6wj7a56c9x6ziimq39mlhi4azg2k9h00pr588gnq0m28naj.nar.zst1357 Compression: zstd1358 NarHash: sha256:04qgd6wj7a56c9x6ziimq39mlhi4azg2k9h00pr588gnq0m28naj1359 NarSize: 2161360 References: /build/TestClientPushesUseOnePush2778851621/001/store/sbqi6mk3g07y1p34h61m6xh2cwf5syfx-shared-dep1361 CA: text:sha256:1dj2kgg00gpd3qk96hl8582vz1n3jmly3qmr8mp6h05wi2m0a44x1362 client_pushes_test.go:97: Retrieved narinfo from S3:1363 StorePath: /build/TestClientPushesUseOnePush2778851621/001/store/70gbxzrh4jvkn1c5hdacqppbhzlgai8b-b1364 URL: nar/04qgd6wj7a56c9x6ziimq39mlhi4azg2k9h00pr588gnq0m28naj.nar.zst1365 Compression: zstd1366 NarHash: sha256:04qgd6wj7a56c9x6ziimq39mlhi4azg2k9h00pr588gnq0m28naj1367 NarSize: 2161368 References: /build/TestClientPushesUseOnePush2778851621/001/store/sbqi6mk3g07y1p34h61m6xh2cwf5syfx-shared-dep1369 CA: text:sha256:1dj2kgg00gpd3qk96hl8582vz1n3jmly3qmr8mp6h05wi2m0a44x13702026/10/01 13:03:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13712026/10/01 13:03:44 INFO Uploading 3wy2ngdrygyyx6bfy42fpd6m9l57k8qi-pinned-file.txt (128B)1372--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.80s)1373=== CONT TestService_RequireScope_OIDC13742026/10/01 13:03:44 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13752026/10/01 13:03:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13762026/10/01 13:03:44 INFO Signed narinfos id=1 count=113772026/10/01 13:03:44 WARN Failed to register uploaded object key=3wy2ngdrygyyx6bfy42fpd6m9l57k8qi.ls error="server returned 404: 404 page not found\n"13782026/10/01 13:03:44 INFO Uploading 1 narinfos1379--- PASS: TestClientPushesUseOnePush (0.69s)1380=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13812026/10/01 13:03:44 INFO Received complete push request method=POST path=/api/pushes/1/complete13822026/10/01 13:03:44 WARN Failed to register uploaded object key=3wy2ngdrygyyx6bfy42fpd6m9l57k8qi.narinfo error="server returned 404: 404 page not found\n"13832026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=013842026/10/01 13:03:44 WARN Force mode enabled - objects will be deleted immediately without grace period13852026/10/01 13:03:44 INFO Upload complete. (65ms)13862026/10/01 13:03:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013872026/10/01 13:03:44 INFO Vacuumed table table=pending_closures13882026/10/01 13:03:44 INFO Vacuumed table table=pending_objects13892026/10/01 13:03:44 INFO Vacuumed table table=multipart_uploads13902026/10/01 13:03:44 INFO Vacuumed table table=closures13912026/10/01 13:03:44 INFO Vacuumed table table=objects13922026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=013932026/10/01 13:03:44 WARN Force mode enabled - objects will be deleted immediately without grace period1394=== NAME TestClientWithDependencies1395 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2851864857/001/store/rm4f0a0rprrqdl62agwq58bkq5iz36s2-test-script13962026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures13972026/10/01 13:03:44 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=013982026/10/01 13:03:44 INFO Vacuumed table table=pending_closures13992026/10/01 13:03:44 INFO Vacuumed table table=pending_objects14002026/10/01 13:03:44 INFO Vacuumed table table=multipart_uploads14012026/10/01 13:03:44 INFO Vacuumed table table=closures14022026/10/01 13:03:44 INFO Vacuumed table table=objects1403--- PASS: TestSweepSkipsRowsLockedByPush (0.45s)1404=== CONT TestService_ReadAuthMiddleware1405=== NAME TestClientMultipleUploads1406 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads222187804/001/store/1fkzgilrrh76z6kl8dcs1cq67q7hvq2s-test-file-0.txt1407=== NAME TestClientWithDependencies1408 client_integration_test.go:615: Found 1 dependencies (including self)14092026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes14102026/10/01 13:03:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14112026/10/01 13:03:45 INFO Uploading 6n00rzx5vj2nprp9s31q7h5nijgr3rpn-unpinned-file.txt (128B)14122026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures14132026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14142026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14152026/10/01 13:03:45 WARN Failed to register uploaded object key=6n00rzx5vj2nprp9s31q7h5nijgr3rpn.ls error="server returned 404: 404 page not found\n"14162026/10/01 13:03:45 INFO Signed narinfos id=2 count=114172026/10/01 13:03:45 INFO Uploading 1 narinfos1418=== NAME TestClientMultipleUploads1419 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads222187804/001/store/8rm9842fpk1zffdaq07ij949xa2xhjhs-test-file-1.txt14202026/10/01 13:03:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35383/oidc14212026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/2/complete14222026/10/01 13:03:45 WARN Failed to register uploaded object key=6n00rzx5vj2nprp9s31q7h5nijgr3rpn.narinfo error="server returned 404: 404 page not found\n"14232026/10/01 13:03:45 INFO Upload complete. (51ms)1424=== NAME TestClientIntegration1425 client_integration_test.go:286: Created store path: /build/TestClientIntegration401648403/002/store/41p1wpk48hq498j15g0sbx15b4gll3gn-test-file.txt14262026/10/01 13:03:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34269/oidc14272026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=014282026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period1429=== NAME TestClientMultipleUploads1430 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads222187804/001/store/nn21zy0mbyfkpql80sk5gh31jsnw0dqx-test-file-2.txt14312026/10/01 13:03:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures14322026/10/01 13:03:45 INFO Garbage collection started14332026/10/01 13:03:45 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14342026/10/01 13:03:45 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1435--- PASS: TestFailedS3DeleteKeepsTombstone (0.50s)1436=== CONT TestService_AuthMiddleware_MTLSProxyHeader14372026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes14382026/10/01 13:03:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14392026/10/01 13:03:45 INFO Uploading rm4f0a0rprrqdl62agwq58bkq5iz36s2-test-script (136B)14402026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=014412026/10/01 13:03:45 WARN Failed to register uploaded object key=log/x8cnrnlc0pwpp5ikvq37clbwz0ghyvcj-test-script.drv error="server returned 404: 404 page not found\n"14422026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14432026/10/01 13:03:45 WARN Failed to register uploaded object key=rm4f0a0rprrqdl62agwq58bkq5iz36s2.ls error="server returned 404: 404 page not found\n"14442026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14452026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=014462026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period14472026/10/01 13:03:45 INFO Signed narinfos id=1 count=114482026/10/01 13:03:45 INFO Uploading 1 narinfos14492026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period14502026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete14512026/10/01 13:03:45 WARN Failed to register uploaded object key=rm4f0a0rprrqdl62agwq58bkq5iz36s2.narinfo error="server returned 404: 404 page not found\n"1452--- PASS: TestCacheStatsHandler (0.29s)1453=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14542026/10/01 13:03:45 INFO Received uploads request method=POST path=/1455=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14562026/10/01 13:03:45 INFO Received complete multipart upload request method=POST path=/1457=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14582026/10/01 13:03:45 INFO Received request for more parts method=POST path=/1459=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14602026/10/01 13:03:45 INFO Received uploads request method=POST path=/1461--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1462 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1463 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1464 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1465 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1466=== CONT TestProxyWriteTimeout/narinfo1467=== CONT TestProxyWriteTimeout/unknown_size1468=== CONT TestProxyWriteTimeout/10_GiB_nar1469=== CONT TestProxyWriteTimeout/1_GiB_nar1470--- PASS: TestProxyWriteTimeout (0.06s)1471 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1472 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1473 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1474 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1475=== CONT TestPendingClosureWriteTimeout/empty1476=== CONT TestPendingClosureWriteTimeout/670k_objects1477=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline14782026/10/01 13:03:45 INFO Upload complete. (71ms)14792026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=01480=== NAME TestClientWithDependencies1481 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2851864857/001/store) requires matching store prefix14822026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes14832026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=014842026/10/01 13:03:45 INFO Vacuumed table table=pending_closures14852026/10/01 13:03:45 INFO Vacuumed table table=pending_closures1486--- PASS: TestClientWithDependencies (0.62s)1487=== CONT TestPendingClosureWriteTimeout/400_objects1488=== CONT TestIsValidUploadKey/narinfo14892026/10/01 13:03:45 INFO Vacuumed table table=pending_objects1490=== CONT TestIsValidUploadKey/empty_key1491=== CONT TestIsValidUploadKey/absolute1492=== CONT TestIsValidUploadKey/traversal_nar1493=== CONT TestIsValidUploadKey/traversal1494=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1495=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1496=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1497=== CONT TestIsValidUploadKey/index.html1498=== CONT TestIsValidUploadKey/nix-cache-info1499=== CONT TestIsValidUploadKey/realisation_plus_in_output15002026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads1501=== CONT TestIsValidUploadKey/realisation1502=== CONT TestIsValidUploadKey/build_log_equals1503=== CONT TestIsValidUploadKey/build_log_question_mark1504=== CONT TestIsValidUploadKey/build_log_plus_in_name15052026/10/01 13:03:45 INFO Vacuumed table table=closures1506=== CONT TestIsValidUploadKey/build_log_home-manager_file1507=== CONT TestIsValidUploadKey/build_log1508=== CONT TestIsValidUploadKey/listing1509=== CONT TestIsValidUploadKey/nar_plain1510=== CONT TestIsValidUploadKey/unknown_type1511=== CONT TestIsValidUploadKey/nar_xz1512=== CONT TestIsValidUploadKey/nar_zst1513--- PASS: TestIsValidUploadKey (0.07s)1514 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1515 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1516 --- PASS: TestIsValidUploadKey/absolute (0.00s)1517 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1518 --- PASS: TestIsValidUploadKey/traversal (0.00s)1519 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1520 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1521 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1522 --- PASS: TestIsValidUploadKey/index.html (0.00s)1523 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1524 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1525 --- PASS: TestIsValidUploadKey/realisation (0.00s)1526 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1527 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1528 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1529 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1530 --- PASS: TestIsValidUploadKey/build_log (0.00s)1531 --- PASS: TestIsValidUploadKey/listing (0.00s)1532 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1533 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1534 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1535 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1536=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15372026/10/01 13:03:45 INFO Received uploads request method=POST path=/15382026/10/01 13:03:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15392026/10/01 13:03:45 INFO Uploading 41p1wpk48hq498j15g0sbx15b4gll3gn-test-file.txt (152B)15402026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures15412026/10/01 13:03:45 INFO Vacuumed table table=pending_objects15422026/10/01 13:03:45 INFO Vacuumed table table=objects15432026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads15442026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1545--- PASS: TestGCSweepDeliversEachKeyOnce (0.40s)15462026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1547=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15482026/10/01 13:03:45 WARN Failed to register uploaded object key=41p1wpk48hq498j15g0sbx15b4gll3gn.ls error="server returned 404: 404 page not found\n"15492026/10/01 13:03:45 INFO Received request for more parts method=POST path=/15502026/10/01 13:03:45 INFO Signed narinfos id=1 count=115512026/10/01 13:03:45 INFO Uploading 1 narinfos15522026/10/01 13:03:45 INFO Vacuumed table table=closures1553--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.28s)1554=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15552026/10/01 13:03:45 INFO Received complete multipart upload request method=POST path=/15562026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete15572026/10/01 13:03:45 WARN Failed to register uploaded object key=41p1wpk48hq498j15g0sbx15b4gll3gn.narinfo error="server returned 404: 404 page not found\n"15582026/10/01 13:03:45 INFO Vacuumed table table=objects1559=== NAME TestClientCADerivations1560 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1462163034/001/store/i5di0zl51phni8q2cqvia2lbghk6bwif-ca-test15612026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes15622026/10/01 13:03:45 INFO Upload complete. (74ms)15632026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures15642026/10/01 13:03:45 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15652026/10/01 13:03:45 INFO Uploading nn21zy0mbyfkpql80sk5gh31jsnw0dqx-test-file-2.txt (160B)15662026/10/01 13:03:45 INFO Uploading 1fkzgilrrh76z6kl8dcs1cq67q7hvq2s-test-file-0.txt (160B)15672026/10/01 13:03:45 INFO Uploading 8rm9842fpk1zffdaq07ij949xa2xhjhs-test-file-1.txt (160B)15682026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15692026/10/01 13:03:45 WARN Failed to register uploaded object key=8rm9842fpk1zffdaq07ij949xa2xhjhs.ls error="server returned 404: 404 page not found\n"15702026/10/01 13:03:45 WARN Failed to register uploaded object key=1fkzgilrrh76z6kl8dcs1cq67q7hvq2s.ls error="server returned 404: 404 page not found\n"15712026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15722026/10/01 13:03:45 WARN Failed to register uploaded object key=nn21zy0mbyfkpql80sk5gh31jsnw0dqx.ls error="server returned 404: 404 page not found\n"15732026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15742026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15752026/10/01 13:03:45 INFO Signed narinfos id=1 count=315762026/10/01 13:03:45 INFO Uploading 3 narinfos15772026/10/01 13:03:45 WARN Failed to register uploaded object key=nn21zy0mbyfkpql80sk5gh31jsnw0dqx.narinfo error="server returned 404: 404 page not found\n"15782026/10/01 13:03:45 WARN Failed to register uploaded object key=8rm9842fpk1zffdaq07ij949xa2xhjhs.narinfo error="server returned 404: 404 page not found\n"15792026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete15802026/10/01 13:03:45 WARN Failed to register uploaded object key=1fkzgilrrh76z6kl8dcs1cq67q7hvq2s.narinfo error="server returned 404: 404 page not found\n"15812026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=015822026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period1583--- PASS: TestService_ReadScope_PublicByDefault (0.26s)15842026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01585=== CONT TestPush_RejectsBadRequests/no_roots15862026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1587=== CONT TestPush_RejectsBadRequests/bad_root15882026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1589=== CONT TestPush_RejectsBadRequests/root_not_in_objects15902026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1591=== CONT TestPush_RejectsBadRequests/no_objects15922026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1593=== CONT TestIsValidCachePath/narinfo1594--- PASS: TestPush_RejectsBadRequests (0.64s)1595 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1596 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1597 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1598 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1599=== CONT TestIsValidCachePath/index.html1600=== CONT TestIsValidCachePath/short_hash1601=== CONT TestIsValidCachePath/wrong_extension1602=== CONT TestIsValidCachePath/leading_slash1603=== CONT TestIsValidCachePath/empty16042026/10/01 13:03:45 INFO Upload complete. (71ms)1605=== CONT TestIsValidCachePath/random_path1606=== CONT TestIsValidCachePath/invalid_char_u1607=== CONT TestIsValidCachePath/invalid_char_e1608=== CONT TestIsValidCachePath/traversal_in_middle1609=== CONT TestIsValidCachePath/traversal_parent1610=== CONT TestIsValidCachePath/nar_uncompressed1611=== CONT TestIsValidCachePath/nix-cache-info1612=== CONT TestIsValidCachePath/nar_xz1613=== CONT TestIsValidCachePath/realisation1614=== CONT TestIsValidCachePath/nar_bz21615=== CONT TestIsValidCachePath/log1616=== CONT TestIsValidCachePath/ls16172026/10/01 13:03:45 INFO Vacuumed table table=pending_closures1618=== NAME TestClientMultipleUploads1619 client_integration_test.go:369: Uploaded 3 paths in 104.415989ms1620=== CONT TestIsValidCachePath/nar_zst1621=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1622=== CONT TestParseSingleRange/none1623=== CONT TestParseSingleRange/open-ended1624--- PASS: TestIsValidCachePath (0.00s)1625 --- PASS: TestIsValidCachePath/narinfo (0.00s)1626 --- PASS: TestIsValidCachePath/index.html (0.00s)1627 --- PASS: TestIsValidCachePath/short_hash (0.00s)1628 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1629 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1630 --- PASS: TestIsValidCachePath/empty (0.00s)1631 --- PASS: TestIsValidCachePath/random_path (0.00s)1632 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1633 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1634 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1635 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1636 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1637 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1638 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1639 --- PASS: TestIsValidCachePath/realisation (0.00s)1640 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1641 --- PASS: TestIsValidCachePath/log (0.00s)1642 --- PASS: TestIsValidCachePath/ls (0.00s)1643 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1644 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1645=== CONT TestParseSingleRange/start_far_past_EOF1646=== CONT TestParseSingleRange/start_past_EOF1647=== CONT TestParseSingleRange/single_byte1648=== CONT TestParseSingleRange/suffix_exceeds_size1649=== CONT TestParseSingleRange/suffix1650=== CONT TestParseSingleRange/end_clamped_to_size1651=== CONT TestParseSingleRange/closed1652=== CONT TestParseSingleRange/malformed_end_before_start1653=== CONT TestParseSingleRange/malformed_both_empty1654=== CONT TestParseSingleRange/multi-range_ignored1655=== CONT TestParseSingleRange/malformed_no_dash1656=== CONT TestParseSingleRange/unknown_unit1657--- PASS: TestParseSingleRange (0.00s)1658 --- PASS: TestParseSingleRange/none (0.00s)1659 --- PASS: TestParseSingleRange/open-ended (0.00s)1660 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1661 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1662 --- PASS: TestParseSingleRange/single_byte (0.00s)1663 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1664 --- PASS: TestParseSingleRange/suffix (0.00s)1665 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1666 --- PASS: TestParseSingleRange/closed (0.00s)1667 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1668 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1669 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1670 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1671 --- PASS: TestParseSingleRange/unknown_unit (0.00s)16722026/10/01 13:03:45 INFO Vacuumed table table=pending_objects1673=== CONT TestServerTLSConfig/no_client_CA1674=== CONT TestServerTLSConfig/not_a_PEM_file16752026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads16762026/10/01 13:03:45 INFO Vacuumed table table=closures1677=== CONT TestServerTLSConfig/missing_CA_file1678--- PASS: TestServerTLSConfig (0.00s)1679 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1680 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1681 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1682=== CONT TestResolveDBConnectionString/flag_wins1683=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1684=== CONT TestResolveDBConnectionString/nothing_configured1685=== CONT TestResolveDBConnectionString/missing_file_is_an_error1686=== CONT TestResolveDBConnectionString/file_when_flag_empty1687=== CONT TestCacheConfigHandler/full_config,_no_issuer1688=== CONT TestCacheConfigHandler/no_signing_keys16892026/10/01 13:03:45 INFO Vacuumed table table=objects1690=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1691=== CONT TestCacheConfigHandler/no_cache_url_configured1692--- PASS: TestResolveDBConnectionString (0.00s)1693 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1694 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1695 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1696 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1697 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1698=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1699--- PASS: TestCacheConfigHandler (0.00s)1700 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1701 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1702 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1703 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1704=== NAME TestClientCADerivations1705 client_ca_test.go:139: Found 1 dependencies (including self)17062026/10/01 13:03:45 INFO All 1 paths already cached1707=== NAME TestClientIntegration1708 client_integration_test.go:312: Retrieved narinfo from S3:1709 StorePath: /build/TestClientIntegration401648403/002/store/41p1wpk48hq498j15g0sbx15b4gll3gn-test-file.txt1710=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1711=== NAME TestClientIntegration1712 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1713 Compression: zstd1714 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11715 NarSize: 1521716 References: 1717 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11718--- PASS: TestClientMultipleUploads (0.62s)1719=== CONT TestClientErrorHandling/InvalidStorePath1720--- PASS: TestGCSweepSkipsPendingObjects (0.32s)1721=== NAME TestClientIntegration1722 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1723 client_integration_test.go:313: Decompressed .ls content (64 bytes):1724 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1725 client_integration_test.go:316: Testing garbage collection...17262026/10/01 13:03:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17272026/10/01 13:03:45 WARN mTLS auth: bound subjects configured but subject DN unavailable17282026/10/01 13:03:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1729--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.25s)1730=== CONT TestClientErrorHandling/ServerNotAvailable1731=== CONT TestClientErrorHandling/InvalidAuthToken1732--- PASS: TestService_ReadAuthMiddleware (0.24s)17332026/10/01 13:03:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures17342026/10/01 13:03:45 INFO Garbage collection started1735--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.62s)17362026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=01737=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1738=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1739=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1740=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1741=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1742=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1743=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1744=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1745=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token17462026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period1747=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1748=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured17492026/10/01 13:03:45 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1750=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17512026/10/01 13:03:45 WARN Authentication failed token_preview=eyJhbGciOi...OzX4SPFgLg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1752--- PASS: TestService_AuthMiddleware_OIDC (0.35s)1753 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1754 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1755 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1756 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)17572026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=017582026/10/01 13:03:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17592026/10/01 13:03:45 INFO Vacuumed table table=pending_closures17602026/10/01 13:03:45 INFO Vacuumed table table=pending_objects17612026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads17622026/10/01 13:03:45 INFO Vacuumed table table=closures17632026/10/01 13:03:45 INFO Vacuumed table table=objects17642026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1765=== RUN TestService_RequireScope_OIDC/builder_may_write1766=== PAUSE TestService_RequireScope_OIDC/builder_may_write1767=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1768=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1769=== RUN TestService_RequireScope_OIDC/ops_may_admin1770=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1771=== RUN TestService_RequireScope_OIDC/ops_may_not_write1772=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1773=== RUN TestService_RequireScope_OIDC/reader_may_not_write1774=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1775=== RUN TestService_RequireScope_OIDC/static_token_may_admin1776=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1777=== RUN TestService_RequireScope_OIDC/static_token_may_write1778=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1779=== RUN TestService_RequireScope_OIDC/reader_may_read1780=== PAUSE TestService_RequireScope_OIDC/reader_may_read1781=== RUN TestService_RequireScope_OIDC/writer_implies_read1782=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1783=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1784=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1785=== CONT TestService_RequireScope_OIDC/builder_may_write1786=== CONT TestService_RequireScope_OIDC/static_token_may_admin1787=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1788=== CONT TestService_RequireScope_OIDC/writer_implies_read1789=== CONT TestService_RequireScope_OIDC/reader_may_read1790=== CONT TestService_RequireScope_OIDC/static_token_may_write1791=== CONT TestService_RequireScope_OIDC/ops_may_not_write1792=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1793=== CONT TestService_RequireScope_OIDC/ops_may_admin1794=== CONT TestService_RequireScope_OIDC/reader_may_not_write17952026/10/01 13:03:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1796--- PASS: TestService_RequireScope_OIDC (0.36s)1797 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1798 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1799 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1800 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1801 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1802 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1803 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1804 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1805 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1806 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)18072026/10/01 13:03:45 INFO Uploading i5di0zl51phni8q2cqvia2lbghk6bwif-ca-test (144B)1808--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.22s)18092026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18102026/10/01 13:03:45 WARN Failed to register uploaded object key=log/q3bnz94ifzq87z3rlmqhy5rvxcx33r77-ca-test.drv error="server returned 404: 404 page not found\n"18112026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18122026/10/01 13:03:45 WARN Failed to register uploaded object key=i5di0zl51phni8q2cqvia2lbghk6bwif.ls error="server returned 404: 404 page not found\n"1813--- PASS: TestPushWaitsForSweepHoldingRow (0.98s)18142026/10/01 13:03:45 INFO Signed narinfos id=1 count=118152026/10/01 13:03:45 INFO Uploading 1 narinfos18162026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete18172026/10/01 13:03:45 WARN Failed to register uploaded object key=i5di0zl51phni8q2cqvia2lbghk6bwif.narinfo error="server returned 404: 404 page not found\n"18182026/10/01 13:03:45 INFO Upload complete. (105ms)1819=== NAME TestClientCADerivations1820 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1462163034/001/store/i5di0zl51phni8q2cqvia2lbghk6bwif-ca-test1821 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1822 Compression: zstd1823 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1824 NarSize: 1441825 References: 1826 Deriver: /build/TestClientCADerivations1462163034/001/store/q3bnz94ifzq87z3rlmqhy5rvxcx33r77-ca-test.drv1827 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1828 client_ca_test.go:185: Checking for realisation files in S3...1829 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1830 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18312026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures18322026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures18332026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=018342026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period18352026/10/01 13:03:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.546832ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18362026/10/01 13:03:45 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/01 13:03:45 INFO Vacuumed table table=pending_closures18382026/10/01 13:03:45 INFO Vacuumed table table=pending_objects18392026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads18402026/10/01 13:03:45 INFO Vacuumed table table=closures18412026/10/01 13:03:45 INFO Vacuumed table table=objects18422026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures18432026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=018442026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period18452026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018462026/10/01 13:03:45 INFO Vacuumed table table=pending_closures18472026/10/01 13:03:45 INFO Vacuumed table table=pending_objects18482026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads18492026/10/01 13:03:45 INFO Vacuumed table table=closures18502026/10/01 13:03:45 INFO Vacuumed table table=objects1851--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1852 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.22s)1853 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.25s)1854=== NAME TestClientCADerivations1855 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1856 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1857 error: binary cache 's3://bucket73?endpoint=http://localhost:38073®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1462163034/001/store'1858 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11859--- PASS: TestClientCADerivations (0.77s)18602026/10/01 13:03:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18612026/10/01 13:03:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18622026/10/01 13:03:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=394.195348ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18632026/10/01 13:03:45 INFO lead: released remote=192.0.2.1:12341864--- PASS: TestLeadEndsOnShutdown (1.61s)1865--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)1866 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1867 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.08s)1868 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.61s)1869=== NAME TestOrphanedObjectsGCStressTest1870 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains18712026/10/01 13:03:45 INFO lead: released remote=192.0.2.1:12341872 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18732026/10/01 13:03:45 INFO lead: acquired remote=192.0.2.1:123418742026/10/01 13:03:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=733.721295ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1875--- PASS: TestPendingClosureWriteTimeout (0.06s)1876 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1877 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1878 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1879 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.03s)1880=== NAME TestOrphanedObjectsGCStressTest1881 orphaned_objects_gc_test.go:509: Stress test completed successfully:1882 orphaned_objects_gc_test.go:510: - Active objects preserved: 201883 orphaned_objects_gc_test.go:511: - Objects deleted: 2101884 orphaned_objects_gc_test.go:512: - Total GC'd: 2101885--- PASS: TestOrphanedObjectsGCStressTest (2.50s)18862026/10/01 13:03:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.482379335s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18872026/10/01 13:03:46 INFO lead: released remote=192.0.2.1:12341888--- PASS: TestLeadElectsOneAndHandsOver (2.93s)18892026/10/01 13:03:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018902026/10/01 13:03:47 INFO Received create pin request method=POST path=/api/pins/myapp18912026/10/01 13:03:47 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1548693068/001/store/3wy2ngdrygyyx6bfy42fpd6m9l57k8qi-pinned-file.txt narinfo_key=3wy2ngdrygyyx6bfy42fpd6m9l57k8qi.narinfo18922026/10/01 13:03:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures18932026/10/01 13:03:47 INFO Garbage collection started18942026/10/01 13:03:47 INFO Aborted multipart uploads count=0 kept=018952026/10/01 13:03:47 WARN Force mode enabled - objects will be deleted immediately without grace period18962026/10/01 13:03:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018972026/10/01 13:03:47 INFO Vacuumed table table=pending_closures18982026/10/01 13:03:47 INFO Vacuumed table table=pending_objects18992026/10/01 13:03:47 INFO Vacuumed table table=multipart_uploads19002026/10/01 13:03:47 INFO Vacuumed table table=closures19012026/10/01 13:03:47 INFO Vacuumed table table=objects19022026/10/01 13:03:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01903=== NAME TestClientIntegration1904 client_integration_test.go:323: Objects in database after GC:1905 client_integration_test.go:323: Successfully deleted all objects with GC --force1906--- PASS: TestClientIntegration (2.64s)1907--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.81s)19082026/10/01 13:03:48 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-config19092026/10/01 13:03:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.177513ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19102026/10/01 13:03:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=422.118121ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19112026/10/01 13:03:48 WARN Rate limiter enabled after throttle name=s3-test rate=519122026/10/01 13:03:48 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1913=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1914 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101915 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001916--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.95s)19172026/10/01 13:03:48 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=872.939091ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1918=== NAME TestPinProtectsFromGC1919 client_integration_test.go:840: Pin successfully protected closure from garbage collection1920--- PASS: TestPinProtectsFromGC (4.78s)1921--- PASS: TestConnectWaitsForAPeerMigration (5.20s)19222026/10/01 13:03:49 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.67714061s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19232026/10/01 13:03:50 INFO Aborted multipart uploads count=1 kept=019242026/10/01 13:03:50 INFO Received cleanup request method=DELETE path=/api/pending_closures19252026/10/01 13:03:50 INFO Aborted multipart uploads count=1 kept=01926--- PASS: TestPendingCleanupUsesOneCutoff (6.63s)19272026/10/01 13:03:51 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"19282026/10/01 13:03:51 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-config19292026/10/01 13:03:51 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.010723ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19302026/10/01 13:03:51 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.820199ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19312026/10/01 13:03:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=796.599623ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19322026/10/01 13:03:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.577749086s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19332026/10/01 13:03:54 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19342026/10/01 13:03:54 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.530909ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19352026/10/01 13:03:54 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.845647ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19362026/10/01 13:03:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=870.200458ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19372026/10/01 13:03:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.584130239s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1938--- PASS: TestClientErrorHandling (0.00s)1939 --- PASS: TestClientErrorHandling/InvalidStorePath (0.23s)1940 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.33s)1941 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.63s)1942PASS1943{"timestamp":"2026-10-01T13:03:57.814090156Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:51648","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(391)"}19442026-10-01 13:03:58.142 UTC [128] LOG: received smart shutdown request19452026-10-01 13:03:58.146 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 119462026-10-01 13:03:58.161 UTC [133] LOG: shutting down19472026-10-01 13:03:58.162 UTC [133] LOG: checkpoint starting: shutdown immediate19482026-10-01 13:04:00.084 UTC [133] LOG: checkpoint complete: wrote 11085 buffers (67.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.273 s, sync=1.591 s, total=1.924 s; sync files=29992, longest=0.003 s, average=0.001 s; distance=414840 kB, estimate=414840 kB; lsn=0/1AC83D90, redo lsn=0/1AC83D9019492026-10-01 13:04:00.166 UTC [128] LOG: database system is shut down1950Running OIDC tests...1951=== RUN TestAudienceForIssuer1952=== PAUSE TestAudienceForIssuer1953=== RUN TestGlobMatch1954=== PAUSE TestGlobMatch1955=== RUN TestValidateToken_ValidToken1956=== PAUSE TestValidateToken_ValidToken1957=== RUN TestValidateToken_WrongAudience1958=== PAUSE TestValidateToken_WrongAudience1959=== RUN TestValidateToken_Expired1960=== PAUSE TestValidateToken_Expired1961=== RUN TestValidateToken_BoundClaimsMismatch1962=== PAUSE TestValidateToken_BoundClaimsMismatch1963=== RUN TestValidateToken_BoundSubjectMismatch1964=== PAUSE TestValidateToken_BoundSubjectMismatch1965=== RUN TestValidateToken_MultipleProviders1966=== PAUSE TestValidateToken_MultipleProviders1967=== RUN TestValidateToken_NoMatchingProvider1968=== PAUSE TestValidateToken_NoMatchingProvider1969=== RUN TestValidateToken_KubernetesServiceAccount1970=== PAUSE TestValidateToken_KubernetesServiceAccount1971=== RUN TestNewValidator_KubernetesRequiresCA1972=== PAUSE TestNewValidator_KubernetesRequiresCA1973=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1974=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1975=== RUN TestPins_ReservedForMatchingRule1976=== PAUSE TestPins_ReservedForMatchingRule1977=== RUN TestPins_TopLevelShorthand1978=== PAUSE TestPins_TopLevelShorthand1979=== RUN TestPins_ConfigValidation1980=== PAUSE TestPins_ConfigValidation1981=== RUN TestScopes_LegacyProviderDefaultsToWrite1982=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1983=== RUN TestScopes_Rules1984=== PAUSE TestScopes_Rules1985=== RUN TestScopes_ConfigValidation1986=== PAUSE TestScopes_ConfigValidation1987=== CONT TestAudienceForIssuer1988=== CONT TestValidateToken_BoundClaimsMismatch1989=== CONT TestValidateToken_WrongAudience1990--- PASS: TestAudienceForIssuer (0.00s)1991=== CONT TestValidateToken_ValidToken1992=== CONT TestValidateToken_KubernetesServiceAccount1993=== CONT TestGlobMatch1994=== RUN TestGlobMatch/foo_foo1995=== PAUSE TestGlobMatch/foo_foo1996=== RUN TestGlobMatch/foo_bar1997=== PAUSE TestGlobMatch/foo_bar1998=== RUN TestGlobMatch/*_1999=== PAUSE TestGlobMatch/*_2000=== RUN TestGlobMatch/*_anything2001=== PAUSE TestGlobMatch/*_anything2002=== RUN TestGlobMatch/foo*_foo2003=== PAUSE TestGlobMatch/foo*_foo2004=== RUN TestGlobMatch/foo*_foobar2005=== PAUSE TestGlobMatch/foo*_foobar2006=== RUN TestGlobMatch/foo*_bar2007=== CONT TestScopes_ConfigValidation2008=== CONT TestScopes_Rules2009=== CONT TestValidateToken_Expired2010=== CONT TestScopes_LegacyProviderDefaultsToWrite2011=== CONT TestPins_ReservedForMatchingRule2012=== CONT TestPins_ConfigValidation2013--- PASS: TestScopes_ConfigValidation (0.00s)2014--- PASS: TestPins_ConfigValidation (0.00s)2015=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2016=== CONT TestPins_TopLevelShorthand2017=== CONT TestValidateToken_MultipleProviders2018=== CONT TestNewValidator_KubernetesRequiresCA2019=== CONT TestValidateToken_NoMatchingProvider2020=== CONT TestValidateToken_BoundSubjectMismatch2021=== PAUSE TestGlobMatch/foo*_bar2022=== RUN TestGlobMatch/*bar_bar2023=== PAUSE TestGlobMatch/*bar_bar2024=== RUN TestGlobMatch/*bar_foobar2025=== PAUSE TestGlobMatch/*bar_foobar2026=== RUN TestGlobMatch/*bar_foo2027=== PAUSE TestGlobMatch/*bar_foo2028=== RUN TestGlobMatch/foo*bar_foobar2029=== PAUSE TestGlobMatch/foo*bar_foobar2030=== RUN TestGlobMatch/foo*bar_foo123bar2031=== PAUSE TestGlobMatch/foo*bar_foo123bar2032=== RUN TestGlobMatch/foo*bar_foobarbaz2033=== PAUSE TestGlobMatch/foo*bar_foobarbaz2034=== RUN TestGlobMatch/*/*_foo/bar2035=== PAUSE TestGlobMatch/*/*_foo/bar2036=== RUN TestGlobMatch/*/*_foo2037=== PAUSE TestGlobMatch/*/*_foo2038=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2039=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2040=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02041=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02042=== RUN TestGlobMatch/refs/*/main_refs/heads/main2043=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2044=== RUN TestGlobMatch/fo?_foo2045=== PAUSE TestGlobMatch/fo?_foo2046=== RUN TestGlobMatch/fo?_fo2047=== PAUSE TestGlobMatch/fo?_fo2048=== RUN TestGlobMatch/fo?_fooo2049=== PAUSE TestGlobMatch/fo?_fooo2050=== RUN TestGlobMatch/?oo_foo2051=== PAUSE TestGlobMatch/?oo_foo2052=== RUN TestGlobMatch/?oo_boo2053=== PAUSE TestGlobMatch/?oo_boo2054=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2055=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2056=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2057=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2058=== CONT TestGlobMatch/foo_foo2059=== CONT TestGlobMatch/*/*_foo2060=== CONT TestGlobMatch/fo?_fooo2061=== CONT TestGlobMatch/foo*_bar2062=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2063=== CONT TestGlobMatch/?oo_boo2064=== CONT TestGlobMatch/?oo_foo2065=== CONT TestGlobMatch/*bar_foo2066=== CONT TestGlobMatch/foo*bar_foobar2067=== CONT TestGlobMatch/refs/*/main_refs/heads/main2068=== CONT TestGlobMatch/fo?_fo2069=== CONT TestGlobMatch/fo?_foo2070=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02071=== CONT TestGlobMatch/foo*_foobar2072=== CONT TestGlobMatch/foo*_foo2073=== CONT TestGlobMatch/*_anything2074=== CONT TestGlobMatch/*_2075=== CONT TestGlobMatch/foo_bar2076=== CONT TestGlobMatch/foo*bar_foo123bar2077=== CONT TestGlobMatch/*/*_foo/bar2078=== CONT TestGlobMatch/foo*bar_foobarbaz2079=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2080=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2081=== CONT TestGlobMatch/*bar_foobar2082=== CONT TestGlobMatch/*bar_bar2083--- PASS: TestGlobMatch (0.01s)2084 --- PASS: TestGlobMatch/foo_foo (0.00s)2085 --- PASS: TestGlobMatch/*/*_foo (0.00s)2086 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2087 --- PASS: TestGlobMatch/foo*_bar (0.00s)2088 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2089 --- PASS: TestGlobMatch/?oo_boo (0.00s)2090 --- PASS: TestGlobMatch/?oo_foo (0.00s)2091 --- PASS: TestGlobMatch/*bar_foo (0.00s)2092 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2093 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2094 --- PASS: TestGlobMatch/fo?_fo (0.00s)2095 --- PASS: TestGlobMatch/fo?_foo (0.00s)2096 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2097 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2098 --- PASS: TestGlobMatch/foo*_foo (0.00s)2099 --- PASS: TestGlobMatch/*_anything (0.00s)2100 --- PASS: TestGlobMatch/*_ (0.00s)2101 --- PASS: TestGlobMatch/foo_bar (0.00s)2102 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2103 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2104 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2105 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2106 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2107 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2108 --- PASS: TestGlobMatch/*bar_bar (0.00s)21092026/10/01 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41561/oidc21102026/10/01 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35459/oidc2111--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)2112--- PASS: TestScopes_Rules (0.04s)21132026/10/01 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34495/oidc2114--- PASS: TestPins_TopLevelShorthand (0.03s)21152026/10/01 13:04:02 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:417432116--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)21172026/10/01 13:04:02 http: TLS handshake error from 127.0.0.1:48534: remote error: tls: bad certificate2118--- PASS: TestNewValidator_KubernetesRequiresCA (0.05s)21192026/10/01 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34497/oidc2120--- PASS: TestValidateToken_ValidToken (0.06s)21212026/10/01 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34349/oidc21222026/10/01 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34005/oidc2123--- PASS: TestPins_ReservedForMatchingRule (0.07s)2124--- PASS: TestValidateToken_Expired (0.07s)21252026/10/01 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40755/oidc2126--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)21272026/10/01 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35689/oidc2128--- PASS: TestValidateToken_WrongAudience (0.09s)21292026/10/01 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44079/oidc21302026/10/01 13:04:02 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232131--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)21322026/10/01 13:04:02 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46435/oidc2133--- PASS: TestValidateToken_NoMatchingProvider (0.10s)2134--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)21352026/10/01 13:04:02 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36187/oidc21362026/10/01 13:04:02 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44619/oidc2137--- PASS: TestValidateToken_MultipleProviders (0.12s)2138PASS2139Running hook tests...2140=== RUN TestSendPathsEmpty2141=== PAUSE TestSendPathsEmpty2142=== RUN TestQueueEnqueueAndFetch2143=== PAUSE TestQueueEnqueueAndFetch2144=== RUN TestQueueDeduplication2145=== PAUSE TestQueueDeduplication2146=== RUN TestQueueRemove2147=== PAUSE TestQueueRemove2148=== RUN TestQueueFetchBatchLimit2149=== PAUSE TestQueueFetchBatchLimit2150=== RUN TestQueueRetryMovesToBack2151=== PAUSE TestQueueRetryMovesToBack2152=== RUN TestQueueFetchRemoveLifecycle2153=== PAUSE TestQueueFetchRemoveLifecycle2154=== RUN TestQueueConcurrentWriters2155=== PAUSE TestQueueConcurrentWriters2156=== RUN TestQueueRemoveLargeClosure2157=== PAUSE TestQueueRemoveLargeClosure2158=== RUN TestServerClientIntegration2159=== PAUSE TestServerClientIntegration2160=== RUN TestServerQueueError2161=== PAUSE TestServerQueueError2162=== RUN TestGetListenerSocketActivation2163 server_test.go:210: === RUN TestGetListenerSocketActivation2164 --- PASS: TestGetListenerSocketActivation (0.00s)2165 PASS2166 2167--- PASS: TestGetListenerSocketActivation (0.01s)2168=== RUN TestDrainIsolatesPoisonPath2169=== PAUSE TestDrainIsolatesPoisonPath2170=== RUN TestRunNotBlockedByPoisonHead2171=== PAUSE TestRunNotBlockedByPoisonHead2172=== RUN TestDrainGivesUpWhenServerDown2173=== PAUSE TestDrainGivesUpWhenServerDown2174=== RUN TestFailedPathPrunedByLaterClosure2175=== PAUSE TestFailedPathPrunedByLaterClosure2176=== RUN TestWorkerUploadsAndRemoves2177=== PAUSE TestWorkerUploadsAndRemoves2178=== RUN TestWorkerSkipsGCdPaths2179=== PAUSE TestWorkerSkipsGCdPaths2180=== RUN TestWorkerPrunesClosureDeps2181=== PAUSE TestWorkerPrunesClosureDeps2182=== RUN TestDrainTimeout2183=== PAUSE TestDrainTimeout2184=== CONT TestSendPathsEmpty2185=== CONT TestServerQueueError2186--- PASS: TestSendPathsEmpty (0.00s)2187=== CONT TestQueueFetchBatchLimit2188=== CONT TestQueueRemove2189=== CONT TestQueueDeduplication2190=== CONT TestQueueRetryMovesToBack21912026/10/01 13:04:02 ERROR Failed to queue paths error="permission denied" count=12192=== CONT TestQueueEnqueueAndFetch2193=== CONT TestServerClientIntegration2194=== CONT TestWorkerUploadsAndRemoves2195=== CONT TestQueueRemoveLargeClosure2196=== CONT TestDrainTimeout2197=== CONT TestWorkerPrunesClosureDeps2198=== CONT TestQueueConcurrentWriters2199=== CONT TestWorkerSkipsGCdPaths2200=== CONT TestDrainGivesUpWhenServerDown2201=== CONT TestQueueFetchRemoveLifecycle2202=== CONT TestFailedPathPrunedByLaterClosure2203=== CONT TestRunNotBlockedByPoisonHead2204=== CONT TestDrainIsolatesPoisonPath2205--- PASS: TestServerQueueError (0.00s)2206--- PASS: TestServerClientIntegration (0.00s)22072026/10/01 13:04:02 INFO Uploading batch count=122082026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=122092026/10/01 13:04:02 INFO Uploading batch count=422102026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=422112026/10/01 13:04:02 INFO Uploading batch count=22212--- PASS: TestQueueFetchBatchLimit (0.02s)2213--- PASS: TestQueueEnqueueAndFetch (0.02s)22142026/10/01 13:04:02 INFO Upload queue status pending=222152026/10/01 13:04:02 INFO Upload queue status pending=32216--- PASS: TestQueueRetryMovesToBack (0.02s)22172026/10/01 13:04:02 INFO Uploading batch count=122182026/10/01 13:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2702736532/002/bbb22192026/10/01 13:04:02 INFO Uploading batch count=222202026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=222212026/10/01 13:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1157626310/002/a2222--- PASS: TestQueueRemove (0.02s)22232026/10/01 13:04:02 INFO Upload queue status pending=222242026/10/01 13:04:02 INFO Uploading batch count=122252026/10/01 13:04:02 INFO Upload queue status pending=222262026/10/01 13:04:02 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths147297392/002/nonexistent2227--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22282026/10/01 13:04:02 INFO Uploading batch count=122292026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=122302026/10/01 13:04:02 INFO Uploading batch count=22231--- PASS: TestQueueDeduplication (0.02s)22322026/10/01 13:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1157626310/002/b22332026/10/01 13:04:02 INFO Uploading batch count=122342026/10/01 13:04:02 INFO Uploading batch count=222352026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=222362026/10/01 13:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1157626310/002/c22372026/10/01 13:04:02 INFO Uploading batch count=122382026/10/01 13:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1157626310/002/d22392026/10/01 13:04:02 INFO Uploading batch count=122402026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=122412026/10/01 13:04:02 INFO Uploading batch count=222422026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=222432026/10/01 13:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1157626310/002/e2244--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22452026/10/01 13:04:02 INFO Uploading batch count=122462026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=122472026/10/01 13:04:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1157626310/002/f22482026/10/01 13:04:02 INFO Uploading batch count=122492026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=122502026/10/01 13:04:02 ERROR Drain finished with paths left in queue remaining=1022512026/10/01 13:04:02 ERROR Drain finished with paths left in queue remaining=12252--- PASS: TestDrainIsolatesPoisonPath (0.02s)2253--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2254--- PASS: TestWorkerPrunesClosureDeps (0.04s)2255--- PASS: TestWorkerUploadsAndRemoves (0.04s)2256--- PASS: TestWorkerSkipsGCdPaths (0.04s)2257--- PASS: TestQueueRemoveLargeClosure (0.10s)22582026/10/01 13:04:02 ERROR Upload failed error="context deadline exceeded" count=222592026/10/01 13:04:02 ERROR Drain finished with paths left in queue remaining=42260--- PASS: TestDrainTimeout (0.22s)2261--- PASS: TestQueueConcurrentWriters (0.50s)22622026/10/01 13:04:03 INFO Uploading batch count=122632026/10/01 13:04:03 INFO Uploading batch count=122642026/10/01 13:04:03 INFO Uploading batch count=122652026/10/01 13:04:03 ERROR Upload failed error="upload failed" count=122662026/10/01 13:04:03 INFO Uploading batch count=122672026/10/01 13:04:03 ERROR Upload failed error="upload failed" count=122682026/10/01 13:04:03 INFO Uploading batch count=122692026/10/01 13:04:03 ERROR Upload failed error="upload failed" count=122702026/10/01 13:04:03 INFO Uploading batch count=122712026/10/01 13:04:03 ERROR Upload failed error="upload failed" count=122722026/10/01 13:04:03 ERROR Drain finished with paths left in queue remaining=12273--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2274PASS