nixbot

builds

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #355 · raw

1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestScriptTokenEmptyCommand101--- PASS: TestScriptTokenEmptyCommand (0.00s)102=== CONT TestEncodeNixBase32103=== CONT TestDoWithRetry_BodyReplayedViaGetBody104=== CONT TestSetClientTLS105=== CONT TestClientSignaturesByStorePath106--- PASS: TestClientSignaturesByStorePath (0.00s)107=== CONT TestParsePathInfoJSON108=== RUN TestParsePathInfoJSON/Nix_format109=== CONT TestStreamPushReportsSignatures110=== CONT TestStreamPushRequestLine111=== CONT TestStreamPushGivesUpOnDeadServer112=== CONT TestStreamPushIsolatesFailures113=== CONT TestStreamPushBatchesUnderLoad114=== CONT TestStreamPushReportsEveryPath115=== CONT TestShellSplitErrors116=== CONT TestShellSplit117=== CONT TestSetClientTLSDoesNotMutateDefaultTransport118=== CONT TestScriptTokenNoExpiryRerunsEveryCall119=== CONT TestFileTokenEmpty120=== CONT TestScriptTokenScriptFails121=== CONT TestFileTokenMissing122=== CONT TestScriptTokenBadJSON123=== CONT TestFileTokenReadsAndCaches124=== CONT TestScriptTokenEmptyToken1252026/10/04 20:06:27 ERROR Upload failed error="bad path" count=3126=== CONT TestStaticToken127--- PASS: TestStaticToken (0.00s)128=== CONT TestScriptTokenCachesUntilRefresh129=== CONT TestSetClientTLSErrors130=== RUN TestEncodeNixBase32/test_string_hash131=== PAUSE TestParsePathInfoJSON/Nix_format132=== CONT TestParsePathInfoJSONMultiplePaths133--- PASS: TestFileTokenEmpty (0.00s)134=== CONT TestPathInfoHashCompatibility1352026/10/04 20:06:27 ERROR Upload failed error="connection refused" count=201362026/10/04 20:06:27 ERROR Server seems unavailable, giving up on batch untried=17137--- PASS: TestShellSplitErrors (0.00s)138=== CONT TestResolveStorePath139--- PASS: TestShellSplit (0.00s)140=== CONT TestGetStorePathHash141=== RUN TestGetStorePathHash/valid_store_path142=== PAUSE TestGetStorePathHash/valid_store_path143=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1442026/10/04 20:06:27 ERROR Upload failed error=boom count=1145=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error146=== CONT TestConvertHashToNix32147=== RUN TestConvertHashToNix32/SRI_format_to_Nix32148=== PAUSE TestEncodeNixBase32/test_string_hash149=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32150--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)151--- PASS: TestStreamPushReportsEveryPath (0.00s)152--- PASS: TestStreamPushIsolatesFailures (0.00s)153=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error154=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess155=== CONT TestRateLimiterFeedback156=== RUN TestEncodeNixBase32/empty_input157=== RUN TestConvertHashToNix32/already_Nix32_format158--- PASS: TestFileTokenMissing (0.00s)159--- PASS: TestScriptTokenScriptFails (0.00s)160=== RUN TestParsePathInfoJSON/Lix_format161=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths162=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)163=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)164=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon165=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon166=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1672026/10/04 20:06:27 ERROR Upload failed error=boom count=1168=== CONT TestDumpPathMatchesNix169=== RUN TestSetClientTLSErrors/missing_cert_file170--- PASS: TestResolveStorePath (0.00s)171=== RUN TestRateLimiterFeedback/429_enables_limiter172=== CONT TestEncodeNixBase32WithRealHash173=== PAUSE TestRateLimiterFeedback/429_enables_limiter174=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1752026/10/04 20:06:27 WARN Rate limiter enabled after throttle name=server-test rate=5176=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI177=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512178=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512179=== PAUSE TestEncodeNixBase32/empty_input180=== PAUSE TestParsePathInfoJSON/Lix_format181=== PAUSE TestConvertHashToNix32/already_Nix32_format182=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error183=== PAUSE TestSetClientTLSErrors/missing_cert_file184--- PASS: TestStreamPushReportsSignatures (0.01s)185=== CONT TestDumpPathWriterError186=== RUN TestConvertHashToNix32/invalid_format1872026/10/04 20:06:27 WARN Rate limiter enabled after throttle name=server-test rate=5188--- PASS: TestEncodeNixBase32WithRealHash (0.00s)189--- PASS: TestFileTokenReadsAndCaches (0.00s)1902026/10/04 20:06:27 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45267191=== CONT TestPathInfoCACompatibility192=== RUN TestRateLimiterFeedback/503_enables_limiter193=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths194=== RUN TestSetClientTLSErrors/missing_key_file195=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error196=== PAUSE TestSetClientTLSErrors/missing_key_file197=== CONT TestUploadMultipart_SupersededByPeer198=== RUN TestUploadMultipart_SupersededByPeer/exists199=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun200=== RUN TestSetClientTLS/rejects_connection_without_client_cert201=== PAUSE TestUploadMultipart_SupersededByPeer/exists202=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert203=== RUN TestParsePathInfoJSON/empty_input204=== PAUSE TestParsePathInfoJSON/empty_input2052026/10/04 20:06:27 WARN Rate limiter backed off name=server-test rate=5206=== RUN TestParsePathInfoJSON/whitespace_only2072026/10/04 20:06:27 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45267208=== CONT TestCaseHackSuffix209=== PAUSE TestConvertHashToNix32/invalid_format210--- PASS: TestScriptTokenBadJSON (0.01s)211=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica212=== RUN TestPathInfoCACompatibility/null_ca_field213=== PAUSE TestRateLimiterFeedback/503_enables_limiter214=== CONT TestFilterOversizedClosures215=== RUN TestSetClientTLSErrors/missing_ca_file216=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error217=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths218=== CONT TestUploadMultipart_PartsInParallel219=== CONT TestDumpPathSingleFile220=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA221=== RUN TestUploadMultipart_SupersededByPeer/missing222=== RUN TestFilterOversizedClosures/no_limit_keeps_everything223=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything224=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped225=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped226=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA227--- PASS: TestScriptTokenEmptyToken (0.00s)228--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)229--- PASS: TestDoServerRequestAttachesToken (0.01s)230=== PAUSE TestParsePathInfoJSON/whitespace_only231=== RUN TestFilterOversizedClosures/all_closures_skipped232=== PAUSE TestFilterOversizedClosures/all_closures_skipped233=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter234=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512235=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter236=== RUN TestParsePathInfoJSON/invalid_JSON237=== PAUSE TestSetClientTLSErrors/missing_ca_file238=== RUN TestSetClientTLSErrors/invalid_ca_file239=== PAUSE TestPathInfoCACompatibility/null_ca_field240=== RUN TestPathInfoCACompatibility/old_string_format_-_text241=== CONT TestPartSizeForNAR242=== RUN TestPartSizeForNAR/zero_stays_at_minimum243=== CONT TestEncodeNixBase32/test_string_hash244=== CONT TestEncodeNixBase32/empty_input245=== CONT TestConvertHashToNix32/SRI_format_to_Nix32246=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)247=== CONT TestRegisterUploadedObjectReusesConnections248=== PAUSE TestUploadMultipart_SupersededByPeer/missing249=== RUN TestSetClientTLS/preserves_debug_logging_transport250=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter251=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI252=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text253=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive254=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive255=== PAUSE TestSetClientTLSErrors/invalid_ca_file2562026/10/04 20:06:27 INFO Garbage collection started257=== PAUSE TestParsePathInfoJSON/invalid_JSON2582026/10/04 20:06:27 INFO Garbage collection started259=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum260=== RUN TestPartSizeForNAR/small_stays_at_minimum261=== PAUSE TestPartSizeForNAR/small_stays_at_minimum262=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum263=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum264=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts265=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts266=== RUN TestPartSizeForNAR/1_TiB267=== PAUSE TestPartSizeForNAR/1_TiB268=== RUN TestPartSizeForNAR/5_TiB_S3_max_object269=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object270=== RUN TestPartSizeForNAR/capped_at_5_GiB271=== PAUSE TestPartSizeForNAR/capped_at_5_GiB272--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)273=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths274=== CONT TestFilterOversizedClosures/no_limit_keeps_everything275=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped276=== CONT TestFilterOversizedClosures/all_closures_skipped2772026/10/04 20:06:27 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=50278=== CONT TestUploadMultipart_SupersededByPeer/exists2792026/10/04 20:06:27 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=2000280--- PASS: TestFilterOversizedClosures (0.00s)281 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)282 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)283 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)284=== CONT TestUploadMultipart_SupersededByPeer/missing285=== CONT TestConvertHashToNix32/invalid_format286=== CONT TestSetClientTLSErrors/missing_cert_file287=== CONT TestSetClientTLSErrors/invalid_ca_file2882026/10/04 20:06:27 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0289=== CONT TestConvertHashToNix32/already_Nix32_format290=== CONT TestSetClientTLSErrors/missing_key_file291=== CONT TestParsePathInfoJSON/Nix_format292=== CONT TestParsePathInfoJSON/whitespace_only293=== CONT TestParsePathInfoJSON/invalid_JSON294=== CONT TestGetStorePathHash/valid_store_path295=== CONT TestParsePathInfoJSON/Lix_format296=== CONT TestPartSizeForNAR/capped_at_5_GiB297=== CONT TestPartSizeForNAR/5_TiB_S3_max_object298=== CONT TestPartSizeForNAR/1_TiB299=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum300=== CONT TestPartSizeForNAR/small_stays_at_minimum301=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts302=== PAUSE TestSetClientTLS/preserves_debug_logging_transport303=== CONT TestSetClientTLS/rejects_connection_without_client_cert304=== CONT TestSetClientTLS/preserves_debug_logging_transport305=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error306=== RUN TestPathInfoCACompatibility/new_structured_format_-_text307=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text308=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error309=== CONT TestGetStorePathHash/basename_without_hyphen_should_error310=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths311--- PASS: TestEncodeNixBase32 (0.01s)312 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)313 --- PASS: TestEncodeNixBase32/empty_input (0.00s)314--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)315--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)316=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method317=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method318=== CONT TestPathInfoCACompatibility/null_ca_field319--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)320=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method321=== CONT TestPathInfoCACompatibility/new_structured_format_-_text322=== CONT TestPathInfoCACompatibility/old_string_format_-_text323=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive324=== CONT TestSetClientTLSErrors/missing_ca_file325=== CONT TestPartSizeForNAR/zero_stays_at_minimum326=== CONT TestParsePathInfoJSON/empty_input327=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter3282026/10/04 20:06:27 WARN Garbage collection finished on another replica. Its statistics are not available here329=== CONT TestRateLimiterFeedback/429_enables_limiter330=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA331=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter332=== CONT TestRateLimiterFeedback/503_enables_limiter333=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter334=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon335--- PASS: TestConvertHashToNix32 (0.01s)336 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)337 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)338 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)339--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)340 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)341 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)3422026/10/04 20:06:27 WARN Rate limiter enabled after throttle name=server-test rate=5343--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)344 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)345 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)3462026/10/04 20:06:27 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:42115347--- PASS: TestGetStorePathHash (0.01s)348 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)349 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)350 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)351 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)352--- PASS: TestPathInfoCACompatibility (0.03s)353 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)354 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)355 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)356 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)357 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)3582026/10/04 20:06:27 WARN Rate limiter enabled after throttle name=server-test rate=53592026/10/04 20:06:27 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:330953602026/10/04 20:06:27 WARN Rate limiter backed off name=server-test rate=5361--- PASS: TestPartSizeForNAR (0.00s)362 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)363 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)364 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)365 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)368 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)369--- PASS: TestParsePathInfoJSON (0.04s)370 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)371 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)372 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)373 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)374 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)375--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)3762026/10/04 20:06:27 WARN Rate limiter backed off name=server-test rate=5377--- PASS: TestPathInfoHashCompatibility (0.00s)378 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)379 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)380 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)381 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)382--- PASS: TestSetClientTLSErrors (0.04s)383 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)384 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)385 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)386 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)387--- PASS: TestRateLimiterFeedback (0.04s)388 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)389 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)390 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)391 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)3922026/10/04 20:06:27 http: TLS handshake error from 127.0.0.1:35324: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.04s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)397--- PASS: TestStreamPushRequestLine (0.06s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)399--- PASS: TestCaseHackSuffix (0.06s)400--- PASS: TestDumpPathSingleFile (0.06s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.11s)404--- PASS: TestUploadMultipart_PartsInParallel (0.64s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres1524838879/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres1524838879/data -l logfile start434435/build/postgres1524838879:5432 - no response4362026-10-04 20:06:29.528 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-04 20:06:29.529 UTC [129] LOG: listening on Unix socket "/build/postgres1524838879/.s.PGSQL.5432"4382026-10-04 20:06:29.532 UTC [136] LOG: database system was shut down at 2026-10-04 20:06:29 UTC4392026-10-04 20:06:29.536 UTC [129] LOG: database system is ready to accept connections440/build/postgres1524838879:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== RUN TestResolveDBConnectionString480=== PAUSE TestResolveDBConnectionString481=== RUN TestConnectWaitsForAPeerMigration482=== PAUSE TestConnectWaitsForAPeerMigration483=== RUN TestLeadElectsOneAndHandsOver484=== PAUSE TestLeadElectsOneAndHandsOver485=== RUN TestLeadIncumbentWinsAfterRestart4862026/10/04 20:06:29 INFO lead: acquired remote=192.0.2.1:12344872026/10/04 20:06:31 INFO lead: released remote=192.0.2.1:12344882026/10/04 20:06:31 INFO lead: acquired remote=192.0.2.1:12344892026/10/04 20:06:32 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (2.29s)491=== RUN TestLeadEndsOnShutdown492=== PAUSE TestLeadEndsOnShutdown493=== RUN TestLeadEndsWhenItsConnectionHangs4942026/10/04 20:06:32 INFO lead: acquired remote=192.0.2.1:12344952026-10-04 20:06:33.627 UTC [383] FATAL: terminating connection due to administrator command4962026/10/04 20:06:33 INFO lead: acquired remote=192.0.2.1:12344972026/10/04 20:06:34 WARN lead: lock connection lost error="timeout: context deadline exceeded"4982026/10/04 20:06:34 INFO lead: released remote=192.0.2.1:12344992026/10/04 20:06:35 INFO lead: released remote=192.0.2.1:1234500--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)501=== RUN TestGCAdvisoryLockBlocksConcurrentRun502=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun503=== RUN TestGCBugBareHashReferences504=== PAUSE TestGCBugBareHashReferences505=== RUN TestGCMetrics506=== PAUSE TestGCMetrics507=== RUN TestPushDedupSurvivesConcurrentGC508=== PAUSE TestPushDedupSurvivesConcurrentGC509=== RUN TestDeduplicatedObjectsRecordedAsPending510=== PAUSE TestDeduplicatedObjectsRecordedAsPending511=== RUN TestGCSweepSkipsPendingObjects512=== PAUSE TestGCSweepSkipsPendingObjects513=== RUN TestTombstonedObjectOfferedWithoutWaiting514=== PAUSE TestTombstonedObjectOfferedWithoutWaiting515=== RUN TestGCSweepDeliversEachKeyOnce516=== PAUSE TestGCSweepDeliversEachKeyOnce517=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection518=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection519=== RUN TestForceGCDuringPushOffersSweptObject520=== PAUSE TestForceGCDuringPushOffersSweptObject521=== RUN TestFailedS3DeleteKeepsTombstone522=== PAUSE TestFailedS3DeleteKeepsTombstone523=== RUN TestSweepSkipsRowsLockedByPush524=== PAUSE TestSweepSkipsRowsLockedByPush525=== RUN TestRegisterCompletedObjectNeedsPendingRow526=== PAUSE TestRegisterCompletedObjectNeedsPendingRow527=== RUN TestGetExistingObjectsLocksRows528=== PAUSE TestGetExistingObjectsLocksRows529=== RUN TestSweepRechecksPendingAfterLocking530=== PAUSE TestSweepRechecksPendingAfterLocking531=== RUN TestPushWaitsForSweepHoldingRow532=== PAUSE TestPushWaitsForSweepHoldingRow533=== RUN TestCommitRacingPendingCleanupKeepsObjects534=== PAUSE TestCommitRacingPendingCleanupKeepsObjects535=== RUN TestGCEndsOnShutdown536=== PAUSE TestGCEndsOnShutdown537=== RUN TestGCTaskStore_StartNew538=== PAUSE TestGCTaskStore_StartNew539=== RUN TestGCTaskStore_DeduplicateSameParams540=== PAUSE TestGCTaskStore_DeduplicateSameParams541=== RUN TestGCTaskStore_ConflictDifferentParams542=== PAUSE TestGCTaskStore_ConflictDifferentParams543=== RUN TestGCTaskStore_GetEmpty544=== PAUSE TestGCTaskStore_GetEmpty545=== RUN TestGCTaskStore_GetReturnsLatest546=== PAUSE TestGCTaskStore_GetReturnsLatest547=== RUN TestGCTaskStore_CompletedAllowsNewTask548=== PAUSE TestGCTaskStore_CompletedAllowsNewTask549=== RUN TestGCTaskStore_PhaseUpdates550=== PAUSE TestGCTaskStore_PhaseUpdates551=== RUN TestGCTaskStore_Fail552=== PAUSE TestGCTaskStore_Fail553=== RUN TestGracefulShutdownDrainsInflight554=== PAUSE TestGracefulShutdownDrainsInflight555=== RUN TestService_healthCheckHandler556=== PAUSE TestService_healthCheckHandler557=== RUN TestService_readinessHandler558=== PAUSE TestService_readinessHandler559=== RUN TestGenerateLandingPage560=== PAUSE TestGenerateLandingPage561=== RUN TestCacheConfigHandlerMaxNarSize562=== PAUSE TestCacheConfigHandlerMaxNarSize563=== RUN TestCreatePendingClosureRejectsOversizedNAR564=== PAUSE TestCreatePendingClosureRejectsOversizedNAR565=== RUN TestNARDeduplicationMetadataUploadBug566=== PAUSE TestNARDeduplicationMetadataUploadBug567=== RUN TestMetricsInventory568=== PAUSE TestMetricsInventory569=== RUN TestService_NativeMTLS570=== PAUSE TestService_NativeMTLS571=== RUN TestServerTLSConfig572=== PAUSE TestServerTLSConfig573=== RUN TestMultipartCleanup574=== PAUSE TestMultipartCleanup575=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded576=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded577=== RUN TestPendingCleanupUsesOneCutoff578=== PAUSE TestPendingCleanupUsesOneCutoff579=== RUN TestObjectStatsTrigger580=== PAUSE TestObjectStatsTrigger581=== RUN TestOrphanedObjectsGC582=== PAUSE TestOrphanedObjectsGC583=== RUN TestOrphanedObjectsGCStressTest584=== PAUSE TestOrphanedObjectsGCStressTest585=== RUN TestCreatePin_ReservedPins586=== PAUSE TestCreatePin_ReservedPins587=== RUN TestPresentReportsOnlyClosureRoots588=== PAUSE TestPresentReportsOnlyClosureRoots589=== RUN TestPresentNotReportedWhileGCDeletesClosure590=== PAUSE TestPresentNotReportedWhileGCDeletesClosure591=== RUN TestParseSingleRange592=== PAUSE TestParseSingleRange593=== RUN TestProxyHeadersOnlyTrustedOnSocket594=== PAUSE TestProxyHeadersOnlyTrustedOnSocket595=== RUN TestIsValidCachePath596=== PAUSE TestIsValidCachePath597=== RUN TestReadProxyNarinfo598=== PAUSE TestReadProxyNarinfo599=== RUN TestReadProxyNarinfoAlreadyDecompressed600=== PAUSE TestReadProxyNarinfoAlreadyDecompressed601=== RUN TestReadProxyNarStreaming602=== PAUSE TestReadProxyNarStreaming603=== RUN TestReadProxy404604=== PAUSE TestReadProxy404605=== RUN TestReadProxyInvalidPath606=== PAUSE TestReadProxyInvalidPath607=== RUN TestReadProxyHead608=== PAUSE TestReadProxyHead609=== RUN TestReadProxyOutlastsServerWriteTimeout610=== PAUSE TestReadProxyOutlastsServerWriteTimeout611=== RUN TestReadProxyConditionalGet612=== PAUSE TestReadProxyConditionalGet613=== RUN TestReadProxyRootRedirectsToIndexHTML614=== PAUSE TestReadProxyRootRedirectsToIndexHTML615=== RUN TestReadProxyDisabled616=== PAUSE TestReadProxyDisabled617=== RUN TestReadRedirectNar618=== PAUSE TestReadRedirectNar619=== RUN TestReadRedirectKeepsNarinfoProxied620=== PAUSE TestReadRedirectKeepsNarinfoProxied621=== RUN TestReadProxyRangeRequest622=== PAUSE TestReadProxyRangeRequest623=== RUN TestReadRedirectUsesPublicS3URL624=== PAUSE TestReadRedirectUsesPublicS3URL625=== RUN TestPush_OverlappingRootsStoreOneRowPerKey626=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey627=== RUN TestPush_CompleteCommitsEveryRoot628=== PAUSE TestPush_CompleteCommitsEveryRoot629=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit630=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit631=== RUN TestPush_RejectsBadRequests632=== PAUSE TestPush_RejectsBadRequests633=== RUN TestPush_SignsNarinfosOfItsPendingObjects634=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects635=== RUN TestRedundantMultipartUpload636=== PAUSE TestRedundantMultipartUpload637=== RUN TestCompleteMultipartUpload_ErrorButObjectExists638=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists639=== RUN TestCompletedNarNotReofferedAcrossClosures640=== PAUSE TestCompletedNarNotReofferedAcrossClosures641=== RUN TestPresignedUploadRegisteredBeforeCommit642=== PAUSE TestPresignedUploadRegisteredBeforeCommit643=== RUN TestService_Rustfstest644=== PAUSE TestService_Rustfstest645=== RUN TestParseSize646=== PAUSE TestParseSize647=== RUN TestSkippedUploadsHandler648=== PAUSE TestSkippedUploadsHandler649=== RUN TestSystemdListenerNotActivated650--- PASS: TestSystemdListenerNotActivated (0.00s)651=== RUN TestWatchdogBeatsWhenHealthy652--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)653=== RUN TestWatchdogSkipsWhenUnhealthy6542026/10/04 20:06:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/04 20:06:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/04 20:06:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/04 20:06:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/04 20:06:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/04 20:06:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/04 20:06:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/04 20:06:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/04 20:06:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/04 20:06:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"664--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)665=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle666=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle667=== RUN TestProxyWriteTimeout668=== PAUSE TestProxyWriteTimeout669=== RUN TestPendingClosureWriteTimeout670=== PAUSE TestPendingClosureWriteTimeout671=== RUN TestIsValidUploadKey672=== PAUSE TestIsValidUploadKey673=== RUN TestUploadHandlersRejectInvalidKeys674=== PAUSE TestUploadHandlersRejectInvalidKeys675=== RUN TestUploadHandlersRejectOversizedBody676=== PAUSE TestUploadHandlersRejectOversizedBody677=== RUN TestService_cleanupPendingClosuresHandler678=== PAUSE TestService_cleanupPendingClosuresHandler679=== RUN TestService_createPendingClosureHandler680=== PAUSE TestService_createPendingClosureHandler681=== RUN TestService_verifyS3Integrity682=== PAUSE TestService_verifyS3Integrity683=== RUN TestCompleteMultipartUnregistered684=== PAUSE TestCompleteMultipartUnregistered685=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT686=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT687=== CONT TestService_AuthMiddleware688=== CONT TestGracefulShutdownDrainsInflight689=== CONT TestUploadHandlersRejectOversizedBody690=== CONT TestService_cleanupPendingClosuresHandler691=== CONT TestPendingClosureWriteTimeout692=== RUN TestPendingClosureWriteTimeout/empty693=== PAUSE TestPendingClosureWriteTimeout/empty694=== RUN TestPendingClosureWriteTimeout/400_objects695=== PAUSE TestPendingClosureWriteTimeout/400_objects696=== RUN TestPendingClosureWriteTimeout/670k_objects697=== PAUSE TestPendingClosureWriteTimeout/670k_objects698=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT6992026/10/04 20:06:35 INFO Starting HTTP server address=127.0.0.1:44857700=== CONT TestCompleteMultipartUnregistered701=== CONT TestService_verifyS3Integrity702=== CONT TestService_createPendingClosureHandler703=== CONT TestIsValidUploadKey704=== RUN TestIsValidUploadKey/narinfo705=== CONT TestProxyWriteTimeout706=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle707=== CONT TestGCMetrics708=== CONT TestGetExistingObjectsLocksRows709=== CONT TestSweepRechecksPendingAfterLocking710=== CONT TestRegisterCompletedObjectNeedsPendingRow711=== CONT TestGCTaskStore_Fail712=== CONT TestSweepSkipsRowsLockedByPush713=== CONT TestGCTaskStore_PhaseUpdates714=== CONT TestFailedS3DeleteKeepsTombstone715=== CONT TestGCTaskStore_CompletedAllowsNewTask716=== CONT TestForceGCDuringPushOffersSweptObject717=== CONT TestGCTaskStore_GetReturnsLatest718=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection719=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline720=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline721--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)722=== CONT TestGCSweepDeliversEachKeyOnce723--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)724=== PAUSE TestIsValidUploadKey/narinfo725=== CONT TestGCTaskStore_GetEmpty7262026/10/04 20:06:35 INFO Shutdown signal received, draining in-flight requests timeout=10s727=== CONT TestGCTaskStore_ConflictDifferentParams728=== CONT TestGCTaskStore_DeduplicateSameParams729=== CONT TestGCSweepSkipsPendingObjects730=== CONT TestDeduplicatedObjectsRecordedAsPending731=== RUN TestIsValidUploadKey/nar_zst732=== PAUSE TestIsValidUploadKey/nar_zst733=== RUN TestIsValidUploadKey/nar_xz734=== PAUSE TestIsValidUploadKey/nar_xz735=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows736=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows737=== CONT TestTombstonedObjectOfferedWithoutWaiting738=== RUN TestProxyWriteTimeout/narinfo739=== PAUSE TestProxyWriteTimeout/narinfo740=== RUN TestProxyWriteTimeout/1_GiB_nar741=== PAUSE TestProxyWriteTimeout/1_GiB_nar742=== RUN TestProxyWriteTimeout/10_GiB_nar743=== PAUSE TestProxyWriteTimeout/10_GiB_nar744=== RUN TestProxyWriteTimeout/unknown_size745=== PAUSE TestProxyWriteTimeout/unknown_size746=== CONT TestPushDedupSurvivesConcurrentGC747=== CONT TestGCTaskStore_StartNew748=== CONT TestGCEndsOnShutdown749--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)750--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)751--- PASS: TestGCTaskStore_Fail (0.00s)752--- PASS: TestGCTaskStore_GetEmpty (0.00s)753--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)754--- PASS: TestGCTaskStore_StartNew (0.00s)755=== RUN TestIsValidUploadKey/nar_plain756=== PAUSE TestIsValidUploadKey/nar_plain757=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check758=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check759=== RUN TestIsValidUploadKey/listing760=== CONT TestCommitRacingPendingCleanupKeepsObjects761=== PAUSE TestIsValidUploadKey/listing762=== RUN TestIsValidUploadKey/build_log763=== PAUSE TestIsValidUploadKey/build_log764=== RUN TestIsValidUploadKey/build_log_home-manager_file765=== PAUSE TestIsValidUploadKey/build_log_home-manager_file766=== RUN TestIsValidUploadKey/build_log_plus_in_name767=== PAUSE TestIsValidUploadKey/build_log_plus_in_name768=== RUN TestIsValidUploadKey/build_log_question_mark769=== PAUSE TestIsValidUploadKey/build_log_question_mark770=== RUN TestIsValidUploadKey/build_log_equals771=== PAUSE TestIsValidUploadKey/build_log_equals772=== RUN TestIsValidUploadKey/realisation773=== PAUSE TestIsValidUploadKey/realisation774=== RUN TestIsValidUploadKey/realisation_plus_in_output775=== PAUSE TestIsValidUploadKey/realisation_plus_in_output776=== RUN TestIsValidUploadKey/nix-cache-info777=== PAUSE TestIsValidUploadKey/nix-cache-info778=== RUN TestIsValidUploadKey/index.html779=== PAUSE TestIsValidUploadKey/index.html780=== RUN TestIsValidUploadKey/narinfo_key,_nar_type781=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type782=== RUN TestIsValidUploadKey/nar_key,_narinfo_type783=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type784=== RUN TestIsValidUploadKey/listing_key,_narinfo_type785=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type786=== RUN TestIsValidUploadKey/traversal787=== PAUSE TestIsValidUploadKey/traversal788=== RUN TestIsValidUploadKey/traversal_nar789=== PAUSE TestIsValidUploadKey/traversal_nar790=== RUN TestIsValidUploadKey/absolute791=== PAUSE TestIsValidUploadKey/absolute792=== RUN TestIsValidUploadKey/empty_key793=== PAUSE TestIsValidUploadKey/empty_key794=== RUN TestIsValidUploadKey/unknown_type795=== PAUSE TestIsValidUploadKey/unknown_type796=== CONT TestUploadHandlersRejectInvalidKeys797=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info798=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info799=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal800=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal801=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key802=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key803=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key804=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key805=== CONT TestReadProxyNarStreaming806--- PASS: TestGracefulShutdownDrainsInflight (0.14s)807=== CONT TestPushWaitsForSweepHoldingRow808=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure809=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure810=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart811=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart812=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts813=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts814=== CONT TestSkippedUploadsHandler8152026/10/04 20:06:35 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000816--- PASS: TestSkippedUploadsHandler (0.01s)817=== CONT TestClientWithDependencies8182026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures819--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.27s)820=== CONT TestCacheConfigHandler821=== RUN TestCacheConfigHandler/full_config,_no_issuer822=== PAUSE TestCacheConfigHandler/full_config,_no_issuer823=== RUN TestCacheConfigHandler/no_cache_url_configured824=== PAUSE TestCacheConfigHandler/no_cache_url_configured825=== RUN TestCacheConfigHandler/no_signing_keys826=== PAUSE TestCacheConfigHandler/no_signing_keys827=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator828=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator829=== CONT TestParseSize830--- PASS: TestParseSize (0.00s)831=== CONT TestGCBugBareHashReferences8322026/10/04 20:06:35 INFO Received cleanup request method=DELETE path=/api/pending_closures8332026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=08342026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures8352026/10/04 20:06:35 INFO Received cleanup request method=DELETE path=/api/pending_closures8362026/10/04 20:06:35 INFO Aborted multipart uploads count=1 kept=08372026/10/04 20:06:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8382026-10-04 20:06:35.548 UTC [448] ERROR: Closure does not exist: id=18392026-10-04 20:06:35.548 UTC [448] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8402026-10-04 20:06:35.548 UTC [448] STATEMENT: -- name: CommitPendingClosure :exec841 SELECT commit_pending_closure($1::bigint)842 843--- PASS: TestService_cleanupPendingClosuresHandler (0.29s)844=== CONT TestClientMultipleUploads845--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.29s)846=== CONT TestService_Rustfstest8472026/10/04 20:06:35 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"848--- PASS: TestService_AuthMiddleware (0.31s)849=== CONT TestGCAdvisoryLockBlocksConcurrentRun8502026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures8512026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures8522026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures8532026/10/04 20:06:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8542026/10/04 20:06:35 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst855--- PASS: TestCompleteMultipartUnregistered (0.36s)856=== CONT TestClientIntegration8572026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=08582026/10/04 20:06:35 WARN Force mode enabled - objects will be deleted immediately without grace period8592026/10/04 20:06:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08602026/10/04 20:06:35 INFO Vacuumed table table=pending_closures8612026/10/04 20:06:35 INFO Vacuumed table table=pending_objects8622026/10/04 20:06:35 INFO Vacuumed table table=multipart_uploads8632026/10/04 20:06:35 INFO Vacuumed table table=closures8642026/10/04 20:06:35 INFO Vacuumed table table=objects8652026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=08662026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures8672026/10/04 20:06:35 WARN Force mode enabled - objects will be deleted immediately without grace period8682026/10/04 20:06:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=08692026/10/04 20:06:35 INFO Vacuumed table table=pending_closures8702026/10/04 20:06:35 INFO Vacuumed table table=pending_objects8712026/10/04 20:06:35 INFO Vacuumed table table=multipart_uploads8722026/10/04 20:06:35 INFO Vacuumed table table=closures8732026/10/04 20:06:35 INFO Vacuumed table table=objects874--- PASS: TestSweepSkipsRowsLockedByPush (0.40s)875=== CONT TestPresignedUploadRegisteredBeforeCommit8762026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures8772026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=08782026/10/04 20:06:35 WARN Force mode enabled - objects will be deleted immediately without grace period8792026/10/04 20:06:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=08802026/10/04 20:06:35 INFO Vacuumed table table=pending_closures8812026/10/04 20:06:35 INFO Vacuumed table table=pending_objects8822026/10/04 20:06:35 INFO Vacuumed table table=multipart_uploads8832026/10/04 20:06:35 INFO Vacuumed table table=closures8842026/10/04 20:06:35 INFO Vacuumed table table=objects8852026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=0886--- PASS: TestGCSweepDeliversEachKeyOnce (0.46s)887=== CONT TestLeadEndsOnShutdown8882026/10/04 20:06:35 WARN Force mode enabled - objects will be deleted immediately without grace period8892026/10/04 20:06:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08902026/10/04 20:06:35 INFO Vacuumed table table=pending_closures8912026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures8922026/10/04 20:06:35 INFO Vacuumed table table=pending_objects8932026/10/04 20:06:35 INFO Vacuumed table table=multipart_uploads8942026/10/04 20:06:35 INFO Vacuumed table table=closures8952026/10/04 20:06:35 INFO Vacuumed table table=objects896--- PASS: TestSweepRechecksPendingAfterLocking (0.41s)897=== CONT TestClientErrorHandling898=== RUN TestClientErrorHandling/InvalidStorePath899=== PAUSE TestClientErrorHandling/InvalidStorePath900=== RUN TestClientErrorHandling/InvalidAuthToken901=== PAUSE TestClientErrorHandling/InvalidAuthToken902=== RUN TestClientErrorHandling/ServerNotAvailable903=== PAUSE TestClientErrorHandling/ServerNotAvailable904=== CONT TestCompletedNarNotReofferedAcrossClosures9052026/10/04 20:06:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete906--- PASS: TestGetExistingObjectsLocksRows (0.49s)907=== CONT TestLeadElectsOneAndHandsOver9082026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures9092026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures910--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.46s)911=== CONT TestConnectWaitsForAPeerMigration9122026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=09132026/10/04 20:06:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09142026/10/04 20:06:35 INFO Vacuumed table table=pending_closures9152026/10/04 20:06:35 INFO Vacuumed table table=pending_objects9162026/10/04 20:06:35 INFO Vacuumed table table=multipart_uploads9172026/10/04 20:06:35 INFO Vacuumed table table=closures9182026/10/04 20:06:35 INFO Vacuumed table table=objects9192026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=09202026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures9212026/10/04 20:06:35 WARN Force mode enabled - objects will be deleted immediately without grace period9222026/10/04 20:06:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09232026/10/04 20:06:35 INFO Vacuumed table table=pending_closures9242026/10/04 20:06:35 INFO Vacuumed table table=pending_objects9252026/10/04 20:06:35 INFO Vacuumed table table=multipart_uploads9262026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=09272026/10/04 20:06:35 INFO Vacuumed table table=closures9282026/10/04 20:06:35 INFO Vacuumed table table=objects9292026/10/04 20:06:35 WARN Force mode enabled - objects will be deleted immediately without grace period930--- PASS: TestPushDedupSurvivesConcurrentGC (0.51s)931=== CONT TestCacheStatsHandler9322026/10/04 20:06:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09332026/10/04 20:06:35 INFO Vacuumed table table=pending_closures9342026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=09352026/10/04 20:06:35 INFO Vacuumed table table=pending_objects9362026/10/04 20:06:35 INFO Vacuumed table table=multipart_uploads9372026/10/04 20:06:35 INFO Vacuumed table table=closures9382026/10/04 20:06:35 INFO Vacuumed table table=objects9392026/10/04 20:06:35 WARN Force mode enabled - objects will be deleted immediately without grace period9402026/10/04 20:06:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09412026/10/04 20:06:35 INFO Vacuumed table table=pending_closures9422026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=0943--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.52s)944=== CONT TestResolveDBConnectionString945=== RUN TestResolveDBConnectionString/flag_wins946=== PAUSE TestResolveDBConnectionString/flag_wins947=== RUN TestResolveDBConnectionString/file_when_flag_empty948=== PAUSE TestResolveDBConnectionString/file_when_flag_empty949=== RUN TestResolveDBConnectionString/missing_file_is_an_error950=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error951=== RUN TestResolveDBConnectionString/PGHOST_allows_empty952=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty953=== RUN TestResolveDBConnectionString/nothing_configured954=== PAUSE TestResolveDBConnectionString/nothing_configured955=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9562026/10/04 20:06:35 INFO Vacuumed table table=pending_objects9572026/10/04 20:06:35 INFO Vacuumed table table=multipart_uploads9582026/10/04 20:06:35 INFO Vacuumed table table=closures9592026/10/04 20:06:35 WARN Force mode enabled - objects will be deleted immediately without grace period9602026/10/04 20:06:35 INFO Vacuumed table table=objects9612026/10/04 20:06:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09622026/10/04 20:06:35 INFO Vacuumed table table=pending_closures9632026/10/04 20:06:35 INFO Vacuumed table table=pending_objects9642026/10/04 20:06:35 INFO Vacuumed table table=multipart_uploads9652026/10/04 20:06:35 INFO Vacuumed table table=closures9662026/10/04 20:06:35 INFO Vacuumed table table=objects967--- PASS: TestGCSweepSkipsPendingObjects (0.53s)968=== CONT TestService_AuthMiddleware_OIDC969--- PASS: TestGCMetrics (0.54s)970=== CONT TestClientFallsBackToClosures9712026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures972--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.55s)973=== CONT TestCompleteMultipartUpload_ErrorButObjectExists9742026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures9752026/10/04 20:06:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9762026/10/04 20:06:35 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=M2E1MjI5MzYtY2M3Ni00NWM3LTkyMDMtYTM0ZGY2MGFjZTE4LjM2YTI4ZGI3LTZkOGEtNGYwYi1hZGIyLTg0OTY4ZTgwZjI3YXgxNzkxMTQ0Mzk1NTkwODU5MzU4 parts=109772026/10/04 20:06:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9782026/10/04 20:06:35 INFO Completed upload id=19792026/10/04 20:06:35 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000980--- PASS: TestReadProxyNarStreaming (0.58s)981=== CONT TestService_ReadScope_PublicByDefault9822026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures9832026/10/04 20:06:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38685/oidc9842026/10/04 20:06:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures9852026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=0986--- PASS: TestGCEndsOnShutdown (0.61s)987=== CONT TestClientPushesUseOnePush9882026/10/04 20:06:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09892026/10/04 20:06:35 INFO Vacuumed table table=pending_closures9902026/10/04 20:06:35 INFO Vacuumed table table=pending_objects9912026/10/04 20:06:35 INFO Vacuumed table table=multipart_uploads9922026/10/04 20:06:35 INFO Vacuumed table table=closures9932026/10/04 20:06:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9942026/10/04 20:06:35 INFO Vacuumed table table=objects9952026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures9962026/10/04 20:06:35 INFO Aborted multipart uploads count=0 kept=0997--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.64s)998=== CONT TestClientCADerivations9992026/10/04 20:06:35 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001000--- PASS: TestService_createPendingClosureHandler (0.72s)1001=== CONT TestService_RequireScope_OIDC10022026/10/04 20:06:35 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=M2E1MjI5MzYtY2M3Ni00NWM3LTkyMDMtYTM0ZGY2MGFjZTE4LjE3Nzc0NGE3LWE5YjAtNDMyOS1hNTdkLTIxYTY5ODc5ZjQxY3gxNzkxMTQ0Mzk1NjQ0NTEwMzUz parts=1010032026/10/04 20:06:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10042026/10/04 20:06:35 WARN Force mode enabled - objects will be deleted immediately without grace period10052026/10/04 20:06:35 INFO Completed upload id=110062026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures10072026/10/04 20:06:35 INFO Received uploads request method=POST path=/api/pending_closures10082026/10/04 20:06:35 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10092026/10/04 20:06:35 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."10102026/10/04 20:06:35 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10112026/10/04 20:06:35 WARN Found objects in DB but missing from S3, will re-upload count=11012--- PASS: TestService_verifyS3Integrity (0.73s)1013=== CONT TestPinProtectsFromGC1014--- PASS: TestFailedS3DeleteKeepsTombstone (0.66s)1015=== CONT TestRedundantMultipartUpload10162026/10/04 20:06:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33603/oidc1017--- PASS: TestService_Rustfstest (0.50s)1018=== CONT TestClientSharedPathCommittedMidPush1019=== NAME TestClientWithDependencies1020 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2742793180/001/store/fqk7fxgdla7h621z0rpw5vqxlvqis9y0-test-script1021=== NAME TestClientMultipleUploads1022 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4116670973/001/store/l6my0hfpg2h4hhnqyrmklcddqfscqlvl-test-file-0.txt10232026/10/04 20:06:36 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1024--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.52s)1025=== CONT TestPendingCleanupUsesOneCutoff1026=== NAME TestClientWithDependencies1027 client_integration_test.go:615: Found 1 dependencies (including self)1028=== NAME TestClientMultipleUploads1029 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4116670973/001/store/y9dcslwcsvkddg1bbdw8f67r9lqa8w47-test-file-1.txt10302026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures1031 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4116670973/001/store/mjmb4x4zjx4c8drq4qcqww2f3md7mm66-test-file-2.txt10322026/10/04 20:06:36 INFO lead: acquired remote=192.0.2.1:123410332026/10/04 20:06:36 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10342026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures1035=== NAME TestClientIntegration1036 client_integration_test.go:286: Created store path: /build/TestClientIntegration1604904113/002/store/abyg2w4kvm74xdfgj88q5avizp6ha7zj-test-file.txt1037--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.48s)1038=== CONT TestPush_SignsNarinfosOfItsPendingObjects10392026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures10402026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes10412026/10/04 20:06:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10422026/10/04 20:06:36 INFO Uploading fqk7fxgdla7h621z0rpw5vqxlvqis9y0-test-script (136B)10432026/10/04 20:06:36 INFO lead: acquired remote=192.0.2.1:123410442026/10/04 20:06:36 WARN Failed to register uploaded object key=log/2p9pbzgsfk4zg3n06ifdwiirhgs8mx63-test-script.drv error="server returned 404: 404 page not found\n"10452026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10462026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10472026/10/04 20:06:36 WARN Failed to register uploaded object key=fqk7fxgdla7h621z0rpw5vqxlvqis9y0.ls error="server returned 404: 404 page not found\n"10482026/10/04 20:06:36 INFO Signed narinfos id=1 count=110492026/10/04 20:06:36 INFO Uploading 1 narinfos10502026/10/04 20:06:36 INFO Received complete push request method=POST path=/api/pushes/1/complete10512026/10/04 20:06:36 WARN Failed to register uploaded object key=fqk7fxgdla7h621z0rpw5vqxlvqis9y0.narinfo error="server returned 404: 404 page not found\n"10522026/10/04 20:06:36 INFO Upload complete. (62ms)1053=== NAME TestClientWithDependencies1054 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2742793180/001/store) requires matching store prefix10552026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes1056--- PASS: TestClientWithDependencies (0.77s)1057=== CONT TestReadProxyNarinfoAlreadyDecompressed10582026/10/04 20:06:36 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10592026/10/04 20:06:36 INFO Uploading l6my0hfpg2h4hhnqyrmklcddqfscqlvl-test-file-0.txt (160B)10602026/10/04 20:06:36 INFO Uploading y9dcslwcsvkddg1bbdw8f67r9lqa8w47-test-file-1.txt (160B)10612026/10/04 20:06:36 INFO Uploading mjmb4x4zjx4c8drq4qcqww2f3md7mm66-test-file-2.txt (160B)10622026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10632026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10642026/10/04 20:06:36 WARN Failed to register uploaded object key=mjmb4x4zjx4c8drq4qcqww2f3md7mm66.ls error="server returned 404: 404 page not found\n"10652026/10/04 20:06:36 WARN Failed to register uploaded object key=y9dcslwcsvkddg1bbdw8f67r9lqa8w47.ls error="server returned 404: 404 page not found\n"10662026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10672026/10/04 20:06:36 WARN Failed to register uploaded object key=l6my0hfpg2h4hhnqyrmklcddqfscqlvl.ls error="server returned 404: 404 page not found\n"10682026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10692026/10/04 20:06:36 INFO Signed narinfos id=1 count=310702026/10/04 20:06:36 INFO Uploading 3 narinfos1071--- PASS: TestCacheStatsHandler (0.37s)1072=== CONT TestReadProxyDisabled10732026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes10742026/10/04 20:06:36 WARN Failed to register uploaded object key=mjmb4x4zjx4c8drq4qcqww2f3md7mm66.narinfo error="server returned 404: 404 page not found\n"10752026/10/04 20:06:36 WARN Failed to register uploaded object key=l6my0hfpg2h4hhnqyrmklcddqfscqlvl.narinfo error="server returned 404: 404 page not found\n"10762026/10/04 20:06:36 INFO Received complete push request method=POST path=/api/pushes/1/complete10772026/10/04 20:06:36 WARN Failed to register uploaded object key=y9dcslwcsvkddg1bbdw8f67r9lqa8w47.narinfo error="server returned 404: 404 page not found\n"10782026/10/04 20:06:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10792026/10/04 20:06:36 INFO Uploading abyg2w4kvm74xdfgj88q5avizp6ha7zj-test-file.txt (152B)10802026/10/04 20:06:36 INFO Upload complete. (58ms)1081=== NAME TestClientMultipleUploads1082 client_integration_test.go:369: Uploaded 3 paths in 92.629041ms10832026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"10842026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10852026/10/04 20:06:36 WARN Failed to register uploaded object key=abyg2w4kvm74xdfgj88q5avizp6ha7zj.ls error="server returned 404: 404 page not found\n"10862026/10/04 20:06:36 INFO Signed narinfos id=1 count=110872026/10/04 20:06:36 INFO Uploading 1 narinfos1088--- PASS: TestGCBugBareHashReferences (0.71s)1089=== CONT TestReadRedirectNar1090--- PASS: TestClientMultipleUploads (0.68s)1091=== CONT TestReadProxyRootRedirectsToIndexHTML10922026/10/04 20:06:36 INFO Received complete push request method=POST path=/api/pushes/1/complete10932026/10/04 20:06:36 WARN Failed to register uploaded object key=abyg2w4kvm74xdfgj88q5avizp6ha7zj.narinfo error="server returned 404: 404 page not found\n"10942026/10/04 20:06:36 INFO Upload complete. (64ms)10952026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures10962026/10/04 20:06:36 INFO All 1 paths already cached1097=== NAME TestClientIntegration1098 client_integration_test.go:312: Retrieved narinfo from S3:1099 StorePath: /build/TestClientIntegration1604904113/002/store/abyg2w4kvm74xdfgj88q5avizp6ha7zj-test-file.txt1100 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1101 Compression: zstd1102 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11103 NarSize: 1521104 References: 1105 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11106 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1107 client_integration_test.go:313: Decompressed .ls content (64 bytes):1108 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1109 client_integration_test.go:316: Testing garbage collection...1110--- PASS: TestService_ReadScope_PublicByDefault (0.37s)1111=== CONT TestNARDeduplicationMetadataUploadBug11122026/10/04 20:06:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11132026/10/04 20:06:36 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2E1MjI5MzYtY2M3Ni00NWM3LTkyMDMtYTM0ZGY2MGFjZTE4LmE2N2Q0OTU3LTA3OTMtNDg4NS1iYWRmLWQxM2Q5YmRmYjA1MngxNzkxMTQ0Mzk2Mjc0ODEwMTA11114=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1115=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1116=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1117=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1118=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1119=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1120=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1121=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1122=== CONT TestReadProxyNarinfo11232026/10/04 20:06:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2E1MjI5MzYtY2M3Ni00NWM3LTkyMDMtYTM0ZGY2MGFjZTE4LmE2N2Q0OTU3LTA3OTMtNDg4NS1iYWRmLWQxM2Q5YmRmYjA1MngxNzkxMTQ0Mzk2Mjc0ODEwMTA1 parts=11124--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.43s)1125=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11262026/10/04 20:06:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures11272026/10/04 20:06:36 INFO Garbage collection started11282026/10/04 20:06:36 INFO Aborted multipart uploads count=0 kept=011292026/10/04 20:06:36 WARN Force mode enabled - objects will be deleted immediately without grace period11302026/10/04 20:06:36 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=011312026/10/04 20:06:36 INFO Vacuumed table table=pending_closures11322026/10/04 20:06:36 INFO Vacuumed table table=pending_objects11332026/10/04 20:06:36 INFO Vacuumed table table=multipart_uploads11342026/10/04 20:06:36 INFO Vacuumed table table=closures11352026/10/04 20:06:36 INFO Vacuumed table table=objects11362026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures11372026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures11382026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures11392026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures11402026/10/04 20:06:36 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11412026/10/04 20:06:36 INFO Uploading k58hfsmq2mjcyln9a2950h8nxk17f6dk-b (216B)11422026/10/04 20:06:36 INFO Uploading fh3dzjjgmn87vgp01wvbid1g0aahs623-shared-dep (136B)1143=== RUN TestService_RequireScope_OIDC/builder_may_write1144=== PAUSE TestService_RequireScope_OIDC/builder_may_write1145=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1146=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1147=== RUN TestService_RequireScope_OIDC/ops_may_admin1148=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1149=== RUN TestService_RequireScope_OIDC/ops_may_not_write1150=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1151=== RUN TestService_RequireScope_OIDC/reader_may_not_write1152=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1153=== RUN TestService_RequireScope_OIDC/static_token_may_admin1154=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin11552026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1156=== RUN TestService_RequireScope_OIDC/static_token_may_write1157=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1158=== RUN TestService_RequireScope_OIDC/reader_may_read1159=== PAUSE TestService_RequireScope_OIDC/reader_may_read1160=== RUN TestService_RequireScope_OIDC/writer_implies_read11612026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/028agd4y19myghvjdwwziccsspb4j5vy757vpxhdi7gzizvzddxm.nar.zst error="server returned 404: 404 page not found\n"1162=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1163=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1164=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1165=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1166=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1167=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc11682026/10/04 20:06:36 WARN Failed to register uploaded object key=fh3dzjjgmn87vgp01wvbid1g0aahs623.ls error="server returned 404: 404 page not found\n"1169=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc11702026/10/04 20:06:36 WARN Failed to register uploaded object key=g8sqga9sz2320gqv4pp2w82khl04lxcg.ls error="server returned 404: 404 page not found\n"1171=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1172=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1173=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1174=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1175=== CONT TestReadProxyConditionalGet1176=== NAME TestClientCADerivations11772026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1178 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1823558406/001/store/pwxv5gpba2xmlm544isb5pg3wb0bzfnw-ca-test11792026/10/04 20:06:36 WARN Failed to register uploaded object key=k58hfsmq2mjcyln9a2950h8nxk17f6dk.ls error="server returned 404: 404 page not found\n"11802026/10/04 20:06:36 INFO Signed narinfos id=1 count=211812026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11822026/10/04 20:06:36 INFO Signed narinfos id=2 count=211832026/10/04 20:06:36 INFO Uploading 4 narinfos11842026/10/04 20:06:36 WARN Failed to register uploaded object key=k58hfsmq2mjcyln9a2950h8nxk17f6dk.narinfo error="server returned 404: 404 page not found\n"11852026/10/04 20:06:36 WARN Failed to register uploaded object key=fh3dzjjgmn87vgp01wvbid1g0aahs623.narinfo error="server returned 404: 404 page not found\n"11862026/10/04 20:06:36 WARN Failed to register uploaded object key=g8sqga9sz2320gqv4pp2w82khl04lxcg.narinfo error="server returned 404: 404 page not found\n"11872026/10/04 20:06:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11882026/10/04 20:06:36 WARN Failed to register uploaded object key=fh3dzjjgmn87vgp01wvbid1g0aahs623.narinfo error="server returned 404: 404 page not found\n"1189=== NAME TestPinProtectsFromGC1190 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC574857350/001/store/h5pwhcw74qcci8dn8ajd2wmdxfgw55w9-pinned-file.txt1191 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC574857350/001/store/28npppm98myha4p9882axbzh5jj3w4v1-unpinned-file.txt11922026/10/04 20:06:36 INFO Completed upload id=111932026/10/04 20:06:36 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11942026/10/04 20:06:36 INFO Completed upload id=211952026/10/04 20:06:36 INFO Upload complete. (70ms)1196--- PASS: TestPushWaitsForSweepHoldingRow (1.06s)1197=== CONT TestMultipartCleanup1198=== NAME TestClientFallsBackToClosures1199 client_pushes_test.go:112: Retrieved narinfo from S3:1200 StorePath: /build/TestClientFallsBackToClosures2234279930/001/store/fh3dzjjgmn87vgp01wvbid1g0aahs623-shared-dep1201 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1202 Compression: zstd1203 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821204 NarSize: 1361205 References: 1206 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1207 client_pushes_test.go:112: Retrieved narinfo from S3:1208 StorePath: /build/TestClientFallsBackToClosures2234279930/001/store/g8sqga9sz2320gqv4pp2w82khl04lxcg-a1209 URL: nar/028agd4y19myghvjdwwziccsspb4j5vy757vpxhdi7gzizvzddxm.nar.zst1210 Compression: zstd1211 NarHash: sha256:028agd4y19myghvjdwwziccsspb4j5vy757vpxhdi7gzizvzddxm1212 NarSize: 2161213 References: /build/TestClientFallsBackToClosures2234279930/001/store/fh3dzjjgmn87vgp01wvbid1g0aahs623-shared-dep1214 CA: text:sha256:1574ashh3wzlvgzd1brijmvxc4ifx61zn3h7vpc02h2ygzypl44q12152026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures1216 client_pushes_test.go:112: Retrieved narinfo from S3:1217 StorePath: /build/TestClientFallsBackToClosures2234279930/001/store/k58hfsmq2mjcyln9a2950h8nxk17f6dk-b1218 URL: nar/028agd4y19myghvjdwwziccsspb4j5vy757vpxhdi7gzizvzddxm.nar.zst1219 Compression: zstd1220 NarHash: sha256:028agd4y19myghvjdwwziccsspb4j5vy757vpxhdi7gzizvzddxm1221 NarSize: 2161222 References: /build/TestClientFallsBackToClosures2234279930/001/store/fh3dzjjgmn87vgp01wvbid1g0aahs623-shared-dep1223 CA: text:sha256:1574ashh3wzlvgzd1brijmvxc4ifx61zn3h7vpc02h2ygzypl44q1224--- PASS: TestClientFallsBackToClosures (0.60s)1225=== CONT TestReadProxyOutlastsServerWriteTimeout12262026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures1227=== NAME TestClientCADerivations1228 client_ca_test.go:139: Found 1 dependencies (including self)12292026/10/04 20:06:36 INFO Received cleanup request method=DELETE path=/api/pending_closures12302026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes12312026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12322026/10/04 20:06:36 INFO Signed narinfos id=1 count=11233--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.37s)1234=== CONT TestServerTLSConfig1235=== RUN TestServerTLSConfig/no_client_CA1236=== PAUSE TestServerTLSConfig/no_client_CA1237=== RUN TestServerTLSConfig/missing_CA_file1238=== PAUSE TestServerTLSConfig/missing_CA_file1239=== RUN TestServerTLSConfig/not_a_PEM_file1240=== PAUSE TestServerTLSConfig/not_a_PEM_file1241=== CONT TestIsValidCachePath1242=== RUN TestIsValidCachePath/narinfo1243=== PAUSE TestIsValidCachePath/narinfo1244=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1245=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1246=== RUN TestIsValidCachePath/nar_zst1247=== PAUSE TestIsValidCachePath/nar_zst1248=== RUN TestIsValidCachePath/nar_xz1249=== PAUSE TestIsValidCachePath/nar_xz1250=== RUN TestIsValidCachePath/nar_bz21251=== PAUSE TestIsValidCachePath/nar_bz21252=== RUN TestIsValidCachePath/nar_uncompressed1253=== PAUSE TestIsValidCachePath/nar_uncompressed1254=== RUN TestIsValidCachePath/ls1255=== PAUSE TestIsValidCachePath/ls1256=== RUN TestIsValidCachePath/log1257=== PAUSE TestIsValidCachePath/log1258=== RUN TestIsValidCachePath/realisation1259=== PAUSE TestIsValidCachePath/realisation1260=== RUN TestIsValidCachePath/nix-cache-info1261=== PAUSE TestIsValidCachePath/nix-cache-info1262=== RUN TestIsValidCachePath/index.html1263=== PAUSE TestIsValidCachePath/index.html1264=== RUN TestIsValidCachePath/traversal_parent1265=== PAUSE TestIsValidCachePath/traversal_parent1266=== RUN TestIsValidCachePath/traversal_in_middle1267=== PAUSE TestIsValidCachePath/traversal_in_middle1268=== RUN TestIsValidCachePath/invalid_char_e1269=== PAUSE TestIsValidCachePath/invalid_char_e1270=== RUN TestIsValidCachePath/invalid_char_u1271=== PAUSE TestIsValidCachePath/invalid_char_u1272=== RUN TestIsValidCachePath/random_path1273=== PAUSE TestIsValidCachePath/random_path1274=== RUN TestIsValidCachePath/empty1275=== PAUSE TestIsValidCachePath/empty1276=== RUN TestIsValidCachePath/leading_slash1277=== PAUSE TestIsValidCachePath/leading_slash1278=== RUN TestIsValidCachePath/wrong_extension1279=== PAUSE TestIsValidCachePath/wrong_extension1280=== RUN TestIsValidCachePath/short_hash1281=== PAUSE TestIsValidCachePath/short_hash1282=== CONT TestService_NativeMTLS1283--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.32s)1284=== CONT TestReadProxyHead12852026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes12862026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes12872026/10/04 20:06:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12882026/10/04 20:06:36 INFO Uploading h5pwhcw74qcci8dn8ajd2wmdxfgw55w9-pinned-file.txt (128B)12892026/10/04 20:06:36 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12902026/10/04 20:06:36 INFO Uploading k8vbxsw2bxzs1276dcnkq6lqdkf2gsxv-shared-dep (136B)12912026/10/04 20:06:36 INFO Uploading nf97zfch1vzjvmia0wi1yb610l7df7sw-a (216B)12922026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12932026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12942026/10/04 20:06:36 WARN Failed to register uploaded object key=h5pwhcw74qcci8dn8ajd2wmdxfgw55w9.ls error="server returned 404: 404 page not found\n"12952026/10/04 20:06:36 INFO Signed narinfos id=1 count=112962026/10/04 20:06:36 INFO Uploading 1 narinfos1297--- PASS: TestReadProxyDisabled (0.32s)1298=== CONT TestProxyHeadersOnlyTrustedOnSocket12992026/10/04 20:06:36 WARN Failed to register uploaded object key=k8vbxsw2bxzs1276dcnkq6lqdkf2gsxv.ls error="server returned 404: 404 page not found\n"13002026/10/04 20:06:36 WARN Failed to register uploaded object key=i92c5dhgs2z9d1vv6x4ric47fa61r092.ls error="server returned 404: 404 page not found\n"13012026/10/04 20:06:36 WARN Failed to register uploaded object key=nf97zfch1vzjvmia0wi1yb610l7df7sw.ls error="server returned 404: 404 page not found\n"13022026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/1viacrf4gyrycyal072fn7rixrzpwcdx18vhcqh5kx3k2ia1xf38.nar.zst error="server returned 404: 404 page not found\n"13032026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13042026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13052026/10/04 20:06:36 INFO Signed narinfos id=1 count=313062026/10/04 20:06:36 INFO Uploading 3 narinfos13072026/10/04 20:06:36 INFO Received complete push request method=POST path=/api/pushes/1/complete13082026/10/04 20:06:36 WARN Failed to register uploaded object key=h5pwhcw74qcci8dn8ajd2wmdxfgw55w9.narinfo error="server returned 404: 404 page not found\n"13092026/10/04 20:06:36 WARN Failed to register uploaded object key=k8vbxsw2bxzs1276dcnkq6lqdkf2gsxv.narinfo error="server returned 404: 404 page not found\n"13102026/10/04 20:06:36 WARN Failed to register uploaded object key=i92c5dhgs2z9d1vv6x4ric47fa61r092.narinfo error="server returned 404: 404 page not found\n"13112026/10/04 20:06:36 INFO Received complete push request method=POST path=/api/pushes/1/complete13122026/10/04 20:06:36 WARN Failed to register uploaded object key=nf97zfch1vzjvmia0wi1yb610l7df7sw.narinfo error="server returned 404: 404 page not found\n"13132026/10/04 20:06:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13142026/10/04 20:06:36 INFO Upload complete. (60ms)13152026/10/04 20:06:36 INFO Upload complete. (57ms)1316=== NAME TestClientPushesUseOnePush1317 client_pushes_test.go:97: Retrieved narinfo from S3:1318 StorePath: /build/TestClientPushesUseOnePush1078744474/001/store/k8vbxsw2bxzs1276dcnkq6lqdkf2gsxv-shared-dep1319 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1320 Compression: zstd1321 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821322 NarSize: 1361323 References: 1324 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1325 client_pushes_test.go:97: Retrieved narinfo from S3:1326 StorePath: /build/TestClientPushesUseOnePush1078744474/001/store/nf97zfch1vzjvmia0wi1yb610l7df7sw-a1327 URL: nar/1viacrf4gyrycyal072fn7rixrzpwcdx18vhcqh5kx3k2ia1xf38.nar.zst1328 Compression: zstd1329 NarHash: sha256:1viacrf4gyrycyal072fn7rixrzpwcdx18vhcqh5kx3k2ia1xf381330 NarSize: 2161331 References: /build/TestClientPushesUseOnePush1078744474/001/store/k8vbxsw2bxzs1276dcnkq6lqdkf2gsxv-shared-dep1332 CA: text:sha256:0rq9fw088q5hhryw351jzxjn8jhwncsbm0gn05vgwz8g3jnn8jh11333 client_pushes_test.go:97: Retrieved narinfo from S3:1334 StorePath: /build/TestClientPushesUseOnePush1078744474/001/store/i92c5dhgs2z9d1vv6x4ric47fa61r092-b1335 URL: nar/1viacrf4gyrycyal072fn7rixrzpwcdx18vhcqh5kx3k2ia1xf38.nar.zst1336 Compression: zstd1337 NarHash: sha256:1viacrf4gyrycyal072fn7rixrzpwcdx18vhcqh5kx3k2ia1xf381338 NarSize: 2161339 References: /build/TestClientPushesUseOnePush1078744474/001/store/k8vbxsw2bxzs1276dcnkq6lqdkf2gsxv-shared-dep1340 CA: text:sha256:0rq9fw088q5hhryw351jzxjn8jhwncsbm0gn05vgwz8g3jnn8jh113412026/10/04 20:06:36 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=M2E1MjI5MzYtY2M3Ni00NWM3LTkyMDMtYTM0ZGY2MGFjZTE4LmM0OTZiOWQyLWI0MmQtNDJjZC1iN2FhLTQxYjMwZWEzYjExNHgxNzkxMTQ0Mzk2MTY0NTYwMTg3 parts=1213422026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures1343--- PASS: TestClientPushesUseOnePush (0.62s)1344=== CONT TestReadProxyInvalidPath1345--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.33s)1346=== CONT TestParseSingleRange1347=== RUN TestParseSingleRange/none1348=== PAUSE TestParseSingleRange/none1349=== RUN TestParseSingleRange/unknown_unit1350=== PAUSE TestParseSingleRange/unknown_unit1351=== RUN TestParseSingleRange/multi-range_ignored1352=== PAUSE TestParseSingleRange/multi-range_ignored1353=== RUN TestParseSingleRange/malformed_no_dash1354=== PAUSE TestParseSingleRange/malformed_no_dash1355=== RUN TestParseSingleRange/malformed_both_empty1356=== PAUSE TestParseSingleRange/malformed_both_empty1357=== RUN TestParseSingleRange/malformed_end_before_start1358=== PAUSE TestParseSingleRange/malformed_end_before_start1359=== RUN TestParseSingleRange/closed1360=== PAUSE TestParseSingleRange/closed1361=== RUN TestParseSingleRange/open-ended1362=== PAUSE TestParseSingleRange/open-ended1363=== RUN TestParseSingleRange/end_clamped_to_size1364=== PAUSE TestParseSingleRange/end_clamped_to_size1365=== RUN TestParseSingleRange/suffix1366=== PAUSE TestParseSingleRange/suffix1367=== RUN TestParseSingleRange/suffix_exceeds_size1368=== PAUSE TestParseSingleRange/suffix_exceeds_size1369=== RUN TestParseSingleRange/single_byte1370=== PAUSE TestParseSingleRange/single_byte1371=== RUN TestParseSingleRange/start_past_EOF1372=== PAUSE TestParseSingleRange/start_past_EOF1373=== RUN TestParseSingleRange/start_far_past_EOF1374=== PAUSE TestParseSingleRange/start_far_past_EOF1375=== CONT TestReadProxy4041376--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.82s)1377=== CONT TestPresentNotReportedWhileGCDeletesClosure1378--- PASS: TestReadRedirectNar (0.36s)1379=== CONT TestMetricsInventory13802026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes13812026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes13822026/10/04 20:06:36 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13832026/10/04 20:06:36 INFO Uploading x67xy8w84v981m4bk44qihzqbrrm092s-shared-dep (136B)13842026/10/04 20:06:36 INFO Uploading xdmmmc6d4ri3fp6zz0gam8lxhh5v3mkw-top (224B)13852026/10/04 20:06:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13862026/10/04 20:06:36 INFO Uploading pwxv5gpba2xmlm544isb5pg3wb0bzfnw-ca-test (144B)13872026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13882026/10/04 20:06:36 WARN Failed to register uploaded object key=xdmmmc6d4ri3fp6zz0gam8lxhh5v3mkw.ls error="server returned 404: 404 page not found\n"13892026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/0g9rr9878l14xq5sjv8kqb76cd6g3w45ndkyn4zsrkr8i2qhibd4.nar.zst error="server returned 404: 404 page not found\n"13902026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13912026/10/04 20:06:36 WARN Failed to register uploaded object key=x67xy8w84v981m4bk44qihzqbrrm092s.ls error="server returned 404: 404 page not found\n"13922026/10/04 20:06:36 INFO Signed narinfos id=1 count=213932026/10/04 20:06:36 WARN Failed to register uploaded object key=pwxv5gpba2xmlm544isb5pg3wb0bzfnw.ls error="server returned 404: 404 page not found\n"13942026/10/04 20:06:36 INFO Uploading 2 narinfos13952026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13962026/10/04 20:06:36 WARN Failed to register uploaded object key=log/x5ai3hjdq8n2lmfnp055jkb9r68kr4l4-ca-test.drv error="server returned 404: 404 page not found\n"13972026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13982026/10/04 20:06:36 INFO Signed narinfos id=1 count=113992026/10/04 20:06:36 INFO Uploading 1 narinfos14002026/10/04 20:06:36 WARN Failed to register uploaded object key=xdmmmc6d4ri3fp6zz0gam8lxhh5v3mkw.narinfo error="server returned 404: 404 page not found\n"14012026/10/04 20:06:36 INFO Received complete push request method=POST path=/api/pushes/1/complete14022026/10/04 20:06:36 WARN Failed to register uploaded object key=x67xy8w84v981m4bk44qihzqbrrm092s.narinfo error="server returned 404: 404 page not found\n"14032026/10/04 20:06:36 INFO Received complete push request method=POST path=/api/pushes/1/complete14042026/10/04 20:06:36 WARN Failed to register uploaded object key=pwxv5gpba2xmlm544isb5pg3wb0bzfnw.narinfo error="server returned 404: 404 page not found\n"14052026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes14062026/10/04 20:06:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14072026/10/04 20:06:36 INFO Uploading 28npppm98myha4p9882axbzh5jj3w4v1-unpinned-file.txt (128B)14082026/10/04 20:06:36 INFO Upload complete. (96ms)14092026/10/04 20:06:36 INFO Upload complete. (58ms)1410=== NAME TestClientSharedPathCommittedMidPush1411 client_integration_test.go:680: Retrieved narinfo from S3:1412 StorePath: /build/TestClientSharedPathCommittedMidPush3314828255/001/store/x67xy8w84v981m4bk44qihzqbrrm092s-shared-dep1413 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1414 Compression: zstd1415 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821416 NarSize: 1361417 References: 1418 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1419=== NAME TestClientCADerivations1420 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1823558406/001/store/pwxv5gpba2xmlm544isb5pg3wb0bzfnw-ca-test1421 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1422 Compression: zstd1423 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1424 NarSize: 1441425 References: 1426 Deriver: /build/TestClientCADerivations1823558406/001/store/x5ai3hjdq8n2lmfnp055jkb9r68kr4l4-ca-test.drv1427 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1428 client_ca_test.go:185: Checking for realisation files in S3...14292026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14302026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14312026/10/04 20:06:36 WARN Failed to register uploaded object key=28npppm98myha4p9882axbzh5jj3w4v1.ls error="server returned 404: 404 page not found\n"14322026/10/04 20:06:36 INFO Signed narinfos id=2 count=114332026/10/04 20:06:36 INFO Uploading 1 narinfos1434=== NAME TestClientSharedPathCommittedMidPush1435 client_integration_test.go:680: Retrieved narinfo from S3:1436 StorePath: /build/TestClientSharedPathCommittedMidPush3314828255/001/store/xdmmmc6d4ri3fp6zz0gam8lxhh5v3mkw-top1437 URL: nar/0g9rr9878l14xq5sjv8kqb76cd6g3w45ndkyn4zsrkr8i2qhibd4.nar.zst1438 Compression: zstd1439 NarHash: sha256:0g9rr9878l14xq5sjv8kqb76cd6g3w45ndkyn4zsrkr8i2qhibd41440 NarSize: 2241441 References: /build/TestClientSharedPathCommittedMidPush3314828255/001/store/x67xy8w84v981m4bk44qihzqbrrm092s-shared-dep1442 CA: text:sha256:15jdkzcl61gqcg7biia9xl6y5hc99lnsxbs4gzzcfbkgxmdjmiay1443=== NAME TestClientCADerivations1444 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1445 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14462026/10/04 20:06:36 INFO Received complete push request method=POST path=/api/pushes/2/complete14472026/10/04 20:06:36 WARN Failed to register uploaded object key=28npppm98myha4p9882axbzh5jj3w4v1.narinfo error="server returned 404: 404 page not found\n"1448--- PASS: TestClientSharedPathCommittedMidPush (0.57s)1449=== CONT TestGenerateLandingPage1450--- PASS: TestGenerateLandingPage (0.00s)1451=== CONT TestService_readinessHandler14522026/10/04 20:06:36 INFO Upload complete. (50ms)1453--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.78s)1454=== CONT TestPresentReportsOnlyClosureRoots1455=== NAME TestNARDeduplicationMetadataUploadBug1456 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1015636170/001/store/28bc81p0fl15qsmy9lcn90b3py9gq5b7-file1.txt14572026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures14582026/10/04 20:06:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures14592026/10/04 20:06:36 INFO Garbage collection started1460--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.35s)1461=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14622026/10/04 20:06:36 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"14632026/10/04 20:06:36 INFO Aborted multipart uploads count=0 kept=014642026/10/04 20:06:36 WARN Force mode enabled - objects will be deleted immediately without grace period1465--- PASS: TestReadProxyConditionalGet (0.24s)1466=== CONT TestCreatePin_ReservedPins14672026/10/04 20:06:36 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=014682026/10/04 20:06:36 INFO Vacuumed table table=pending_closures14692026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures14702026/10/04 20:06:36 INFO Vacuumed table table=pending_objects14712026/10/04 20:06:36 INFO Vacuumed table table=multipart_uploads14722026/10/04 20:06:36 INFO Vacuumed table table=closures14732026/10/04 20:06:36 INFO Vacuumed table table=objects1474=== NAME TestClientCADerivations1475 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1476 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1477 error: binary cache 's3://bucket43?endpoint=http://localhost:41013&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1823558406/001/store'1478 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11479--- PASS: TestClientCADerivations (0.74s)1480=== CONT TestService_ReadAuthMiddleware14812026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes14822026/10/04 20:06:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14832026/10/04 20:06:36 INFO Uploading 28bc81p0fl15qsmy9lcn90b3py9gq5b7-file1.txt (160B)14842026/10/04 20:06:36 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14852026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14862026/10/04 20:06:36 WARN Failed to register uploaded object key=28bc81p0fl15qsmy9lcn90b3py9gq5b7.ls error="server returned 404: 404 page not found\n"14872026/10/04 20:06:36 INFO Signed narinfos id=1 count=114882026/10/04 20:06:36 INFO Uploading 1 narinfos14892026/10/04 20:06:36 INFO Received complete push request method=POST path=/api/pushes/1/complete14902026/10/04 20:06:36 WARN Failed to register uploaded object key=28bc81p0fl15qsmy9lcn90b3py9gq5b7.narinfo error="server returned 404: 404 page not found\n"14912026/10/04 20:06:36 INFO Upload complete. (55ms)1492=== NAME TestNARDeduplicationMetadataUploadBug1493 metadata_upload_test.go:54: Retrieved narinfo from S3:1494 StorePath: /build/TestNARDeduplicationMetadataUploadBug1015636170/001/store/28bc81p0fl15qsmy9lcn90b3py9gq5b7-file1.txt1495 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1496 Compression: zstd1497 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1498 NarSize: 1601499 References: 1500 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15012026/10/04 20:06:36 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15022026/10/04 20:06:36 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1503--- PASS: TestService_NativeMTLS (0.24s)1504=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1505=== NAME TestNARDeduplicationMetadataUploadBug1506 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1507 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1508 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1509--- PASS: TestReadProxyHead (0.26s)1510=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1511=== NAME TestNARDeduplicationMetadataUploadBug1512 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1015636170/001/store/9cpgmnvxfr5c7fw3643f6i2qzxraijnc-file2.txt15132026/10/04 20:06:36 INFO Starting HTTP server address=127.0.0.1:4640315142026/10/04 20:06:36 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2176816275/001/proxy.sock15152026/10/04 20:06:36 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15162026/10/04 20:06:36 INFO Shutdown signal received, draining in-flight requests timeout=10s1517--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.26s)1518=== CONT TestPush_CompleteCommitsEveryRoot15192026/10/04 20:06:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15202026/10/04 20:06:36 INFO Received cleanup request method=DELETE path=/api/pending_closures15212026/10/04 20:06:36 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket58/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15222026/10/04 20:06:36 INFO Aborted multipart uploads count=0 kept=115232026/10/04 20:06:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=M2E1MjI5MzYtY2M3Ni00NWM3LTkyMDMtYTM0ZGY2MGFjZTE4LmJmZWNjZDlmLWM4ZGQtNDQ3NS1iZWFiLTcwZWUwNWE1ZTNkMngxNzkxMTQ0Mzk2NDAyNzU2NzE5 parts=1215242026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures15252026/10/04 20:06:36 INFO Received cleanup request method=DELETE path=/api/pending_closures15262026/10/04 20:06:36 INFO Aborted multipart uploads count=1 kept=015272026/10/04 20:06:36 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161528--- PASS: TestReadProxyNarinfo (0.52s)1529=== CONT TestOrphanedObjectsGCStressTest15302026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures1531--- PASS: TestMultipartCleanup (0.37s)1532=== CONT TestOrphanedObjectsGC1533--- PASS: TestReadProxyInvalidPath (0.28s)1534=== CONT TestObjectStatsTrigger15352026/10/04 20:06:36 INFO Received push request method=POST path=/api/pushes15362026/10/04 20:06:36 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15372026/10/04 20:06:36 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15382026/10/04 20:06:36 INFO Signed narinfos id=2 count=115392026/10/04 20:06:36 WARN Failed to register uploaded object key=9cpgmnvxfr5c7fw3643f6i2qzxraijnc.ls error="server returned 404: 404 page not found\n"15402026/10/04 20:06:36 INFO Uploading 1 narinfos15412026/10/04 20:06:36 INFO Received complete push request method=POST path=/api/pushes/2/complete15422026/10/04 20:06:36 WARN Failed to register uploaded object key=9cpgmnvxfr5c7fw3643f6i2qzxraijnc.narinfo error="server returned 404: 404 page not found\n"15432026/10/04 20:06:36 INFO Upload complete. (74ms)1544=== NAME TestNARDeduplicationMetadataUploadBug1545 metadata_upload_test.go:76: Retrieved narinfo from S3:1546 StorePath: /build/TestNARDeduplicationMetadataUploadBug1015636170/001/store/9cpgmnvxfr5c7fw3643f6i2qzxraijnc-file2.txt1547 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1548 Compression: zstd1549 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1550 NarSize: 1601551 References: 1552 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1553 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1554 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1555 {"version":1,"root":{"type":"regular","size":44}}1556--- PASS: TestNARDeduplicationMetadataUploadBug (0.62s)1557=== CONT TestCacheConfigHandlerMaxNarSize1558--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1559=== CONT TestService_AuthMiddleware_MTLSProxyHeader1560--- PASS: TestReadProxy404 (0.35s)1561=== CONT TestPush_RejectsBadRequests1562--- PASS: TestMetricsInventory (0.33s)1563=== CONT TestReadProxyRangeRequest15642026/10/04 20:06:36 WARN readiness check failed error="closed pool"1565--- PASS: TestService_readinessHandler (0.31s)1566=== CONT TestService_healthCheckHandler15672026/10/04 20:06:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35805/oidc1568--- PASS: TestPresentReportsOnlyClosureRoots (0.34s)1569=== CONT TestReadRedirectKeepsNarinfoProxied15702026/10/04 20:06:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15712026/10/04 20:06:36 WARN mTLS auth: bound subjects configured but subject DN unavailable15722026/10/04 20:06:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1573--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)1574=== CONT TestCreatePendingClosureRejectsOversizedNAR15752026/10/04 20:06:36 INFO Received uploads request method=POST path=/api/pending_closures1576--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1577=== CONT TestReadRedirectUsesPublicS3URL1578--- PASS: TestService_ReadAuthMiddleware (0.30s)1579=== CONT TestPendingClosureWriteTimeout/empty1580=== CONT TestPendingClosureWriteTimeout/670k_objects1581=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15822026/10/04 20:06:37 INFO Received push request method=POST path=/api/pushes1583--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.31s)1584=== CONT TestPendingClosureWriteTimeout/400_objects1585=== CONT TestProxyWriteTimeout/narinfo1586=== CONT TestProxyWriteTimeout/10_GiB_nar1587=== CONT TestProxyWriteTimeout/unknown_size1588=== CONT TestProxyWriteTimeout/1_GiB_nar1589--- PASS: TestProxyWriteTimeout (0.08s)1590 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1591 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1592 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1593 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1594=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows15952026/10/04 20:06:37 INFO Received push request method=POST path=/api/pushes15962026/10/04 20:06:37 INFO Received complete push request method=POST path=/api/pushes/1/complete15972026/10/04 20:06:37 INFO Received push request method=POST path=/api/pushes15982026/10/04 20:06:37 INFO Received push request method=POST path=/api/pushes15992026/10/04 20:06:37 INFO Received complete push request method=POST path=/api/pushes/1/complete1600--- PASS: TestPush_CompleteCommitsEveryRoot (0.32s)1601=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16022026/10/04 20:06:37 INFO Aborted multipart uploads count=0 kept=016032026/10/04 20:06:37 WARN Force mode enabled - objects will be deleted immediately without grace period16042026/10/04 20:06:37 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=016052026/10/04 20:06:37 INFO Vacuumed table table=pending_closures16062026/10/04 20:06:37 INFO Vacuumed table table=pending_objects1607--- PASS: TestObjectStatsTrigger (0.33s)1608=== CONT TestIsValidUploadKey/narinfo1609=== CONT TestIsValidUploadKey/realisation_plus_in_output1610=== CONT TestIsValidUploadKey/unknown_type1611=== CONT TestIsValidUploadKey/empty_key1612=== CONT TestIsValidUploadKey/absolute1613=== CONT TestIsValidUploadKey/traversal_nar1614=== CONT TestIsValidUploadKey/traversal1615=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1616=== CONT TestIsValidUploadKey/index.html1617=== CONT TestIsValidUploadKey/nix-cache-info1618=== CONT TestIsValidUploadKey/build_log_home-manager_file1619=== CONT TestIsValidUploadKey/realisation1620=== CONT TestIsValidUploadKey/build_log_equals1621=== CONT TestIsValidUploadKey/build_log_question_mark1622=== CONT TestIsValidUploadKey/build_log_plus_in_name1623=== CONT TestIsValidUploadKey/nar_plain1624=== CONT TestIsValidUploadKey/build_log1625=== CONT TestIsValidUploadKey/listing1626=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1627=== CONT TestIsValidUploadKey/nar_xz1628=== CONT TestIsValidUploadKey/nar_zst1629=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1630--- PASS: TestIsValidUploadKey (0.08s)1631 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1632 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1633 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1634 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1635 --- PASS: TestIsValidUploadKey/absolute (0.00s)1636 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1637 --- PASS: TestIsValidUploadKey/traversal (0.00s)1638 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1639 --- PASS: TestIsValidUploadKey/index.html (0.00s)1640 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1641 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1642 --- PASS: TestIsValidUploadKey/realisation (0.00s)1643 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1644 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1645 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1646 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1647 --- PASS: TestIsValidUploadKey/build_log (0.00s)1648 --- PASS: TestIsValidUploadKey/listing (0.00s)1649 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1650 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1651 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1652 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1653=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16542026/10/04 20:06:37 INFO Received uploads request method=POST path=/1655=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16562026/10/04 20:06:37 INFO Received complete multipart upload request method=POST path=/1657=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16582026/10/04 20:06:37 INFO Received request for more parts method=POST path=/1659=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16602026/10/04 20:06:37 INFO Received uploads request method=POST path=/1661=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16622026/10/04 20:06:37 INFO Vacuumed table table=multipart_uploads16632026/10/04 20:06:37 INFO Received uploads request method=POST path=/1664--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1665 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1666 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1667 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1668 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)16692026/10/04 20:06:37 INFO Vacuumed table table=closures16702026/10/04 20:06:37 INFO Vacuumed table table=objects16712026/10/04 20:06:37 INFO Received complete push request method=POST path=/api/pushes/2/complete1672--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.27s)1673=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16742026/10/04 20:06:37 INFO Received request for more parts method=POST path=/1675--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.40s)1676=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16772026/10/04 20:06:37 INFO Received complete multipart upload request method=POST path=/16782026/10/04 20:06:37 INFO lead: released remote=192.0.2.1:12341679--- PASS: TestLeadEndsOnShutdown (1.47s)1680=== CONT TestCacheConfigHandler/full_config,_no_issuer1681=== CONT TestCacheConfigHandler/no_signing_keys1682=== CONT TestCacheConfigHandler/no_cache_url_configured1683=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1684--- PASS: TestCacheConfigHandler (0.00s)1685 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1686 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1687 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1688 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1689=== CONT TestClientErrorHandling/InvalidStorePath1690=== RUN TestPush_RejectsBadRequests/bad_root1691=== PAUSE TestPush_RejectsBadRequests/bad_root1692=== RUN TestPush_RejectsBadRequests/root_not_in_objects1693=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1694=== RUN TestPush_RejectsBadRequests/no_roots1695=== PAUSE TestPush_RejectsBadRequests/no_roots1696=== RUN TestPush_RejectsBadRequests/no_objects1697=== PAUSE TestPush_RejectsBadRequests/no_objects1698=== CONT TestClientErrorHandling/ServerNotAvailable16992026/10/04 20:06:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17002026/10/04 20:06:37 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=M2E1MjI5MzYtY2M3Ni00NWM3LTkyMDMtYTM0ZGY2MGFjZTE4LjRkOGY2YTA2LWNmMDEtNGFlZi1iM2MxLWRlZjQ3NmFjYWI1YXgxNzkxMTQ0Mzk2ODI4NDk5Njc2 error="Get \"http://127.0.0.1:1/bucket45/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"17012026/10/04 20:06:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=M2E1MjI5MzYtY2M3Ni00NWM3LTkyMDMtYTM0ZGY2MGFjZTE4LjA1MTczMzZiLWUzYzYtNGFmMi1iNmUyLTdiZjE4MTllZDNhM3gxNzkxMTQ0Mzk2ODIxOTE1Njk4 parts=1217022026/10/04 20:06:37 INFO Received cleanup request method=DELETE path=/api/pending_closures1703--- PASS: TestReadProxyRangeRequest (0.30s)1704=== CONT TestClientErrorHandling/InvalidAuthToken17052026/10/04 20:06:37 INFO Aborted multipart uploads count=1 kept=01706--- PASS: TestRedundantMultipartUpload (1.25s)1707=== CONT TestResolveDBConnectionString/flag_wins1708=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1709=== CONT TestResolveDBConnectionString/missing_file_is_an_error1710=== CONT TestResolveDBConnectionString/file_when_flag_empty1711=== CONT TestResolveDBConnectionString/nothing_configured1712=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1713--- PASS: TestResolveDBConnectionString (0.00s)1714 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1715 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1716 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1717 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1718 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1719--- PASS: TestService_healthCheckHandler (0.30s)1720=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17212026/10/04 20:06:37 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]1722=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1723=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1724=== CONT TestService_RequireScope_OIDC/builder_may_write17252026/10/04 20:06:37 WARN Authentication failed token_preview=eyJhbGciOi...y_TbrTGC9Q token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1726=== CONT TestService_RequireScope_OIDC/reader_may_read1727=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1728=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read17292026/10/04 20:06:37 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1730--- PASS: TestService_AuthMiddleware_OIDC (0.44s)1731 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1732 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1733 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1734 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1735=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1736=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1737=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1738=== CONT TestService_RequireScope_OIDC/reader_may_not_write1739=== CONT TestService_RequireScope_OIDC/static_token_may_write1740=== CONT TestService_RequireScope_OIDC/static_token_may_admin1741=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1742=== CONT TestService_RequireScope_OIDC/writer_implies_read1743=== CONT TestService_RequireScope_OIDC/ops_may_not_write1744=== CONT TestServerTLSConfig/no_client_CA1745=== CONT TestServerTLSConfig/missing_CA_file1746=== CONT TestService_RequireScope_OIDC/ops_may_admin1747=== CONT TestServerTLSConfig/not_a_PEM_file1748=== CONT TestIsValidCachePath/narinfo1749=== CONT TestIsValidCachePath/short_hash1750=== CONT TestIsValidCachePath/wrong_extension1751=== CONT TestIsValidCachePath/leading_slash1752=== CONT TestIsValidCachePath/empty1753=== CONT TestIsValidCachePath/random_path1754=== CONT TestIsValidCachePath/index.html1755=== CONT TestIsValidCachePath/invalid_char_e1756=== CONT TestIsValidCachePath/traversal_in_middle1757=== CONT TestIsValidCachePath/traversal_parent1758=== CONT TestIsValidCachePath/invalid_char_u1759=== CONT TestIsValidCachePath/nix-cache-info1760=== CONT TestIsValidCachePath/realisation1761=== CONT TestIsValidCachePath/log1762=== CONT TestIsValidCachePath/nar_uncompressed1763=== CONT TestIsValidCachePath/nar_xz1764=== CONT TestIsValidCachePath/nar_bz21765=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1766--- PASS: TestServerTLSConfig (0.00s)1767 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1768 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1769 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1770=== CONT TestIsValidCachePath/nar_zst1771=== CONT TestParseSingleRange/closed1772=== CONT TestParseSingleRange/malformed_end_before_start1773=== CONT TestParseSingleRange/malformed_both_empty1774=== CONT TestParseSingleRange/open-ended1775=== CONT TestIsValidCachePath/ls1776=== CONT TestParseSingleRange/start_past_EOF1777=== CONT TestParseSingleRange/malformed_no_dash1778=== CONT TestParseSingleRange/suffix1779=== CONT TestParseSingleRange/suffix_exceeds_size1780=== CONT TestParseSingleRange/multi-range_ignored1781=== CONT TestParseSingleRange/none1782--- PASS: TestService_RequireScope_OIDC (0.47s)1783 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1784 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1785 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1786 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1787 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1788 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1789 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1790 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1791 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1792 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1793 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1794 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1795 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1796 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1797=== CONT TestParseSingleRange/start_far_past_EOF1798=== CONT TestParseSingleRange/end_clamped_to_size1799=== CONT TestPush_RejectsBadRequests/bad_root18002026/10/04 20:06:37 INFO Received push request method=POST path=/api/pushes1801--- PASS: TestIsValidCachePath (0.00s)1802 --- PASS: TestIsValidCachePath/narinfo (0.00s)1803 --- PASS: TestIsValidCachePath/short_hash (0.00s)1804 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1805 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1806 --- PASS: TestIsValidCachePath/empty (0.00s)1807 --- PASS: TestIsValidCachePath/random_path (0.00s)1808 --- PASS: TestIsValidCachePath/index.html (0.00s)1809 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1810 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1811 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1812 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1813 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1814 --- PASS: TestIsValidCachePath/realisation (0.00s)1815 --- PASS: TestIsValidCachePath/log (0.00s)1816 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1817 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1818 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1819 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1820 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1821 --- PASS: TestIsValidCachePath/ls (0.00s)1822=== CONT TestPush_RejectsBadRequests/no_roots1823=== CONT TestParseSingleRange/unknown_unit18242026/10/04 20:06:37 INFO Received push request method=POST path=/api/pushes1825=== CONT TestParseSingleRange/single_byte1826=== CONT TestPush_RejectsBadRequests/root_not_in_objects18272026/10/04 20:06:37 INFO Received push request method=POST path=/api/pushes1828--- PASS: TestParseSingleRange (0.00s)1829 --- PASS: TestParseSingleRange/closed (0.00s)1830 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1831 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1832 --- PASS: TestParseSingleRange/open-ended (0.00s)1833 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1834 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1835 --- PASS: TestParseSingleRange/suffix (0.00s)1836 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1837 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1838 --- PASS: TestParseSingleRange/none (0.00s)1839 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1840 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1841 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1842 --- PASS: TestParseSingleRange/single_byte (0.00s)1843=== CONT TestPush_RejectsBadRequests/no_objects18442026/10/04 20:06:37 INFO Received push request method=POST path=/api/pushes1845--- PASS: TestPush_RejectsBadRequests (0.29s)1846 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1847 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1848 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1849 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)18502026/10/04 20:06:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18512026/10/04 20:06:37 WARN Refused reserved pin name=worker-x86_64-linux18522026/10/04 20:06:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18532026/10/04 20:06:37 INFO Received create pin request method=POST path=/api/pins/my-app18542026/10/04 20:06:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1855--- PASS: TestCreatePin_ReservedPins (0.58s)18562026/10/04 20:06:37 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/present1857--- PASS: TestReadRedirectKeepsNarinfoProxied (0.30s)18582026/10/04 20:06:37 INFO Received uploads request method=POST path=/api/pending_closures1859--- PASS: TestReadRedirectUsesPublicS3URL (0.33s)1860--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.76s)18612026/10/04 20:06:37 INFO Received uploads request method=POST path=/api/pending_closures18622026/10/04 20:06:37 INFO Aborted multipart uploads count=0 kept=018632026/10/04 20:06:37 WARN Force mode enabled - objects will be deleted immediately without grace period18642026/10/04 20:06:37 INFO Received uploads request method=POST path=/api/pending_closures18652026/10/04 20:06:37 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=018662026/10/04 20:06:37 INFO Vacuumed table table=pending_closures18672026/10/04 20:06:37 INFO Vacuumed table table=pending_objects18682026/10/04 20:06:37 INFO Vacuumed table table=multipart_uploads18692026/10/04 20:06:37 INFO Vacuumed table table=closures18702026/10/04 20:06:37 INFO Vacuumed table table=objects18712026/10/04 20:06:37 INFO Aborted multipart uploads count=0 kept=018722026/10/04 20:06:37 WARN Force mode enabled - objects will be deleted immediately without grace period18732026/10/04 20:06:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018742026/10/04 20:06:37 INFO Vacuumed table table=pending_closures18752026/10/04 20:06:37 INFO Vacuumed table table=pending_objects18762026/10/04 20:06:37 INFO Vacuumed table table=multipart_uploads18772026/10/04 20:06:37 INFO Vacuumed table table=closures18782026/10/04 20:06:37 INFO Vacuumed table table=objects18792026/10/04 20:06:37 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.081834ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1880--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1881 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.32s)1882 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.26s)18832026/10/04 20:06:37 INFO lead: released remote=192.0.2.1:12341884=== NAME TestOrphanedObjectsGC1885 orphaned_objects_gc_test.go:290: GC Test Summary:1886 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1887 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1888 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1889 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1890 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1891--- PASS: TestOrphanedObjectsGC (0.61s)18922026/10/04 20:06:37 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18932026/10/04 20:06:37 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18942026/10/04 20:06:37 INFO lead: acquired remote=192.0.2.1:123418952026/10/04 20:06:37 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=364.688515ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18962026/10/04 20:06:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=790.531433ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1897--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1898 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1899 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1900 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.98s)1901--- PASS: TestPendingClosureWriteTimeout (0.00s)1902 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1903 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1904 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1905 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.15s)19062026/10/04 20:06:38 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01907=== NAME TestClientIntegration1908 client_integration_test.go:323: Objects in database after GC:1909 client_integration_test.go:323: Successfully deleted all objects with GC --force1910--- PASS: TestClientIntegration (2.70s)1911=== NAME TestOrphanedObjectsGCStressTest1912 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1913 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19142026/10/04 20:06:38 INFO lead: released remote=192.0.2.1:12341915--- PASS: TestLeadElectsOneAndHandsOver (2.84s)19162026/10/04 20:06:38 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019172026/10/04 20:06:38 INFO Received create pin request method=POST path=/api/pins/myapp19182026/10/04 20:06:38 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC574857350/001/store/h5pwhcw74qcci8dn8ajd2wmdxfgw55w9-pinned-file.txt narinfo_key=h5pwhcw74qcci8dn8ajd2wmdxfgw55w9.narinfo19192026/10/04 20:06:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures19202026/10/04 20:06:38 INFO Garbage collection started19212026/10/04 20:06:38 INFO Aborted multipart uploads count=0 kept=019222026/10/04 20:06:38 WARN Force mode enabled - objects will be deleted immediately without grace period19232026/10/04 20:06:38 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=019242026/10/04 20:06:38 INFO Vacuumed table table=pending_closures19252026/10/04 20:06:38 INFO Vacuumed table table=pending_objects19262026/10/04 20:06:38 INFO Vacuumed table table=multipart_uploads19272026/10/04 20:06:38 INFO Vacuumed table table=closures19282026/10/04 20:06:38 INFO Vacuumed table table=objects19292026/10/04 20:06:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.738079173s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1930=== NAME TestOrphanedObjectsGCStressTest1931 orphaned_objects_gc_test.go:509: Stress test completed successfully:1932 orphaned_objects_gc_test.go:510: - Active objects preserved: 201933 orphaned_objects_gc_test.go:511: - Objects deleted: 2101934 orphaned_objects_gc_test.go:512: - Total GC'd: 2101935--- PASS: TestOrphanedObjectsGCStressTest (1.95s)19362026/10/04 20:06:40 WARN Rate limiter enabled after throttle name=s3-test rate=519372026/10/04 20:06:40 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1938=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1939 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101940 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001941--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.79s)19422026/10/04 20:06:40 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-config19432026/10/04 20:06:40 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.299777ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1944=== NAME TestPinProtectsFromGC1945 client_integration_test.go:840: Pin successfully protected closure from garbage collection1946--- PASS: TestPinProtectsFromGC (4.69s)19472026/10/04 20:06:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.305686ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1948--- PASS: TestConnectWaitsForAPeerMigration (5.12s)1949--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.46s)19502026/10/04 20:06:41 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=858.00918ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19512026/10/04 20:06:42 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.611181728s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19522026/10/04 20:06:42 INFO Aborted multipart uploads count=1 kept=019532026/10/04 20:06:42 INFO Received cleanup request method=DELETE path=/api/pending_closures19542026/10/04 20:06:42 INFO Aborted multipart uploads count=1 kept=01955--- PASS: TestPendingCleanupUsesOneCutoff (6.41s)19562026/10/04 20:06:43 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"19572026/10/04 20:06:43 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-config19582026/10/04 20:06:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.264493ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19592026/10/04 20:06:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=427.451313ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19602026/10/04 20:06:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=750.167115ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19612026/10/04 20:06:45 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.716007929s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19622026/10/04 20:06:46 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_closures19632026/10/04 20:06:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.184569ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19642026/10/04 20:06:47 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=383.741554ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19652026/10/04 20:06:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=874.651803ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19662026/10/04 20:06:48 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.625192168s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1967--- PASS: TestClientErrorHandling (0.00s)1968 --- PASS: TestClientErrorHandling/InvalidStorePath (0.20s)1969 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.25s)1970 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.84s)1971PASS19722026-10-04 20:06:50.250 UTC [129] LOG: received smart shutdown request19732026-10-04 20:06:50.253 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 119742026-10-04 20:06:50.266 UTC [134] LOG: shutting down19752026-10-04 20:06:50.266 UTC [134] LOG: checkpoint starting: shutdown immediate19762026-10-04 20:06:51.214 UTC [134] LOG: checkpoint complete: wrote 10861 buffers (66.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.182 s, sync=0.737 s, total=0.949 s; sync files=29992, longest=0.008 s, average=0.001 s; distance=414733 kB, estimate=414733 kB; lsn=0/1AC69158, redo lsn=0/1AC6915819772026-10-04 20:06:51.293 UTC [129] LOG: database system is shut down1978Running OIDC tests...1979=== RUN TestAudienceForIssuer1980=== PAUSE TestAudienceForIssuer1981=== RUN TestGlobMatch1982=== PAUSE TestGlobMatch1983=== RUN TestValidateToken_ValidToken1984=== PAUSE TestValidateToken_ValidToken1985=== RUN TestValidateToken_WrongAudience1986=== PAUSE TestValidateToken_WrongAudience1987=== RUN TestValidateToken_Expired1988=== PAUSE TestValidateToken_Expired1989=== RUN TestValidateToken_BoundClaimsMismatch1990=== PAUSE TestValidateToken_BoundClaimsMismatch1991=== RUN TestValidateToken_BoundSubjectMismatch1992=== PAUSE TestValidateToken_BoundSubjectMismatch1993=== RUN TestValidateToken_MultipleProviders1994=== PAUSE TestValidateToken_MultipleProviders1995=== RUN TestValidateToken_NoMatchingProvider1996=== PAUSE TestValidateToken_NoMatchingProvider1997=== RUN TestValidateToken_KubernetesServiceAccount1998=== PAUSE TestValidateToken_KubernetesServiceAccount1999=== RUN TestNewValidator_KubernetesRequiresCA2000=== PAUSE TestNewValidator_KubernetesRequiresCA2001=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2002=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2003=== RUN TestPins_ReservedForMatchingRule2004=== PAUSE TestPins_ReservedForMatchingRule2005=== RUN TestPins_TopLevelShorthand2006=== PAUSE TestPins_TopLevelShorthand2007=== RUN TestPins_ConfigValidation2008=== PAUSE TestPins_ConfigValidation2009=== RUN TestScopes_LegacyProviderDefaultsToWrite2010=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2011=== RUN TestScopes_Rules2012=== PAUSE TestScopes_Rules2013=== RUN TestScopes_ConfigValidation2014=== PAUSE TestScopes_ConfigValidation2015=== CONT TestAudienceForIssuer2016=== CONT TestValidateToken_BoundClaimsMismatch2017=== CONT TestValidateToken_KubernetesServiceAccount2018--- PASS: TestAudienceForIssuer (0.00s)2019=== CONT TestValidateToken_Expired2020=== CONT TestValidateToken_MultipleProviders2021=== CONT TestValidateToken_NoMatchingProvider2022=== CONT TestPins_ReservedForMatchingRule2023=== CONT TestValidateToken_ValidToken2024=== CONT TestPins_TopLevelShorthand2025=== CONT TestValidateToken_WrongAudience2026=== CONT TestValidateToken_BoundSubjectMismatch2027=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2028=== CONT TestGlobMatch2029=== RUN TestGlobMatch/foo_foo2030=== PAUSE TestGlobMatch/foo_foo2031=== RUN TestGlobMatch/foo_bar2032=== PAUSE TestGlobMatch/foo_bar2033=== RUN TestGlobMatch/*_2034=== PAUSE TestGlobMatch/*_2035=== RUN TestGlobMatch/*_anything2036=== CONT TestPins_ConfigValidation2037=== CONT TestNewValidator_KubernetesRequiresCA2038=== CONT TestScopes_ConfigValidation2039=== CONT TestScopes_Rules2040=== CONT TestScopes_LegacyProviderDefaultsToWrite2041=== PAUSE TestGlobMatch/*_anything2042=== RUN TestGlobMatch/foo*_foo2043=== PAUSE TestGlobMatch/foo*_foo2044=== RUN TestGlobMatch/foo*_foobar2045=== PAUSE TestGlobMatch/foo*_foobar2046=== RUN TestGlobMatch/foo*_bar2047=== PAUSE TestGlobMatch/foo*_bar2048=== RUN TestGlobMatch/*bar_bar2049=== PAUSE TestGlobMatch/*bar_bar2050=== RUN TestGlobMatch/*bar_foobar2051=== PAUSE TestGlobMatch/*bar_foobar2052=== RUN TestGlobMatch/*bar_foo2053=== PAUSE TestGlobMatch/*bar_foo2054=== RUN TestGlobMatch/foo*bar_foobar2055=== PAUSE TestGlobMatch/foo*bar_foobar2056=== RUN TestGlobMatch/foo*bar_foo123bar2057=== PAUSE TestGlobMatch/foo*bar_foo123bar2058=== RUN TestGlobMatch/foo*bar_foobarbaz2059=== PAUSE TestGlobMatch/foo*bar_foobarbaz2060=== RUN TestGlobMatch/*/*_foo/bar2061=== PAUSE TestGlobMatch/*/*_foo/bar2062=== RUN TestGlobMatch/*/*_foo2063=== PAUSE TestGlobMatch/*/*_foo2064=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2065=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2066=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02067=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02068=== RUN TestGlobMatch/refs/*/main_refs/heads/main2069=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2070=== RUN TestGlobMatch/fo?_foo2071=== PAUSE TestGlobMatch/fo?_foo2072=== RUN TestGlobMatch/fo?_fo2073=== PAUSE TestGlobMatch/fo?_fo2074=== RUN TestGlobMatch/fo?_fooo2075--- PASS: TestScopes_ConfigValidation (0.00s)2076=== PAUSE TestGlobMatch/fo?_fooo2077=== RUN TestGlobMatch/?oo_foo2078=== PAUSE TestGlobMatch/?oo_foo2079=== RUN TestGlobMatch/?oo_boo2080=== PAUSE TestGlobMatch/?oo_boo2081=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2082=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2083=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2084=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2085=== CONT TestGlobMatch/foo_foo2086=== CONT TestGlobMatch/foo*bar_foobar2087=== CONT TestGlobMatch/foo*_foo2088=== CONT TestGlobMatch/*_anything2089=== CONT TestGlobMatch/*_2090=== CONT TestGlobMatch/*bar_foo2091=== CONT TestGlobMatch/foo_bar2092=== CONT TestGlobMatch/fo?_fo2093=== CONT TestGlobMatch/fo?_foo2094=== CONT TestGlobMatch/refs/*/main_refs/heads/main2095--- PASS: TestPins_ConfigValidation (0.00s)2096=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2097=== CONT TestGlobMatch/*/*_foo/bar2098=== CONT TestGlobMatch/*/*_foo2099=== CONT TestGlobMatch/foo*bar_foobarbaz2100=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2101=== CONT TestGlobMatch/?oo_boo2102=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2103=== CONT TestGlobMatch/?oo_foo2104=== CONT TestGlobMatch/*bar_foobar2105=== CONT TestGlobMatch/*bar_bar2106=== CONT TestGlobMatch/foo*_bar2107=== CONT TestGlobMatch/foo*_foobar2108=== CONT TestGlobMatch/fo?_fooo2109=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02110=== CONT TestGlobMatch/foo*bar_foo123bar2111--- PASS: TestGlobMatch (0.00s)2112 --- PASS: TestGlobMatch/foo_foo (0.00s)2113 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2114 --- PASS: TestGlobMatch/foo*_foo (0.00s)2115 --- PASS: TestGlobMatch/*_anything (0.00s)2116 --- PASS: TestGlobMatch/*_ (0.00s)2117 --- PASS: TestGlobMatch/*bar_foo (0.00s)2118 --- PASS: TestGlobMatch/foo_bar (0.00s)2119 --- PASS: TestGlobMatch/fo?_fo (0.00s)2120 --- PASS: TestGlobMatch/fo?_foo (0.00s)2121 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2122 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2123 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2124 --- PASS: TestGlobMatch/*/*_foo (0.00s)2125 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2126 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2127 --- PASS: TestGlobMatch/?oo_boo (0.00s)2128 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2129 --- PASS: TestGlobMatch/?oo_foo (0.00s)2130 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2131 --- PASS: TestGlobMatch/*bar_bar (0.00s)2132 --- PASS: TestGlobMatch/foo*_bar (0.00s)2133 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2134 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2135 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2136 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)21372026/10/04 20:06:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37689/oidc21382026/10/04 20:06:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43005/oidc2139--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)2140--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)21412026/10/04 20:06:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38413/oidc21422026/10/04 20:06:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42609/oidc21432026/10/04 20:06:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33989/oidc2144--- PASS: TestPins_TopLevelShorthand (0.09s)2145--- PASS: TestValidateToken_BoundClaimsMismatch (0.09s)2146--- PASS: TestScopes_Rules (0.09s)21472026/10/04 20:06:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33251/oidc2148--- PASS: TestPins_ReservedForMatchingRule (0.13s)21492026/10/04 20:06:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40891/oidc21502026/10/04 20:06:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41427/oidc2151--- PASS: TestValidateToken_ValidToken (0.15s)2152--- PASS: TestValidateToken_WrongAudience (0.15s)21532026/10/04 20:06:53 http: TLS handshake error from 127.0.0.1:58866: remote error: tls: bad certificate2154--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)21552026/10/04 20:06:53 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:39759/oidc21562026/10/04 20:06:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36805/oidc2157--- PASS: TestValidateToken_MultipleProviders (0.18s)21582026/10/04 20:06:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39807/oidc2159--- PASS: TestValidateToken_Expired (0.22s)21602026/10/04 20:06:53 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321612026/10/04 20:06:53 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:428112162--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.24s)2163--- PASS: TestValidateToken_KubernetesServiceAccount (0.24s)21642026/10/04 20:06:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46193/oidc2165--- PASS: TestValidateToken_NoMatchingProvider (0.35s)2166PASS2167Running hook tests...2168=== RUN TestSendPathsEmpty2169=== PAUSE TestSendPathsEmpty2170=== RUN TestQueueEnqueueAndFetch2171=== PAUSE TestQueueEnqueueAndFetch2172=== RUN TestQueueDeduplication2173=== PAUSE TestQueueDeduplication2174=== RUN TestQueueRemove2175=== PAUSE TestQueueRemove2176=== RUN TestQueueFetchBatchLimit2177=== PAUSE TestQueueFetchBatchLimit2178=== RUN TestQueueRetryMovesToBack2179=== PAUSE TestQueueRetryMovesToBack2180=== RUN TestQueueFetchRemoveLifecycle2181=== PAUSE TestQueueFetchRemoveLifecycle2182=== RUN TestQueueConcurrentWriters2183=== PAUSE TestQueueConcurrentWriters2184=== RUN TestQueueRemoveLargeClosure2185=== PAUSE TestQueueRemoveLargeClosure2186=== RUN TestServerClientIntegration2187=== PAUSE TestServerClientIntegration2188=== RUN TestServerQueueError2189=== PAUSE TestServerQueueError2190=== RUN TestGetListenerSocketActivation2191 server_test.go:210: === RUN TestGetListenerSocketActivation2192 --- PASS: TestGetListenerSocketActivation (0.00s)2193 PASS2194 2195--- PASS: TestGetListenerSocketActivation (0.01s)2196=== RUN TestDrainIsolatesPoisonPath2197=== PAUSE TestDrainIsolatesPoisonPath2198=== RUN TestRunNotBlockedByPoisonHead2199=== PAUSE TestRunNotBlockedByPoisonHead2200=== RUN TestDrainGivesUpWhenServerDown2201=== PAUSE TestDrainGivesUpWhenServerDown2202=== RUN TestFailedPathPrunedByLaterClosure2203=== PAUSE TestFailedPathPrunedByLaterClosure2204=== RUN TestWorkerUploadsAndRemoves2205=== PAUSE TestWorkerUploadsAndRemoves2206=== RUN TestWorkerSkipsGCdPaths2207=== PAUSE TestWorkerSkipsGCdPaths2208=== RUN TestWorkerPrunesClosureDeps2209=== PAUSE TestWorkerPrunesClosureDeps2210=== RUN TestDrainTimeout2211=== PAUSE TestDrainTimeout2212=== CONT TestSendPathsEmpty2213=== CONT TestWorkerSkipsGCdPaths2214=== CONT TestWorkerPrunesClosureDeps2215=== CONT TestDrainTimeout2216=== CONT TestQueueRemoveLargeClosure2217=== CONT TestWorkerUploadsAndRemoves2218--- PASS: TestSendPathsEmpty (0.00s)2219=== CONT TestFailedPathPrunedByLaterClosure2220=== CONT TestDrainGivesUpWhenServerDown2221=== CONT TestQueueConcurrentWriters2222=== CONT TestRunNotBlockedByPoisonHead2223=== CONT TestQueueFetchRemoveLifecycle2224=== CONT TestDrainIsolatesPoisonPath2225=== CONT TestQueueRetryMovesToBack2226=== CONT TestServerQueueError2227=== CONT TestQueueFetchBatchLimit2228=== CONT TestServerClientIntegration2229=== CONT TestQueueRemove2230=== CONT TestQueueDeduplication2231=== CONT TestQueueEnqueueAndFetch22322026/10/04 20:06:53 ERROR Failed to queue paths error="permission denied" count=12233--- PASS: TestServerQueueError (0.00s)2234--- PASS: TestServerClientIntegration (0.00s)22352026/10/04 20:06:53 INFO Uploading batch count=422362026/10/04 20:06:53 ERROR Upload failed error="upload failed" count=422372026/10/04 20:06:53 INFO Uploading batch count=22238--- PASS: TestQueueFetchBatchLimit (0.01s)22392026/10/04 20:06:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2123984441/002/bbb22402026/10/04 20:06:53 INFO Uploading batch count=122412026/10/04 20:06:53 ERROR Upload failed error="upload failed" count=122422026/10/04 20:06:53 INFO Upload queue status pending=222432026/10/04 20:06:53 INFO Uploading batch count=222442026/10/04 20:06:53 ERROR Upload failed error="upload failed" count=222452026/10/04 20:06:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown202745234/002/a2246--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2247--- PASS: TestQueueEnqueueAndFetch (0.01s)22482026/10/04 20:06:53 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1497164275/002/nonexistent2249--- PASS: TestQueueRemove (0.01s)22502026/10/04 20:06:53 INFO Upload queue status pending=222512026/10/04 20:06:53 INFO Uploading batch count=222522026/10/04 20:06:53 INFO Upload queue status pending=222532026/10/04 20:06:53 INFO Upload queue status pending=32254--- PASS: TestQueueRetryMovesToBack (0.02s)22552026/10/04 20:06:53 INFO Uploading batch count=122562026/10/04 20:06:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown202745234/002/b22572026/10/04 20:06:53 INFO Uploading batch count=12258--- PASS: TestQueueDeduplication (0.02s)22592026/10/04 20:06:53 INFO Uploading batch count=122602026/10/04 20:06:53 ERROR Upload failed error="upload failed" count=122612026/10/04 20:06:53 INFO Uploading batch count=122622026/10/04 20:06:53 INFO Uploading batch count=122632026/10/04 20:06:53 ERROR Upload failed error="upload failed" count=122642026/10/04 20:06:53 INFO Uploading batch count=222652026/10/04 20:06:53 ERROR Upload failed error="upload failed" count=222662026/10/04 20:06:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown202745234/002/c22672026/10/04 20:06:53 INFO Uploading batch count=122682026/10/04 20:06:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown202745234/002/d22692026/10/04 20:06:53 INFO Uploading batch count=122702026/10/04 20:06:53 ERROR Upload failed error="upload failed" count=122712026/10/04 20:06:53 INFO Uploading batch count=222722026/10/04 20:06:53 ERROR Upload failed error="upload failed" count=222732026/10/04 20:06:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown202745234/002/e22742026/10/04 20:06:53 INFO Uploading batch count=122752026/10/04 20:06:53 ERROR Upload failed error="upload failed" count=122762026/10/04 20:06:53 ERROR Drain finished with paths left in queue remaining=122772026/10/04 20:06:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown202745234/002/f2278--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)22792026/10/04 20:06:53 ERROR Drain finished with paths left in queue remaining=102280--- PASS: TestDrainIsolatesPoisonPath (0.02s)2281--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2282--- PASS: TestWorkerPrunesClosureDeps (0.04s)2283--- PASS: TestWorkerUploadsAndRemoves (0.03s)2284--- PASS: TestWorkerSkipsGCdPaths (0.04s)2285--- PASS: TestQueueRemoveLargeClosure (0.15s)22862026/10/04 20:06:53 ERROR Upload failed error="context deadline exceeded" count=222872026/10/04 20:06:53 ERROR Drain finished with paths left in queue remaining=42288--- PASS: TestQueueConcurrentWriters (0.21s)2289--- PASS: TestDrainTimeout (0.22s)22902026/10/04 20:06:54 INFO Uploading batch count=122912026/10/04 20:06:54 INFO Uploading batch count=122922026/10/04 20:06:54 INFO Uploading batch count=122932026/10/04 20:06:54 ERROR Upload failed error="upload failed" count=122942026/10/04 20:06:54 INFO Uploading batch count=122952026/10/04 20:06:54 ERROR Upload failed error="upload failed" count=122962026/10/04 20:06:54 INFO Uploading batch count=122972026/10/04 20:06:54 ERROR Upload failed error="upload failed" count=122982026/10/04 20:06:54 INFO Uploading batch count=122992026/10/04 20:06:54 ERROR Upload failed error="upload failed" count=123002026/10/04 20:06:54 ERROR Drain finished with paths left in queue remaining=12301--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2302PASS