niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #384
· 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.04s)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 TestSetClientTLSErrors101=== CONT TestEncodeNixBase32102=== RUN TestEncodeNixBase32/test_string_hash103=== PAUSE TestEncodeNixBase32/test_string_hash104=== RUN TestEncodeNixBase32/empty_input105=== PAUSE TestEncodeNixBase32/empty_input106=== CONT TestResolveStorePath107=== CONT TestDoWithRetry_BodyReplayedViaGetBody108=== CONT TestPathInfoHashCompatibility109=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)110=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)111=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon112=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon113=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI114=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI115=== CONT TestSetClientTLSDoesNotMutateDefaultTransport116=== CONT TestGetStorePathHash117=== RUN TestGetStorePathHash/valid_store_path118=== CONT TestSetClientTLS119=== CONT TestConvertHashToNix32120=== CONT TestClientSignaturesByStorePath121=== CONT TestEncodeNixBase32WithRealHash122=== CONT TestStreamPushReportsSignatures123=== CONT TestRateLimiterFeedback124=== CONT TestStreamPushRequestLine125=== CONT TestStreamPushGivesUpOnDeadServer126=== CONT TestStreamPushIsolatesFailures127=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess128=== CONT TestStreamPushBatchesUnderLoad129=== CONT TestShellSplitErrors130=== CONT TestShellSplit131=== CONT TestStreamPushReportsEveryPath132=== CONT TestUploadMultipart_PartsInParallel133=== CONT TestParsePathInfoJSON134=== CONT TestPathInfoCACompatibility135=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512136--- PASS: TestResolveStorePath (0.00s)137=== CONT TestDumpPathWriterError138=== PAUSE TestGetStorePathHash/valid_store_path139=== RUN TestConvertHashToNix32/SRI_format_to_Nix321402026/10/06 21:14:03 ERROR Upload failed error="connection refused" count=20141=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix321422026/10/06 21:14:03 WARN Rate limiter enabled after throttle name=server-test rate=5143=== CONT TestParsePathInfoJSONMultiplePaths144--- PASS: TestClientSignaturesByStorePath (0.00s)145--- PASS: TestEncodeNixBase32WithRealHash (0.00s)146--- PASS: TestShellSplitErrors (0.00s)147--- PASS: TestShellSplit (0.00s)148=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1492026/10/06 21:14:03 ERROR Server seems unavailable, giving up on batch untried=17150=== RUN TestPathInfoCACompatibility/null_ca_field1512026/10/06 21:14:03 ERROR Upload failed error="bad path" count=3152=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths153=== CONT TestDumpPathMatchesNix154=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512155=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths156=== PAUSE TestPathInfoCACompatibility/null_ca_field157=== CONT TestUploadMultipart_SupersededByPeer1582026/10/06 21:14:03 ERROR Upload failed error=boom count=1159=== RUN TestUploadMultipart_SupersededByPeer/exists160=== RUN TestConvertHashToNix32/already_Nix32_format161=== RUN TestGetStorePathHash/basename_without_hyphen_should_error162=== RUN TestParsePathInfoJSON/Nix_format163=== RUN TestRateLimiterFeedback/429_enables_limiter164=== CONT TestDumpPathSingleFile165=== RUN TestSetClientTLSErrors/missing_cert_file166=== RUN TestPathInfoCACompatibility/old_string_format_-_text167=== CONT TestScriptTokenCachesUntilRefresh168=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1692026/10/06 21:14:03 WARN Rate limiter enabled after throttle name=server-test rate=5170=== PAUSE TestRateLimiterFeedback/429_enables_limiter171--- PASS: TestStreamPushReportsSignatures (0.00s)1722026/10/06 21:14:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45941173=== PAUSE TestSetClientTLSErrors/missing_cert_file174=== CONT TestPartSizeForNAR175=== RUN TestPartSizeForNAR/zero_stays_at_minimum176=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text177=== RUN TestRateLimiterFeedback/503_enables_limiter178=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive179=== PAUSE TestUploadMultipart_SupersededByPeer/exists180=== PAUSE TestConvertHashToNix32/already_Nix32_format181=== PAUSE TestParsePathInfoJSON/Nix_format182=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error183=== CONT TestScriptTokenEmptyCommand184--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)185=== CONT TestScriptTokenScriptFails186=== RUN TestSetClientTLSErrors/missing_key_file187=== RUN TestConvertHashToNix32/invalid_format188=== RUN TestParsePathInfoJSON/Lix_format189=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error190--- PASS: TestStreamPushReportsEveryPath (0.00s)191--- PASS: TestScriptTokenEmptyCommand (0.00s)192=== CONT TestScriptTokenBadJSON193--- PASS: TestStreamPushIsolatesFailures (0.03s)194=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun1952026/10/06 21:14:03 ERROR Upload failed error=boom count=1196=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum197=== PAUSE TestRateLimiterFeedback/503_enables_limiter198=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive199=== RUN TestUploadMultipart_SupersededByPeer/missing200=== PAUSE TestUploadMultipart_SupersededByPeer/missing201=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter2022026/10/06 21:14:03 WARN Rate limiter backed off name=server-test rate=5203=== RUN TestPathInfoCACompatibility/new_structured_format_-_text2042026/10/06 21:14:03 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:45941205=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text206--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)207=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method208=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method209--- PASS: TestDoServerRequestAttachesToken (0.03s)210=== RUN TestPartSizeForNAR/small_stays_at_minimum211=== PAUSE TestPartSizeForNAR/small_stays_at_minimum212=== CONT TestCaseHackSuffix213=== CONT TestScriptTokenEmptyToken214=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter215=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter216=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica217=== PAUSE TestSetClientTLSErrors/missing_key_file218=== RUN TestSetClientTLSErrors/missing_ca_file219=== PAUSE TestSetClientTLSErrors/missing_ca_file220=== RUN TestSetClientTLSErrors/invalid_ca_file221=== PAUSE TestSetClientTLSErrors/invalid_ca_file222=== PAUSE TestConvertHashToNix32/invalid_format223=== CONT TestFileTokenMissing224=== PAUSE TestParsePathInfoJSON/Lix_format2252026/10/06 21:14:03 INFO Garbage collection started226--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)227=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error228=== CONT TestFilterOversizedClosures229=== CONT TestRegisterUploadedObjectReusesConnections230=== RUN TestFilterOversizedClosures/no_limit_keeps_everything231=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything232=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped233=== RUN TestSetClientTLS/rejects_connection_without_client_cert234=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert235=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA236=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA237=== RUN TestSetClientTLS/preserves_debug_logging_transport238=== PAUSE TestSetClientTLS/preserves_debug_logging_transport239--- PASS: TestFileTokenMissing (0.00s)240=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped241=== RUN TestFilterOversizedClosures/all_closures_skipped242=== PAUSE TestFilterOversizedClosures/all_closures_skipped243=== CONT TestFileTokenEmpty244=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter245=== CONT TestScriptTokenNoExpiryRerunsEveryCall2462026/10/06 21:14:03 INFO Garbage collection started247--- PASS: TestScriptTokenScriptFails (0.00s)248=== CONT TestEncodeNixBase32/empty_input249=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512250--- PASS: TestScriptTokenBadJSON (0.00s)251--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)252=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon253=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)254=== RUN TestParsePathInfoJSON/empty_input255=== PAUSE TestParsePathInfoJSON/empty_input256=== RUN TestParsePathInfoJSON/whitespace_only257=== PAUSE TestParsePathInfoJSON/whitespace_only258=== RUN TestParsePathInfoJSON/invalid_JSON259=== PAUSE TestParsePathInfoJSON/invalid_JSON260=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI261=== CONT TestPathInfoCACompatibility/new_structured_format_-_text262=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method263=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive264=== CONT TestPathInfoCACompatibility/old_string_format_-_text265=== CONT TestSetClientTLSErrors/missing_cert_file266=== CONT TestPathInfoCACompatibility/null_ca_field267=== CONT TestSetClientTLSErrors/missing_ca_file2682026/10/06 21:14:03 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=0269=== CONT TestSetClientTLSErrors/invalid_ca_file270=== CONT TestStaticToken271=== CONT TestSetClientTLSErrors/missing_key_file272=== CONT TestConvertHashToNix32/already_Nix32_format273=== CONT TestSetClientTLS/rejects_connection_without_client_cert274=== CONT TestFilterOversizedClosures/no_limit_keeps_everything275--- PASS: TestFileTokenEmpty (0.00s)276=== CONT TestConvertHashToNix32/SRI_format_to_Nix32277--- PASS: TestPathInfoHashCompatibility (0.00s)278 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)279 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)280 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)281 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)282=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error283=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error284=== CONT TestSetClientTLS/preserves_debug_logging_transport285=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA286=== CONT TestFileTokenReadsAndCaches2872026/10/06 21:14:03 WARN Garbage collection finished on another replica. Its statistics are not available here288--- PASS: TestPathInfoCACompatibility (0.03s)289 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)290 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)291 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)292 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)293 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)294--- PASS: TestScriptTokenEmptyToken (0.00s)295--- PASS: TestStaticToken (0.00s)296--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)297--- PASS: TestFileTokenReadsAndCaches (0.00s)298=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter299=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum300=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum301=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts302=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts303=== CONT TestFilterOversizedClosures/all_closures_skipped3042026/10/06 21:14:03 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=50305=== CONT TestEncodeNixBase32/test_string_hash306=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter307=== CONT TestRateLimiterFeedback/503_enables_limiter308=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths309=== RUN TestPartSizeForNAR/1_TiB310=== PAUSE TestPartSizeForNAR/1_TiB311=== RUN TestPartSizeForNAR/5_TiB_S3_max_object312=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths313=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object314=== CONT TestParsePathInfoJSON/whitespace_only315=== CONT TestParsePathInfoJSON/empty_input316=== CONT TestUploadMultipart_SupersededByPeer/missing317=== CONT TestConvertHashToNix32/invalid_format318=== CONT TestRateLimiterFeedback/429_enables_limiter319--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)320=== CONT TestParsePathInfoJSON/Lix_format321=== CONT TestParsePathInfoJSON/invalid_JSON322=== CONT TestGetStorePathHash/valid_store_path323=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error324=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error325=== CONT TestGetStorePathHash/basename_without_hyphen_should_error326=== CONT TestUploadMultipart_SupersededByPeer/exists3272026/10/06 21:14:03 WARN Rate limiter enabled after throttle name=server-test rate=5328=== RUN TestPartSizeForNAR/capped_at_5_GiB3292026/10/06 21:14:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:33133330=== PAUSE TestPartSizeForNAR/capped_at_5_GiB331=== CONT TestPartSizeForNAR/zero_stays_at_minimum332=== CONT TestPartSizeForNAR/capped_at_5_GiB333=== CONT TestPartSizeForNAR/5_TiB_S3_max_object334=== CONT TestPartSizeForNAR/1_TiB335=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts336=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum337=== CONT TestPartSizeForNAR/small_stays_at_minimum338--- PASS: TestSetClientTLSErrors (0.03s)339 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)340 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)341 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)342 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)343--- PASS: TestEncodeNixBase32 (0.00s)344 --- PASS: TestEncodeNixBase32/empty_input (0.00s)345 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)346--- PASS: TestConvertHashToNix32 (0.03s)347 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)348 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)349 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)3502026/10/06 21:14:03 WARN Rate limiter backed off name=server-test rate=5351=== CONT TestParsePathInfoJSON/Nix_format352--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)353 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)354 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)355=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3562026/10/06 21:14:03 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=2000357--- PASS: TestFilterOversizedClosures (0.00s)358 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)359 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)360 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)361--- PASS: TestGetStorePathHash (0.03s)362 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)363 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)364 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)365 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)366--- PASS: TestPartSizeForNAR (0.03s)367 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)368 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)369 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)370 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)371 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)372 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)373 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)374--- PASS: TestParsePathInfoJSON (0.03s)375 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)376 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)377 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)378 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)379 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)3802026/10/06 21:14:03 WARN Rate limiter enabled after throttle name=server-test rate=53812026/10/06 21:14:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33929382--- PASS: TestUploadMultipart_SupersededByPeer (0.02s)383 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)384 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)3852026/10/06 21:14:03 WARN Rate limiter backed off name=server-test rate=5386--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)387--- PASS: TestRateLimiterFeedback (0.03s)388 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)389 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)390 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)391 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)392--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)393--- PASS: TestStreamPushRequestLine (0.05s)3942026/10/06 21:14:03 http: TLS handshake error from 127.0.0.1:40408: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.03s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)399--- PASS: TestDumpPathSingleFile (0.06s)400--- PASS: TestCaseHackSuffix (0.03s)401--- PASS: TestDumpPathWriterError (0.06s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.08s)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/postgres2271022685/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/postgres2271022685/data -l logfile start434435/build/postgres2271022685:5432 - no response4362026-10-06 21:14:05.433 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 21:14:05.434 UTC [129] LOG: listening on Unix socket "/build/postgres2271022685/.s.PGSQL.5432"4382026-10-06 21:14:05.439 UTC [136] LOG: database system was shut down at 2026-10-06 21:14:05 UTC4392026-10-06 21:14:05.443 UTC [129] LOG: database system is ready to accept connections440/build/postgres2271022685:5432 - accepting connections441{"timestamp":"2026-10-06T21:14:05.632692072Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"28532fea-938e-4289-abe2-1cb891ade976","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(198)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/06 21:14:05 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 21:14:06 INFO lead: released remote=192.0.2.1:12344912026/10/06 21:14:06 INFO lead: acquired remote=192.0.2.1:12344922026/10/06 21:14:07 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/06 21:14:07 INFO lead: acquired remote=192.0.2.1:12345002026-10-06 21:14:09.129 UTC [388] FATAL: terminating connection due to administrator command5012026/10/06 21:14:09 INFO lead: acquired remote=192.0.2.1:12345022026/10/06 21:14:10 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/06 21:14:10 INFO lead: released remote=192.0.2.1:12345042026/10/06 21:14:10 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestService_NativeMTLS575=== PAUSE TestService_NativeMTLS576=== RUN TestServerTLSConfig577=== PAUSE TestServerTLSConfig578=== RUN TestMultipartCleanup579=== PAUSE TestMultipartCleanup580=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== RUN TestPendingCleanupUsesOneCutoff583=== PAUSE TestPendingCleanupUsesOneCutoff584=== RUN TestObjectStatsTrigger585=== PAUSE TestObjectStatsTrigger586=== RUN TestOrphanedObjectsGC587=== PAUSE TestOrphanedObjectsGC588=== RUN TestOrphanedObjectsGCStressTest589=== PAUSE TestOrphanedObjectsGCStressTest590=== RUN TestCreatePin_ReservedPins591=== PAUSE TestCreatePin_ReservedPins592=== RUN TestPresentReportsOnlyClosureRoots593=== PAUSE TestPresentReportsOnlyClosureRoots594=== RUN TestPresentRefreshesOnlyStaleClosures595=== PAUSE TestPresentRefreshesOnlyStaleClosures596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyContentNegotiation609=== PAUSE TestReadProxyContentNegotiation610=== RUN TestReadProxyNarStreaming611=== PAUSE TestReadProxyNarStreaming612=== RUN TestReadProxy404613=== PAUSE TestReadProxy404614=== RUN TestReadProxyInvalidPath615=== PAUSE TestReadProxyInvalidPath616=== RUN TestReadProxyHead617=== PAUSE TestReadProxyHead618=== RUN TestReadProxyOutlastsServerWriteTimeout619=== PAUSE TestReadProxyOutlastsServerWriteTimeout620=== RUN TestReadProxyConditionalGet621=== PAUSE TestReadProxyConditionalGet622=== RUN TestReadProxyRootRedirectsToIndexHTML623=== PAUSE TestReadProxyRootRedirectsToIndexHTML624=== RUN TestReadProxyDisabled625=== PAUSE TestReadProxyDisabled626=== RUN TestReadRedirectNar627=== PAUSE TestReadRedirectNar628=== RUN TestReadRedirectKeepsNarinfoProxied629=== PAUSE TestReadRedirectKeepsNarinfoProxied630=== RUN TestReadProxyRangeRequest631=== PAUSE TestReadProxyRangeRequest632=== RUN TestReadRedirectUsesPublicS3URL633=== PAUSE TestReadRedirectUsesPublicS3URL634=== RUN TestPush_OverlappingRootsStoreOneRowPerKey635=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey636=== RUN TestPush_CompleteCommitsEveryRoot637=== PAUSE TestPush_CompleteCommitsEveryRoot638=== RUN TestPush_RepeatedRootCommitsOnce639=== PAUSE TestPush_RepeatedRootCommitsOnce640=== RUN TestPush_CompleteWaitsForCleanupOfThePush641=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush642=== RUN TestPush_RootsAreLockedInByteOrder643=== PAUSE TestPush_RootsAreLockedInByteOrder644=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit645=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit646=== RUN TestPush_RejectsBadRequests647=== PAUSE TestPush_RejectsBadRequests648=== RUN TestPush_SignsNarinfosOfItsPendingObjects649=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects650=== RUN TestRedundantMultipartUpload651=== PAUSE TestRedundantMultipartUpload652=== RUN TestCompleteMultipartUpload_ErrorButObjectExists653=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists654=== RUN TestCompletedNarNotReofferedAcrossClosures655=== PAUSE TestCompletedNarNotReofferedAcrossClosures656=== RUN TestPresignedUploadRegisteredBeforeCommit657=== PAUSE TestPresignedUploadRegisteredBeforeCommit658=== RUN TestService_Rustfstest659=== PAUSE TestService_Rustfstest660=== RUN TestParseSize661=== PAUSE TestParseSize662=== RUN TestSkippedUploadsHandler663=== PAUSE TestSkippedUploadsHandler664=== RUN TestSystemdListenerNotActivated665--- PASS: TestSystemdListenerNotActivated (0.00s)666=== RUN TestWatchdogBeatsWhenHealthy667--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)668=== RUN TestWatchdogSkipsWhenUnhealthy6692026/10/06 21:14:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:14:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:14:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 21:14:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 21:14:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 21:14:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/06 21:14:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6762026/10/06 21:14:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/06 21:14:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/06 21:14:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"679--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)680=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle681=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle682=== RUN TestProxyWriteTimeout683=== PAUSE TestProxyWriteTimeout684=== RUN TestPendingClosureWriteTimeout685=== PAUSE TestPendingClosureWriteTimeout686=== RUN TestIsValidUploadKey687=== PAUSE TestIsValidUploadKey688=== RUN TestUploadHandlersRejectInvalidKeys689=== PAUSE TestUploadHandlersRejectInvalidKeys690=== RUN TestUploadHandlersRejectOversizedBody691=== PAUSE TestUploadHandlersRejectOversizedBody692=== RUN TestService_cleanupPendingClosuresHandler693=== PAUSE TestService_cleanupPendingClosuresHandler694=== RUN TestService_createPendingClosureHandler695=== PAUSE TestService_createPendingClosureHandler696=== RUN TestService_verifyS3Integrity697=== PAUSE TestService_verifyS3Integrity698=== RUN TestCompleteMultipartUnregistered699=== PAUSE TestCompleteMultipartUnregistered700=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT701=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT702=== CONT TestProxyWriteTimeout703=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT704=== RUN TestProxyWriteTimeout/narinfo705=== CONT TestService_AuthMiddleware706=== CONT TestReadRedirectKeepsNarinfoProxied707=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle708=== CONT TestSkippedUploadsHandler709=== CONT TestParseSize710--- PASS: TestParseSize (0.00s)711=== CONT TestService_Rustfstest712=== CONT TestPresignedUploadRegisteredBeforeCommit713=== CONT TestCompletedNarNotReofferedAcrossClosures7142026/10/06 21:14:10 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000715=== CONT TestCompleteMultipartUpload_ErrorButObjectExists716=== CONT TestRedundantMultipartUpload717=== CONT TestPush_SignsNarinfosOfItsPendingObjects718=== CONT TestPush_RejectsBadRequests719=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit720=== CONT TestPush_RootsAreLockedInByteOrder721=== CONT TestPush_CompleteWaitsForCleanupOfThePush722=== CONT TestPush_RepeatedRootCommitsOnce723=== CONT TestPush_CompleteCommitsEveryRoot724=== CONT TestPush_OverlappingRootsStoreOneRowPerKey725=== CONT TestReadRedirectUsesPublicS3URL726=== CONT TestService_cleanupPendingClosuresHandler727=== CONT TestReadProxyRangeRequest728=== CONT TestReadRedirectNar729=== PAUSE TestProxyWriteTimeout/narinfo730=== RUN TestProxyWriteTimeout/1_GiB_nar731=== PAUSE TestProxyWriteTimeout/1_GiB_nar732=== RUN TestProxyWriteTimeout/10_GiB_nar733=== PAUSE TestProxyWriteTimeout/10_GiB_nar734=== RUN TestProxyWriteTimeout/unknown_size735=== PAUSE TestProxyWriteTimeout/unknown_size736=== CONT TestReadProxyRootRedirectsToIndexHTML737=== CONT TestReadProxyDisabled738--- PASS: TestSkippedUploadsHandler (0.01s)739=== CONT TestReadProxyConditionalGet7402026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures741--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.31s)742=== CONT TestReadProxyOutlastsServerWriteTimeout7432026/10/06 21:14:11 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"744--- PASS: TestService_AuthMiddleware (0.32s)745=== CONT TestReadProxyHead7462026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures747--- PASS: TestReadRedirectKeepsNarinfoProxied (0.37s)748=== CONT TestReadProxyInvalidPath749--- PASS: TestService_Rustfstest (0.56s)750=== CONT TestReadProxy4047512026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures7522026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures7532026/10/06 21:14:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7542026/10/06 21:14:11 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGM5YmE0YWMtM2MxMi00M2VmLThmOWItOTYyMWVjMjEyZWFlLmYzNTI0NzFmLWNmMmItNGM2Mi1hYmZjLTUwZTk1OTI5NGQ3ZngxNzkxMzIxMjUxMzQ2MTk1MTYw7552026/10/06 21:14:11 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7562026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures7572026/10/06 21:14:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGM5YmE0YWMtM2MxMi00M2VmLThmOWItOTYyMWVjMjEyZWFlLmYzNTI0NzFmLWNmMmItNGM2Mi1hYmZjLTUwZTk1OTI5NGQ3ZngxNzkxMzIxMjUxMzQ2MTk1MTYw parts=1758--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.62s)759=== CONT TestReadProxyNarStreaming760--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.62s)761=== CONT TestReadProxyContentNegotiation7622026/10/06 21:14:11 INFO Received push request method=POST path=/api/pushes7632026/10/06 21:14:11 INFO Received complete push request method=POST path=/api/pushes/1/complete7642026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures7652026/10/06 21:14:11 INFO Received push request method=POST path=/api/pushes7662026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures7672026/10/06 21:14:11 INFO Received push request method=POST path=/api/pushes7682026/10/06 21:14:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7692026/10/06 21:14:11 INFO Signed narinfos id=1 count=17702026/10/06 21:14:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7712026/10/06 21:14:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7722026/10/06 21:14:11 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"7732026/10/06 21:14:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7742026/10/06 21:14:11 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"7752026/10/06 21:14:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7762026/10/06 21:14:11 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=17772026/10/06 21:14:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7782026/10/06 21:14:11 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo779--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.68s)780=== CONT TestReadProxyNarinfoAlreadyDecompressed7812026/10/06 21:14:11 INFO Received cleanup request method=DELETE path=/api/pending_closures7822026/10/06 21:14:11 INFO Aborted multipart uploads count=0 kept=07832026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures7842026/10/06 21:14:11 INFO Received cleanup request method=DELETE path=/api/pending_closures7852026/10/06 21:14:11 INFO Aborted multipart uploads count=1 kept=07862026/10/06 21:14:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7872026-10-06 21:14:11.464 UTC [469] ERROR: Closure does not exist: id=17882026-10-06 21:14:11.464 UTC [469] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE7892026-10-06 21:14:11.464 UTC [469] STATEMENT: -- name: CommitPendingClosure :exec790 SELECT commit_pending_closure($1::bigint)791 792--- PASS: TestService_cleanupPendingClosuresHandler (0.70s)793=== CONT TestReadProxyNarinfo7942026/10/06 21:14:11 INFO Aborted multipart uploads count=0 kept=07952026/10/06 21:14:11 INFO Received push request method=POST path=/api/pushes7962026/10/06 21:14:11 WARN Force mode enabled - objects will be deleted immediately without grace period7972026/10/06 21:14:11 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=07982026/10/06 21:14:11 INFO Vacuumed table table=pending_closures7992026/10/06 21:14:11 INFO Received complete push request method=POST path=/api/pushes/1/complete8002026/10/06 21:14:11 INFO Vacuumed table table=pending_objects8012026/10/06 21:14:11 INFO Received push request method=POST path=/api/pushes8022026/10/06 21:14:11 INFO Vacuumed table table=multipart_uploads8032026/10/06 21:14:11 INFO Vacuumed table table=closures8042026/10/06 21:14:11 INFO Vacuumed table table=objects805--- PASS: TestPush_CompleteCommitsEveryRoot (0.74s)806=== CONT TestIsValidCachePath807=== RUN TestIsValidCachePath/narinfo808=== PAUSE TestIsValidCachePath/narinfo809=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars810=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars811=== RUN TestIsValidCachePath/nar_zst812=== PAUSE TestIsValidCachePath/nar_zst813=== RUN TestIsValidCachePath/nar_xz814=== PAUSE TestIsValidCachePath/nar_xz815=== RUN TestIsValidCachePath/nar_bz2816=== PAUSE TestIsValidCachePath/nar_bz2817=== RUN TestIsValidCachePath/nar_uncompressed818=== PAUSE TestIsValidCachePath/nar_uncompressed819=== RUN TestIsValidCachePath/ls820=== PAUSE TestIsValidCachePath/ls821=== RUN TestIsValidCachePath/log822=== PAUSE TestIsValidCachePath/log823=== RUN TestIsValidCachePath/realisation824=== PAUSE TestIsValidCachePath/realisation825=== RUN TestIsValidCachePath/nix-cache-info826=== PAUSE TestIsValidCachePath/nix-cache-info827=== RUN TestIsValidCachePath/index.html828=== PAUSE TestIsValidCachePath/index.html829=== RUN TestIsValidCachePath/traversal_parent830=== PAUSE TestIsValidCachePath/traversal_parent831=== RUN TestIsValidCachePath/traversal_in_middle832=== PAUSE TestIsValidCachePath/traversal_in_middle833=== RUN TestIsValidCachePath/invalid_char_e834=== PAUSE TestIsValidCachePath/invalid_char_e835=== RUN TestIsValidCachePath/invalid_char_u836=== PAUSE TestIsValidCachePath/invalid_char_u837=== RUN TestIsValidCachePath/random_path838=== PAUSE TestIsValidCachePath/random_path839=== RUN TestIsValidCachePath/empty840=== PAUSE TestIsValidCachePath/empty841=== RUN TestIsValidCachePath/leading_slash842=== PAUSE TestIsValidCachePath/leading_slash843=== RUN TestIsValidCachePath/wrong_extension844=== PAUSE TestIsValidCachePath/wrong_extension845=== RUN TestIsValidCachePath/short_hash846=== PAUSE TestIsValidCachePath/short_hash847=== CONT TestProxyHeadersOnlyTrustedOnSocket8482026/10/06 21:14:11 INFO Received complete push request method=POST path=/api/pushes/2/complete849--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.74s)850=== CONT TestParseSingleRange851=== RUN TestParseSingleRange/none852=== PAUSE TestParseSingleRange/none853=== RUN TestParseSingleRange/unknown_unit854=== PAUSE TestParseSingleRange/unknown_unit855=== RUN TestParseSingleRange/multi-range_ignored856=== PAUSE TestParseSingleRange/multi-range_ignored857=== RUN TestParseSingleRange/malformed_no_dash858=== PAUSE TestParseSingleRange/malformed_no_dash859=== RUN TestParseSingleRange/malformed_both_empty860=== PAUSE TestParseSingleRange/malformed_both_empty861=== RUN TestParseSingleRange/malformed_end_before_start862=== PAUSE TestParseSingleRange/malformed_end_before_start863=== RUN TestParseSingleRange/closed864=== PAUSE TestParseSingleRange/closed865=== RUN TestParseSingleRange/open-ended866=== PAUSE TestParseSingleRange/open-ended867=== RUN TestParseSingleRange/end_clamped_to_size868=== PAUSE TestParseSingleRange/end_clamped_to_size869=== RUN TestParseSingleRange/suffix870=== PAUSE TestParseSingleRange/suffix871=== RUN TestParseSingleRange/suffix_exceeds_size872=== PAUSE TestParseSingleRange/suffix_exceeds_size873=== RUN TestParseSingleRange/single_byte874=== PAUSE TestParseSingleRange/single_byte875=== RUN TestParseSingleRange/start_past_EOF876=== PAUSE TestParseSingleRange/start_past_EOF877=== RUN TestParseSingleRange/start_far_past_EOF878=== PAUSE TestParseSingleRange/start_far_past_EOF879=== CONT TestFailedS3DeleteKeepsTombstone8802026/10/06 21:14:11 INFO Received complete push request method=POST path=/api/pushes/1/complete8812026/10/06 21:14:11 INFO Received push request method=POST path=/api/pushes882--- PASS: TestPush_RepeatedRootCommitsOnce (0.76s)883=== CONT TestForceGCDuringPushOffersSweptObject884=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows885=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows886=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check887=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check888=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection889--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.77s)890=== CONT TestGCSweepDeliversEachKeyOnce891=== RUN TestPush_RejectsBadRequests/root_not_in_objects892=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects893=== RUN TestPush_RejectsBadRequests/no_roots894=== PAUSE TestPush_RejectsBadRequests/no_roots895=== RUN TestPush_RejectsBadRequests/no_objects896=== PAUSE TestPush_RejectsBadRequests/no_objects897=== RUN TestPush_RejectsBadRequests/bad_root898=== PAUSE TestPush_RejectsBadRequests/bad_root899=== CONT TestTombstonedObjectOfferedWithoutWaiting900--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.80s)901=== CONT TestGCSweepSkipsPendingObjects9022026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures9032026/10/06 21:14:11 INFO Received push request method=POST path=/api/pushes904--- PASS: TestReadProxyConditionalGet (0.89s)905=== CONT TestDeduplicatedObjectsRecordedAsPending9062026/10/06 21:14:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9072026/10/06 21:14:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9082026/10/06 21:14:11 INFO Received push request method=POST path=/api/pushes9092026/10/06 21:14:11 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OGM5YmE0YWMtM2MxMi00M2VmLThmOWItOTYyMWVjMjEyZWFlLjAzYThkZDgzLWUzYWItNDY0NC05MzI3LTFlMGI1OWM3OTE4OXgxNzkxMzIxMjUxMDk5OTI4Mzkx parts=129102026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures911--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.92s)912=== CONT TestPushDedupSurvivesConcurrentGC913--- PASS: TestReadRedirectNar (0.93s)914=== CONT TestGCMetrics9152026-10-06 21:14:11.699 UTC [554] ERROR: could not obtain lock on row in relation "closures"9162026-10-06 21:14:11.699 UTC [554] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9172026-10-06 21:14:11.700 UTC [554] ERROR: could not obtain lock on row in relation "closures"9182026-10-06 21:14:11.700 UTC [554] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9192026-10-06 21:14:11.700 UTC [554] ERROR: could not obtain lock on row in relation "closures"9202026-10-06 21:14:11.700 UTC [554] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9212026-10-06 21:14:11.700 UTC [554] ERROR: could not obtain lock on row in relation "closures"9222026-10-06 21:14:11.700 UTC [554] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9232026-10-06 21:14:11.700 UTC [554] ERROR: could not obtain lock on row in relation "closures"9242026-10-06 21:14:11.700 UTC [554] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT925--- PASS: TestPush_RootsAreLockedInByteOrder (0.95s)926=== CONT TestGCBugBareHashReferences927--- PASS: TestReadProxyRangeRequest (0.95s)928=== CONT TestGCAdvisoryLockBlocksConcurrentRun929--- PASS: TestReadProxyDisabled (0.96s)930=== CONT TestSweepSkipsRowsLockedByPush931--- PASS: TestReadRedirectUsesPublicS3URL (1.00s)932=== CONT TestLeadEndsOnShutdown933--- PASS: TestReadProxyHead (0.70s)934=== CONT TestLeadIncumbentAnnouncesAtOnce9352026/10/06 21:14:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9362026/10/06 21:14:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OGM5YmE0YWMtM2MxMi00M2VmLThmOWItOTYyMWVjMjEyZWFlLjU5MmI1OThkLTliODctNDIwNy04M2Q4LWJlMGE5Mjg3ZGIzY3gxNzkxMzIxMjUxNDA2MzUyMzY1 parts=129372026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures938--- PASS: TestReadProxy404 (0.52s)939=== CONT TestPresentNotReportedWhileGCDeletesClosure940=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale941=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale942=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh943=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh944=== CONT TestLeadElectsOneAndHandsOver945--- PASS: TestReadProxyInvalidPath (0.71s)946=== CONT TestPresentRefreshesOnlyStaleClosures9472026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures948--- PASS: TestReadProxyNarStreaming (0.51s)949=== CONT TestConnectWaitsForAPeerMigration950--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.47s)951=== CONT TestPresentReportsOnlyClosureRoots9522026-10-06 21:14:11.921 UTC [531] ERROR: Push does not exist: id=19532026-10-06 21:14:11.921 UTC [531] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE9542026-10-06 21:14:11.921 UTC [531] STATEMENT: SELECT commit_push($1)955--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.16s)956=== CONT TestResolveDBConnectionString957=== RUN TestResolveDBConnectionString/flag_wins958=== PAUSE TestResolveDBConnectionString/flag_wins959=== RUN TestResolveDBConnectionString/file_when_flag_empty960=== PAUSE TestResolveDBConnectionString/file_when_flag_empty961=== RUN TestResolveDBConnectionString/missing_file_is_an_error962=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error963=== RUN TestResolveDBConnectionString/PGHOST_allows_empty964=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty965=== RUN TestResolveDBConnectionString/nothing_configured966=== PAUSE TestResolveDBConnectionString/nothing_configured967=== CONT TestCreatePin_ReservedPins968--- PASS: TestReadProxyContentNegotiation (0.54s)969=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9702026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures9712026/10/06 21:14:11 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2036423736/001/proxy.sock9722026/10/06 21:14:11 INFO Starting HTTP server address=127.0.0.1:440419732026/10/06 21:14:11 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9742026/10/06 21:14:11 INFO Shutdown signal received, draining in-flight requests timeout=10s975--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.48s)976=== CONT TestOrphanedObjectsGCStressTest9772026/10/06 21:14:11 INFO Received uploads request method=POST path=/api/pending_closures9782026/10/06 21:14:12 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>979--- PASS: TestReadProxyNarinfo (0.54s)980=== CONT TestDeleteClosuresRacingPins9812026/10/06 21:14:12 INFO Aborted multipart uploads count=0 kept=09822026/10/06 21:14:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40687/oidc9832026/10/06 21:14:12 WARN Force mode enabled - objects will be deleted immediately without grace period9842026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures9852026/10/06 21:14:12 INFO Aborted multipart uploads count=0 kept=0986--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.51s)987=== CONT TestOrphanedObjectsGC9882026/10/06 21:14:12 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9892026/10/06 21:14:12 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."9902026/10/06 21:14:12 WARN Force mode enabled - objects will be deleted immediately without grace period991--- PASS: TestFailedS3DeleteKeepsTombstone (0.55s)992=== CONT TestClientFallsBackToClosures9932026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures9942026/10/06 21:14:12 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=09952026/10/06 21:14:12 INFO Vacuumed table table=pending_closures9962026/10/06 21:14:12 INFO Vacuumed table table=pending_objects9972026/10/06 21:14:12 INFO Vacuumed table table=multipart_uploads9982026/10/06 21:14:12 INFO Vacuumed table table=closures9992026/10/06 21:14:12 INFO Vacuumed table table=objects1000--- PASS: TestGCSweepDeliversEachKeyOnce (0.54s)1001=== CONT TestObjectStatsTrigger10022026/10/06 21:14:12 INFO Aborted multipart uploads count=0 kept=010032026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures10042026/10/06 21:14:12 WARN Force mode enabled - objects will be deleted immediately without grace period10052026/10/06 21:14:12 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=01006--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.44s)1007=== CONT TestClientPushesUseOnePush10082026/10/06 21:14:12 INFO Vacuumed table table=pending_closures10092026/10/06 21:14:12 INFO Vacuumed table table=pending_objects10102026/10/06 21:14:12 INFO Vacuumed table table=multipart_uploads10112026/10/06 21:14:12 INFO Vacuumed table table=closures10122026/10/06 21:14:12 INFO Vacuumed table table=objects1013--- PASS: TestGCSweepSkipsPendingObjects (0.55s)1014=== CONT TestPendingCleanupUsesOneCutoff10152026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures10162026/10/06 21:14:12 INFO Aborted multipart uploads count=0 kept=010172026/10/06 21:14:12 WARN Force mode enabled - objects will be deleted immediately without grace period10182026/10/06 21:14:12 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=010192026/10/06 21:14:12 INFO Vacuumed table table=pending_closures10202026/10/06 21:14:12 INFO Vacuumed table table=pending_objects10212026/10/06 21:14:12 INFO Vacuumed table table=multipart_uploads10222026/10/06 21:14:12 INFO Vacuumed table table=closures10232026/10/06 21:14:12 INFO Vacuumed table table=objects1024--- PASS: TestGCMetrics (0.46s)1025=== CONT TestPinProtectsFromGC10262026/10/06 21:14:12 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"1027--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.47s)1028=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10292026/10/06 21:14:12 INFO Aborted multipart uploads count=0 kept=01030--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.68s)1031=== CONT TestClientSharedPathCommittedMidPush10322026/10/06 21:14:12 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=010332026/10/06 21:14:12 INFO Vacuumed table table=pending_closures10342026/10/06 21:14:12 INFO Vacuumed table table=pending_objects10352026/10/06 21:14:12 INFO Vacuumed table table=multipart_uploads10362026/10/06 21:14:12 INFO Vacuumed table table=closures10372026/10/06 21:14:12 INFO Vacuumed table table=objects10382026/10/06 21:14:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10392026/10/06 21:14:12 INFO Aborted multipart uploads count=0 kept=010402026/10/06 21:14:12 INFO Aborted multipart uploads count=0 kept=010412026/10/06 21:14:12 INFO lead: acquired remote=192.0.2.1:123410422026/10/06 21:14:12 WARN Force mode enabled - objects will be deleted immediately without grace period10432026/10/06 21:14:12 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=010442026/10/06 21:14:12 WARN Force mode enabled - objects will be deleted immediately without grace period10452026/10/06 21:14:12 INFO Vacuumed table table=pending_closures10462026/10/06 21:14:12 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=010472026/10/06 21:14:12 INFO Vacuumed table table=pending_closures10482026/10/06 21:14:12 INFO Vacuumed table table=pending_objects10492026/10/06 21:14:12 INFO Vacuumed table table=multipart_uploads10502026/10/06 21:14:12 INFO Vacuumed table table=pending_objects10512026/10/06 21:14:12 INFO Vacuumed table table=multipart_uploads10522026/10/06 21:14:12 INFO Vacuumed table table=closures10532026/10/06 21:14:12 INFO Vacuumed table table=closures10542026/10/06 21:14:12 INFO Vacuumed table table=objects10552026/10/06 21:14:12 INFO Vacuumed table table=objects10562026/10/06 21:14:12 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGM5YmE0YWMtM2MxMi00M2VmLThmOWItOTYyMWVjMjEyZWFlLjRlOTUwYmFhLTMyYmMtNGM2Yi05OWRlLTFjMmQ5NTdiN2Q1Y3gxNzkxMzIxMjUxODQ1MTcxNjEz error="Get \"http://127.0.0.1:1/bucket11/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10572026/10/06 21:14:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGM5YmE0YWMtM2MxMi00M2VmLThmOWItOTYyMWVjMjEyZWFlLjY4YWNhZTZjLTBmMmUtNDcwYi1iMzkxLWNhZjU1NjI5MDM1NXgxNzkxMzIxMjUxODM4NjMxMzU2 parts=121058--- PASS: TestPushDedupSurvivesConcurrentGC (0.56s)1059=== CONT TestMultipartCleanup10602026/10/06 21:14:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10612026/10/06 21:14:12 INFO Aborted multipart uploads count=0 kept=010622026/10/06 21:14:12 INFO Aborted multipart uploads count=1 kept=010632026/10/06 21:14:12 WARN Force mode enabled - objects will be deleted immediately without grace period10642026/10/06 21:14:12 INFO lead: acquired remote=192.0.2.1:123410652026/10/06 21:14:12 INFO lead: released remote=192.0.2.1:12341066--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.47s)1067=== CONT TestClientWithDependencies1068--- PASS: TestRedundantMultipartUpload (1.49s)1069=== CONT TestServerTLSConfig1070=== RUN TestServerTLSConfig/no_client_CA1071=== PAUSE TestServerTLSConfig/no_client_CA1072=== RUN TestServerTLSConfig/missing_CA_file1073=== PAUSE TestServerTLSConfig/missing_CA_file1074=== RUN TestServerTLSConfig/not_a_PEM_file1075=== PAUSE TestServerTLSConfig/not_a_PEM_file1076=== CONT TestClientMultipleUploads10772026/10/06 21:14:12 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=010782026/10/06 21:14:12 INFO Vacuumed table table=pending_closures10792026/10/06 21:14:12 INFO Vacuumed table table=pending_objects10802026/10/06 21:14:12 INFO Vacuumed table table=multipart_uploads10812026/10/06 21:14:12 INFO Vacuumed table table=closures10822026/10/06 21:14:12 INFO Vacuumed table table=objects1083--- PASS: TestSweepSkipsRowsLockedByPush (0.53s)1084=== CONT TestService_NativeMTLS1085--- PASS: TestPresentRefreshesOnlyStaleClosures (0.44s)1086=== CONT TestUploadHandlersRejectInvalidKeys1087=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1088=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1089=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1090=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1091=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1092=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1093=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1094=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1095=== CONT TestMetricsInventory10962026/10/06 21:14:12 INFO lead: acquired remote=192.0.2.1:12341097--- PASS: TestPresentReportsOnlyClosureRoots (0.41s)1098=== CONT TestClientIntegration1099--- PASS: TestGCBugBareHashReferences (0.67s)1100=== CONT TestUploadHandlersRejectOversizedBody11012026/10/06 21:14:12 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11022026/10/06 21:14:12 WARN Refused reserved pin name=worker-x86_64-linux11032026/10/06 21:14:12 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11042026/10/06 21:14:12 INFO Received create pin request method=POST path=/api/pins/my-app11052026/10/06 21:14:12 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1106--- PASS: TestCreatePin_ReservedPins (0.53s)1107=== CONT TestNARDeduplicationMetadataUploadBug1108--- PASS: TestObjectStatsTrigger (0.45s)1109=== CONT TestClientErrorHandling1110=== RUN TestClientErrorHandling/InvalidStorePath1111=== PAUSE TestClientErrorHandling/InvalidStorePath1112=== RUN TestClientErrorHandling/InvalidAuthToken1113=== PAUSE TestClientErrorHandling/InvalidAuthToken1114=== RUN TestClientErrorHandling/ServerNotAvailable1115=== PAUSE TestClientErrorHandling/ServerNotAvailable1116=== CONT TestCreatePendingClosureRejectsOversizedNAR11172026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures1118--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1119=== CONT TestService_verifyS3Integrity1120=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1121=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1122=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1123=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1124=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1125=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1126=== CONT TestClientCADerivations11272026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures11282026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures11292026/10/06 21:14:12 INFO Received cleanup request method=DELETE path=/api/pending_closures11302026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures1131--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.43s)1132=== CONT TestCompleteMultipartUnregistered11332026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures1134=== NAME TestPinProtectsFromGC1135 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3214984705/001/store/bp6gaccj4rpki9hcsf39myif32skz3h5-pinned-file.txt1136 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3214984705/001/store/qkhf1qgypbf68a05scjvn00if3i7hzgb-unpinned-file.txt11372026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures11382026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures11392026/10/06 21:14:12 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11402026/10/06 21:14:12 INFO Uploading vky2bg23byj58bs31q1r3mb5vr6siqss-b (216B)11412026/10/06 21:14:12 INFO Uploading yg5n354pxhrc8y5kw43lvcc1h88dhnsd-shared-dep (136B)11422026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11432026/10/06 21:14:12 WARN Failed to register uploaded object key=v9wd4gby9wj687814c5y1s91pn8vsslb.ls error="server returned 404: 404 page not found\n"11442026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/08pa5qwypq37azaj5w82bx0yfsviq55ha1lbx5s4kixcvyprqb8h.nar.zst error="server returned 404: 404 page not found\n"11452026/10/06 21:14:12 WARN Failed to register uploaded object key=vky2bg23byj58bs31q1r3mb5vr6siqss.ls error="server returned 404: 404 page not found\n"11462026/10/06 21:14:12 WARN Failed to register uploaded object key=yg5n354pxhrc8y5kw43lvcc1h88dhnsd.ls error="server returned 404: 404 page not found\n"11472026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11482026/10/06 21:14:12 INFO Signed narinfos id=1 count=211492026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11502026/10/06 21:14:12 INFO Signed narinfos id=2 count=211512026/10/06 21:14:12 INFO Uploading 4 narinfos11522026/10/06 21:14:12 WARN Failed to register uploaded object key=vky2bg23byj58bs31q1r3mb5vr6siqss.narinfo error="server returned 404: 404 page not found\n"11532026/10/06 21:14:12 WARN Failed to register uploaded object key=v9wd4gby9wj687814c5y1s91pn8vsslb.narinfo error="server returned 404: 404 page not found\n"11542026/10/06 21:14:12 WARN Failed to register uploaded object key=yg5n354pxhrc8y5kw43lvcc1h88dhnsd.narinfo error="server returned 404: 404 page not found\n"11552026/10/06 21:14:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11562026/10/06 21:14:12 WARN Failed to register uploaded object key=yg5n354pxhrc8y5kw43lvcc1h88dhnsd.narinfo error="server returned 404: 404 page not found\n"11572026/10/06 21:14:12 INFO Completed upload id=111582026/10/06 21:14:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11592026/10/06 21:14:12 INFO Completed upload id=211602026/10/06 21:14:12 INFO Upload complete. (75ms)1161=== NAME TestClientFallsBackToClosures1162 client_pushes_test.go:112: Retrieved narinfo from S3:1163 StorePath: /build/TestClientFallsBackToClosures368812854/001/store/yg5n354pxhrc8y5kw43lvcc1h88dhnsd-shared-dep1164 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1165 Compression: zstd1166 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821167 NarSize: 1361168 References: 1169 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1170 client_pushes_test.go:112: Retrieved narinfo from S3:1171 StorePath: /build/TestClientFallsBackToClosures368812854/001/store/v9wd4gby9wj687814c5y1s91pn8vsslb-a1172 URL: nar/08pa5qwypq37azaj5w82bx0yfsviq55ha1lbx5s4kixcvyprqb8h.nar.zst1173 Compression: zstd1174 NarHash: sha256:08pa5qwypq37azaj5w82bx0yfsviq55ha1lbx5s4kixcvyprqb8h1175 NarSize: 2161176 References: /build/TestClientFallsBackToClosures368812854/001/store/yg5n354pxhrc8y5kw43lvcc1h88dhnsd-shared-dep1177 CA: text:sha256:08sksrzh8dfxbhyakf4kx8ma2gryh6vi654r706kyalhw0vrf4g41178 client_pushes_test.go:112: Retrieved narinfo from S3:1179 StorePath: /build/TestClientFallsBackToClosures368812854/001/store/vky2bg23byj58bs31q1r3mb5vr6siqss-b1180 URL: nar/08pa5qwypq37azaj5w82bx0yfsviq55ha1lbx5s4kixcvyprqb8h.nar.zst1181 Compression: zstd1182 NarHash: sha256:08pa5qwypq37azaj5w82bx0yfsviq55ha1lbx5s4kixcvyprqb8h1183 NarSize: 2161184 References: /build/TestClientFallsBackToClosures368812854/001/store/yg5n354pxhrc8y5kw43lvcc1h88dhnsd-shared-dep1185 CA: text:sha256:08sksrzh8dfxbhyakf4kx8ma2gryh6vi654r706kyalhw0vrf4g41186--- PASS: TestClientFallsBackToClosures (0.65s)1187=== CONT TestCacheConfigHandlerMaxNarSize1188--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1189=== CONT TestCacheStatsHandler1190--- PASS: TestMetricsInventory (0.44s)1191=== CONT TestGenerateLandingPage1192--- PASS: TestGenerateLandingPage (0.00s)1193=== CONT TestService_ReadAuthMiddleware11942026/10/06 21:14:12 INFO Received push request method=POST path=/api/pushes11952026/10/06 21:14:12 INFO Received push request method=POST path=/api/pushes11962026/10/06 21:14:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11972026/10/06 21:14:12 INFO Uploading bp6gaccj4rpki9hcsf39myif32skz3h5-pinned-file.txt (128B)11982026/10/06 21:14:12 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11992026/10/06 21:14:12 INFO Uploading hzc6d4nrci7fggf127kz99xbxxnsfz95-b (216B)12002026/10/06 21:14:12 INFO Uploading 28w9jl0f82vq9qi0k3j4y1j9s5px2xfk-shared-dep (136B)1201=== NAME TestClientMultipleUploads1202 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3308295426/001/store/srbrdya2si5arcxv4qrh790n1j1sha1a-test-file-0.txt12032026/10/06 21:14:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12042026/10/06 21:14:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1205--- PASS: TestService_NativeMTLS (0.48s)1206=== CONT TestService_AuthMiddleware_OIDC12072026/10/06 21:14:12 WARN Failed to register uploaded object key=bp6gaccj4rpki9hcsf39myif32skz3h5.ls error="server returned 404: 404 page not found\n"12082026/10/06 21:14:12 WARN Failed to register uploaded object key=7xx0bf06dpzyj9i2z6017mg394alvhwc.ls error="server returned 404: 404 page not found\n"12092026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12102026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12112026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/1jf3ffhihlq1nkr29d3af2gi8q556jv77frh8rdvq6gslr46dwcy.nar.zst error="server returned 404: 404 page not found\n"12122026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12132026/10/06 21:14:12 WARN Failed to register uploaded object key=hzc6d4nrci7fggf127kz99xbxxnsfz95.ls error="server returned 404: 404 page not found\n"12142026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12152026/10/06 21:14:12 WARN Failed to register uploaded object key=28w9jl0f82vq9qi0k3j4y1j9s5px2xfk.ls error="server returned 404: 404 page not found\n"12162026/10/06 21:14:12 INFO Signed narinfos id=1 count=112172026/10/06 21:14:12 INFO Uploading 1 narinfos12182026/10/06 21:14:12 INFO Signed narinfos id=1 count=312192026/10/06 21:14:12 INFO Uploading 3 narinfos12202026/10/06 21:14:12 INFO Received complete push request method=POST path=/api/pushes/1/complete12212026/10/06 21:14:12 WARN Failed to register uploaded object key=bp6gaccj4rpki9hcsf39myif32skz3h5.narinfo error="server returned 404: 404 page not found\n"12222026/10/06 21:14:12 WARN Failed to register uploaded object key=hzc6d4nrci7fggf127kz99xbxxnsfz95.narinfo error="server returned 404: 404 page not found\n"12232026/10/06 21:14:12 WARN Failed to register uploaded object key=7xx0bf06dpzyj9i2z6017mg394alvhwc.narinfo error="server returned 404: 404 page not found\n"12242026/10/06 21:14:12 INFO Received complete push request method=POST path=/api/pushes/1/complete12252026/10/06 21:14:12 WARN Failed to register uploaded object key=28w9jl0f82vq9qi0k3j4y1j9s5px2xfk.narinfo error="server returned 404: 404 page not found\n"12262026/10/06 21:14:12 INFO Upload complete. (63ms)12272026/10/06 21:14:12 INFO Upload complete. (61ms)1228=== NAME TestClientPushesUseOnePush1229 client_pushes_test.go:97: Retrieved narinfo from S3:1230 StorePath: /build/TestClientPushesUseOnePush2833534628/001/store/28w9jl0f82vq9qi0k3j4y1j9s5px2xfk-shared-dep1231 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1232 Compression: zstd1233 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821234 NarSize: 1361235 References: 1236 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1237 client_pushes_test.go:97: Retrieved narinfo from S3:1238 StorePath: /build/TestClientPushesUseOnePush2833534628/001/store/7xx0bf06dpzyj9i2z6017mg394alvhwc-a1239 URL: nar/1jf3ffhihlq1nkr29d3af2gi8q556jv77frh8rdvq6gslr46dwcy.nar.zst1240 Compression: zstd1241 NarHash: sha256:1jf3ffhihlq1nkr29d3af2gi8q556jv77frh8rdvq6gslr46dwcy1242 NarSize: 2161243 References: /build/TestClientPushesUseOnePush2833534628/001/store/28w9jl0f82vq9qi0k3j4y1j9s5px2xfk-shared-dep1244 CA: text:sha256:1pzbxb8f4b9y917v7r0m02h7fblrahx42bd4kab3j2ka56b8m12l1245 client_pushes_test.go:97: Retrieved narinfo from S3:1246 StorePath: /build/TestClientPushesUseOnePush2833534628/001/store/hzc6d4nrci7fggf127kz99xbxxnsfz95-b1247 URL: nar/1jf3ffhihlq1nkr29d3af2gi8q556jv77frh8rdvq6gslr46dwcy.nar.zst1248 Compression: zstd1249 NarHash: sha256:1jf3ffhihlq1nkr29d3af2gi8q556jv77frh8rdvq6gslr46dwcy1250 NarSize: 2161251 References: /build/TestClientPushesUseOnePush2833534628/001/store/28w9jl0f82vq9qi0k3j4y1j9s5px2xfk-shared-dep1252 CA: text:sha256:1pzbxb8f4b9y917v7r0m02h7fblrahx42bd4kab3j2ka56b8m12l12532026/10/06 21:14:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12542026/10/06 21:14:12 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket64/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12552026/10/06 21:14:12 INFO Aborted multipart uploads count=0 kept=11256=== NAME TestClientWithDependencies1257 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2904077562/001/store/3rkimydsqrvwlnqsbxrpk7x3lrhcqg8n-test-script1258--- PASS: TestClientPushesUseOnePush (0.66s)1259=== CONT TestService_readinessHandler12602026/10/06 21:14:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12612026/10/06 21:14:12 INFO Aborted multipart uploads count=1 kept=01262--- PASS: TestMultipartCleanup (0.53s)1263=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1264=== NAME TestClientMultipleUploads1265 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3308295426/001/store/csmhgjvrzbqfp4j3djkh98h3zdbggh46-test-file-1.txt12662026/10/06 21:14:12 INFO Received push request method=POST path=/api/pushes12672026/10/06 21:14:12 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12682026/10/06 21:14:12 INFO Uploading mz7k386gkcp8j4ivicdydiwdc0jx68x9-shared-dep (136B)12692026/10/06 21:14:12 INFO Uploading 11q712qnfn27w0382sv8qknvi6vf7w4g-top (224B)1270--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.87s)1271=== CONT TestCacheConfigHandler1272=== RUN TestCacheConfigHandler/full_config,_no_issuer1273=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1274=== RUN TestCacheConfigHandler/no_cache_url_configured1275=== PAUSE TestCacheConfigHandler/no_cache_url_configured1276=== RUN TestCacheConfigHandler/no_signing_keys1277=== PAUSE TestCacheConfigHandler/no_signing_keys1278=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1279=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1280=== CONT TestService_healthCheckHandler1281=== NAME TestClientWithDependencies1282 client_integration_test.go:615: Found 1 dependencies (including self)12832026/10/06 21:14:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40897/oidc12842026/10/06 21:14:12 WARN Failed to register uploaded object key=11q712qnfn27w0382sv8qknvi6vf7w4g.ls error="server returned 404: 404 page not found\n"12852026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/0wqn8fi04qfz2n61iwjs3b42kmxvndcb138lwm51jbx26g4ifyxj.nar.zst error="server returned 404: 404 page not found\n"12862026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12872026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12882026/10/06 21:14:12 WARN Failed to register uploaded object key=mz7k386gkcp8j4ivicdydiwdc0jx68x9.ls error="server returned 404: 404 page not found\n"12892026/10/06 21:14:12 INFO Signed narinfos id=1 count=212902026/10/06 21:14:12 INFO Uploading 2 narinfos12912026/10/06 21:14:12 INFO Received complete push request method=POST path=/api/pushes/1/complete12922026/10/06 21:14:12 WARN Failed to register uploaded object key=mz7k386gkcp8j4ivicdydiwdc0jx68x9.narinfo error="server returned 404: 404 page not found\n"12932026/10/06 21:14:12 WARN Failed to register uploaded object key=11q712qnfn27w0382sv8qknvi6vf7w4g.narinfo error="server returned 404: 404 page not found\n"12942026/10/06 21:14:12 INFO Received push request method=POST path=/api/pushes1295=== NAME TestClientIntegration1296 client_integration_test.go:286: Created store path: /build/TestClientIntegration2356476904/002/store/m49v52a88918sivkks2w1gwvqx2c513v-test-file.txt1297=== NAME TestClientMultipleUploads1298 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3308295426/001/store/is9ca0h0sn8ag2375wn60wz7jx4ws89z-test-file-2.txt1299=== NAME TestNARDeduplicationMetadataUploadBug1300 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3113717968/001/store/mfqwv4366kwqj90jlcd0f5j582xg9iyk-file1.txt13012026/10/06 21:14:12 INFO Upload complete. (156ms)13022026/10/06 21:14:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13032026/10/06 21:14:12 INFO Uploading qkhf1qgypbf68a05scjvn00if3i7hzgb-unpinned-file.txt (128B)1304=== NAME TestClientSharedPathCommittedMidPush1305 client_integration_test.go:680: Retrieved narinfo from S3:1306 StorePath: /build/TestClientSharedPathCommittedMidPush2328547279/001/store/mz7k386gkcp8j4ivicdydiwdc0jx68x9-shared-dep1307 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1308 Compression: zstd1309 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821310 NarSize: 1361311 References: 1312 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1313 client_integration_test.go:680: Retrieved narinfo from S3:1314 StorePath: /build/TestClientSharedPathCommittedMidPush2328547279/001/store/11q712qnfn27w0382sv8qknvi6vf7w4g-top1315 URL: nar/0wqn8fi04qfz2n61iwjs3b42kmxvndcb138lwm51jbx26g4ifyxj.nar.zst1316 Compression: zstd1317 NarHash: sha256:0wqn8fi04qfz2n61iwjs3b42kmxvndcb138lwm51jbx26g4ifyxj1318 NarSize: 2241319 References: /build/TestClientSharedPathCommittedMidPush2328547279/001/store/mz7k386gkcp8j4ivicdydiwdc0jx68x9-shared-dep1320 CA: text:sha256:0wam4gckh2xvn12n4k0a0l2n1ghfx3h8mr1sx6q02yh0ldz7rl2613212026/10/06 21:14:12 WARN Failed to register uploaded object key=qkhf1qgypbf68a05scjvn00if3i7hzgb.ls error="server returned 404: 404 page not found\n"13222026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13232026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13242026/10/06 21:14:12 INFO Signed narinfos id=2 count=113252026/10/06 21:14:12 INFO Uploading 1 narinfos1326=== NAME TestOrphanedObjectsGC1327 orphaned_objects_gc_test.go:287: GC Test Summary:1328 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1329 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1330 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1331 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1332 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1333--- PASS: TestOrphanedObjectsGC (0.85s)1334=== CONT TestService_AuthMiddleware_MTLSProxyHeader1335--- PASS: TestClientSharedPathCommittedMidPush (0.70s)1336=== CONT TestGracefulShutdownDrainsInflight13372026/10/06 21:14:12 INFO Starting HTTP server address=127.0.0.1:3962913382026/10/06 21:14:12 INFO Received complete push request method=POST path=/api/pushes/2/complete13392026/10/06 21:14:12 INFO Shutdown signal received, draining in-flight requests timeout=10s13402026/10/06 21:14:12 WARN Failed to register uploaded object key=qkhf1qgypbf68a05scjvn00if3i7hzgb.narinfo error="server returned 404: 404 page not found\n"13412026/10/06 21:14:12 INFO Upload complete. (124ms)13422026/10/06 21:14:12 INFO Received push request method=POST path=/api/pushes13432026/10/06 21:14:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13442026/10/06 21:14:12 INFO Uploading 3rkimydsqrvwlnqsbxrpk7x3lrhcqg8n-test-script (136B)13452026/10/06 21:14:12 INFO Received uploads request method=POST path=/api/pending_closures13462026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13472026/10/06 21:14:12 WARN Failed to register uploaded object key=3rkimydsqrvwlnqsbxrpk7x3lrhcqg8n.ls error="server returned 404: 404 page not found\n"13482026/10/06 21:14:12 WARN Failed to register uploaded object key=log/1134dkvhvjrhywqa6023pvhbik0rrn3d-test-script.drv error="server returned 404: 404 page not found\n"13492026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13502026/10/06 21:14:12 INFO Signed narinfos id=1 count=113512026/10/06 21:14:12 INFO Uploading 1 narinfos13522026/10/06 21:14:12 INFO Received complete push request method=POST path=/api/pushes/1/complete13532026/10/06 21:14:12 WARN Failed to register uploaded object key=3rkimydsqrvwlnqsbxrpk7x3lrhcqg8n.narinfo error="server returned 404: 404 page not found\n"1354--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1355=== CONT TestService_ReadScope_PublicByDefault13562026/10/06 21:14:12 INFO Received push request method=POST path=/api/pushes13572026/10/06 21:14:12 INFO Received push request method=POST path=/api/pushes13582026/10/06 21:14:12 INFO Received push request method=POST path=/api/pushes13592026/10/06 21:14:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures13602026/10/06 21:14:12 INFO Garbage collection started13612026/10/06 21:14:12 INFO Upload complete. (103ms)13622026/10/06 21:14:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13632026/10/06 21:14:12 INFO Uploading m49v52a88918sivkks2w1gwvqx2c513v-test-file.txt (152B)1364=== NAME TestClientWithDependencies1365 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2904077562/001/store) requires matching store prefix13662026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1367--- PASS: TestClientWithDependencies (0.74s)1368=== CONT TestGCTaskStore_Fail1369--- PASS: TestGCTaskStore_Fail (0.00s)1370=== CONT TestService_createPendingClosureHandler13712026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13722026/10/06 21:14:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13732026/10/06 21:14:12 WARN Failed to register uploaded object key=m49v52a88918sivkks2w1gwvqx2c513v.ls error="server returned 404: 404 page not found\n"13742026/10/06 21:14:12 INFO Signed narinfos id=1 count=113752026/10/06 21:14:12 INFO Uploading 1 narinfos13762026/10/06 21:14:12 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1377--- PASS: TestCompleteMultipartUnregistered (0.37s)1378=== CONT TestGCTaskStore_PhaseUpdates1379--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1380=== CONT TestService_RequireScope_OIDC13812026/10/06 21:14:12 INFO Received complete push request method=POST path=/api/pushes/1/complete13822026/10/06 21:14:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13832026/10/06 21:14:12 INFO Uploading mfqwv4366kwqj90jlcd0f5j582xg9iyk-file1.txt (160B)13842026/10/06 21:14:12 WARN Failed to register uploaded object key=m49v52a88918sivkks2w1gwvqx2c513v.narinfo error="server returned 404: 404 page not found\n"13852026/10/06 21:14:12 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13862026/10/06 21:14:12 INFO Uploading csmhgjvrzbqfp4j3djkh98h3zdbggh46-test-file-1.txt (160B)13872026/10/06 21:14:12 INFO Uploading srbrdya2si5arcxv4qrh790n1j1sha1a-test-file-0.txt (160B)13882026/10/06 21:14:12 INFO Uploading is9ca0h0sn8ag2375wn60wz7jx4ws89z-test-file-2.txt (160B)13892026/10/06 21:14:12 INFO Aborted multipart uploads count=0 kept=013902026/10/06 21:14:12 WARN Failed to register uploaded object key=csmhgjvrzbqfp4j3djkh98h3zdbggh46.ls error="server returned 404: 404 page not found\n"13912026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13922026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13932026/10/06 21:14:12 INFO Upload complete. (74ms)13942026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13952026/10/06 21:14:12 WARN Failed to register uploaded object key=srbrdya2si5arcxv4qrh790n1j1sha1a.ls error="server returned 404: 404 page not found\n"13962026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13972026/10/06 21:14:12 WARN Failed to register uploaded object key=mfqwv4366kwqj90jlcd0f5j582xg9iyk.ls error="server returned 404: 404 page not found\n"13982026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13992026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14002026/10/06 21:14:12 WARN Failed to register uploaded object key=is9ca0h0sn8ag2375wn60wz7jx4ws89z.ls error="server returned 404: 404 page not found\n"14012026/10/06 21:14:12 INFO Signed narinfos id=1 count=114022026/10/06 21:14:12 INFO Signed narinfos id=1 count=314032026/10/06 21:14:12 INFO Uploading 1 narinfos14042026/10/06 21:14:12 INFO Uploading 3 narinfos14052026/10/06 21:14:13 WARN Force mode enabled - objects will be deleted immediately without grace period14062026/10/06 21:14:13 WARN Failed to register uploaded object key=srbrdya2si5arcxv4qrh790n1j1sha1a.narinfo error="server returned 404: 404 page not found\n"14072026/10/06 21:14:13 WARN Failed to register uploaded object key=csmhgjvrzbqfp4j3djkh98h3zdbggh46.narinfo error="server returned 404: 404 page not found\n"14082026/10/06 21:14:13 INFO Received complete push request method=POST path=/api/pushes/1/complete14092026/10/06 21:14:13 INFO Received complete push request method=POST path=/api/pushes/1/complete14102026/10/06 21:14:13 WARN Failed to register uploaded object key=is9ca0h0sn8ag2375wn60wz7jx4ws89z.narinfo error="server returned 404: 404 page not found\n"14112026/10/06 21:14:13 WARN Failed to register uploaded object key=mfqwv4366kwqj90jlcd0f5j582xg9iyk.narinfo error="server returned 404: 404 page not found\n"14122026/10/06 21:14:13 INFO Upload complete. (93ms)1413=== NAME TestClientMultipleUploads1414 client_integration_test.go:369: Uploaded 3 paths in 124.009762ms14152026/10/06 21:14:13 INFO Upload complete. (90ms)1416=== NAME TestNARDeduplicationMetadataUploadBug1417 metadata_upload_test.go:54: Retrieved narinfo from S3:1418 StorePath: /build/TestNARDeduplicationMetadataUploadBug3113717968/001/store/mfqwv4366kwqj90jlcd0f5j582xg9iyk-file1.txt1419 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1420 Compression: zstd1421 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1422 NarSize: 1601423 References: 1424 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1425 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1426 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1427 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14282026/10/06 21:14:13 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=01429--- PASS: TestClientMultipleUploads (0.77s)1430=== CONT TestGCTaskStore_CompletedAllowsNewTask1431--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1432=== CONT TestGCEndsOnShutdown1433=== RUN TestGCEndsOnShutdown/before_the_run1434=== PAUSE TestGCEndsOnShutdown/before_the_run1435=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1436=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1437=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1438=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1439=== CONT TestSweepRechecksPendingAfterLocking1440=== NAME TestClientCADerivations1441 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1372858980/001/store/pkjg33cmsif3hxnlp0dmh2fqcl1v9lap-ca-test1442--- PASS: TestCacheStatsHandler (0.32s)1443=== CONT TestGCTaskStore_GetReturnsLatest1444--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1445=== CONT TestCommitRacingPendingCleanupKeepsObjects14462026/10/06 21:14:13 INFO Vacuumed table table=pending_closures14472026/10/06 21:14:13 INFO Vacuumed table table=pending_objects14482026/10/06 21:14:13 INFO Vacuumed table table=multipart_uploads14492026/10/06 21:14:13 INFO Vacuumed table table=closures14502026/10/06 21:14:13 INFO Vacuumed table table=objects14512026/10/06 21:14:13 INFO All 1 paths already cached1452--- PASS: TestService_ReadAuthMiddleware (0.32s)1453=== CONT TestGCTaskStore_GetEmpty1454--- PASS: TestGCTaskStore_GetEmpty (0.00s)1455=== CONT TestPushWaitsForSweepHoldingRow1456=== NAME TestClientIntegration1457 client_integration_test.go:312: Retrieved narinfo from S3:1458 StorePath: /build/TestClientIntegration2356476904/002/store/m49v52a88918sivkks2w1gwvqx2c513v-test-file.txt1459 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1460 Compression: zstd1461 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11462 NarSize: 1521463 References: 1464 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11465 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1466 client_integration_test.go:313: Decompressed .ls content (64 bytes):1467 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1468 client_integration_test.go:316: Testing garbage collection...1469=== NAME TestNARDeduplicationMetadataUploadBug1470 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3113717968/001/store/9pfjdjhikjr9c8nhi3g7wgng6lzhsbbw-file2.txt1471=== NAME TestClientCADerivations1472 client_ca_test.go:139: Found 1 dependencies (including self)14732026/10/06 21:14:13 WARN readiness check failed error="closed pool"1474--- PASS: TestService_readinessHandler (0.30s)1475=== CONT TestGCTaskStore_ConflictDifferentParams1476--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1477=== CONT TestRegisterCompletedObjectNeedsPendingRow14782026/10/06 21:14:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37445/oidc14792026/10/06 21:14:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures14802026/10/06 21:14:13 INFO Garbage collection started14812026/10/06 21:14:13 INFO Aborted multipart uploads count=0 kept=014822026/10/06 21:14:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14832026/10/06 21:14:13 WARN mTLS auth: bound subjects configured but subject DN unavailable14842026/10/06 21:14:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1485--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)1486=== CONT TestGCTaskStore_StartNew1487--- PASS: TestGCTaskStore_StartNew (0.00s)1488=== CONT TestGCTaskStore_DeduplicateSameParams1489--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1490=== CONT TestPendingClosureWriteTimeout1491=== RUN TestPendingClosureWriteTimeout/empty1492=== PAUSE TestPendingClosureWriteTimeout/empty1493=== RUN TestPendingClosureWriteTimeout/400_objects1494=== PAUSE TestPendingClosureWriteTimeout/400_objects1495=== RUN TestPendingClosureWriteTimeout/670k_objects1496=== PAUSE TestPendingClosureWriteTimeout/670k_objects1497=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1498=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1499=== CONT TestIsValidUploadKey1500=== RUN TestIsValidUploadKey/narinfo1501=== PAUSE TestIsValidUploadKey/narinfo1502=== RUN TestIsValidUploadKey/nar_zst1503=== PAUSE TestIsValidUploadKey/nar_zst1504=== RUN TestIsValidUploadKey/nar_xz1505=== PAUSE TestIsValidUploadKey/nar_xz1506=== RUN TestIsValidUploadKey/nar_plain1507=== PAUSE TestIsValidUploadKey/nar_plain1508=== RUN TestIsValidUploadKey/listing1509=== PAUSE TestIsValidUploadKey/listing1510=== RUN TestIsValidUploadKey/build_log1511=== PAUSE TestIsValidUploadKey/build_log1512=== RUN TestIsValidUploadKey/build_log_home-manager_file1513=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1514=== RUN TestIsValidUploadKey/build_log_plus_in_name1515=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1516=== RUN TestIsValidUploadKey/build_log_question_mark1517=== PAUSE TestIsValidUploadKey/build_log_question_mark1518=== RUN TestIsValidUploadKey/build_log_equals1519=== PAUSE TestIsValidUploadKey/build_log_equals1520=== RUN TestIsValidUploadKey/realisation1521=== PAUSE TestIsValidUploadKey/realisation1522=== RUN TestIsValidUploadKey/realisation_plus_in_output1523=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1524=== RUN TestIsValidUploadKey/nix-cache-info1525=== PAUSE TestIsValidUploadKey/nix-cache-info1526=== RUN TestIsValidUploadKey/index.html1527=== PAUSE TestIsValidUploadKey/index.html1528=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1529=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1530=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1531=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1532=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1533=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1534=== RUN TestIsValidUploadKey/traversal1535=== PAUSE TestIsValidUploadKey/traversal1536=== RUN TestIsValidUploadKey/traversal_nar1537=== PAUSE TestIsValidUploadKey/traversal_nar1538=== RUN TestIsValidUploadKey/absolute1539=== PAUSE TestIsValidUploadKey/absolute1540=== RUN TestIsValidUploadKey/empty_key1541=== PAUSE TestIsValidUploadKey/empty_key1542=== RUN TestIsValidUploadKey/unknown_type1543=== PAUSE TestIsValidUploadKey/unknown_type1544=== CONT TestGetExistingObjectsLocksRows15452026/10/06 21:14:13 WARN Force mode enabled - objects will be deleted immediately without grace period1546--- PASS: TestService_healthCheckHandler (0.32s)1547=== CONT TestProxyWriteTimeout/narinfo1548=== CONT TestProxyWriteTimeout/10_GiB_nar1549=== CONT TestProxyWriteTimeout/unknown_size1550=== CONT TestProxyWriteTimeout/1_GiB_nar1551--- PASS: TestProxyWriteTimeout (0.01s)1552 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1553 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1554 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1555 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1556=== CONT TestIsValidCachePath/narinfo1557=== CONT TestIsValidCachePath/wrong_extension1558=== CONT TestIsValidCachePath/leading_slash1559=== CONT TestIsValidCachePath/empty1560=== CONT TestIsValidCachePath/random_path1561=== CONT TestIsValidCachePath/invalid_char_u1562=== CONT TestIsValidCachePath/short_hash1563=== CONT TestIsValidCachePath/invalid_char_e1564=== CONT TestIsValidCachePath/traversal_in_middle1565=== CONT TestIsValidCachePath/traversal_parent1566=== CONT TestIsValidCachePath/index.html1567=== CONT TestIsValidCachePath/nix-cache-info1568=== CONT TestIsValidCachePath/realisation1569=== CONT TestIsValidCachePath/log1570=== CONT TestIsValidCachePath/ls1571=== CONT TestIsValidCachePath/nar_uncompressed1572=== CONT TestIsValidCachePath/nar_bz21573=== CONT TestIsValidCachePath/nar_xz1574=== CONT TestIsValidCachePath/nar_zst1575=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1576=== CONT TestParseSingleRange/none1577--- PASS: TestIsValidCachePath (0.00s)1578 --- PASS: TestIsValidCachePath/narinfo (0.00s)1579 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1580 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1581 --- PASS: TestIsValidCachePath/empty (0.00s)1582 --- PASS: TestIsValidCachePath/random_path (0.00s)1583 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1584 --- PASS: TestIsValidCachePath/short_hash (0.00s)1585 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1586 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1587 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1588 --- PASS: TestIsValidCachePath/index.html (0.00s)1589 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1590 --- PASS: TestIsValidCachePath/realisation (0.00s)1591 --- PASS: TestIsValidCachePath/log (0.00s)1592 --- PASS: TestIsValidCachePath/ls (0.00s)1593 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1594 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1595 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1596 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1597 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1598=== CONT TestParseSingleRange/suffix1599=== CONT TestParseSingleRange/end_clamped_to_size1600=== CONT TestParseSingleRange/open-ended1601=== CONT TestParseSingleRange/closed1602=== CONT TestParseSingleRange/malformed_end_before_start1603=== CONT TestParseSingleRange/malformed_both_empty1604=== CONT TestParseSingleRange/malformed_no_dash1605=== CONT TestParseSingleRange/multi-range_ignored1606=== CONT TestParseSingleRange/unknown_unit1607=== CONT TestParseSingleRange/start_far_past_EOF1608=== CONT TestParseSingleRange/suffix_exceeds_size1609=== CONT TestParseSingleRange/start_past_EOF1610=== CONT TestParseSingleRange/single_byte1611--- PASS: TestParseSingleRange (0.00s)1612 --- PASS: TestParseSingleRange/none (0.00s)1613 --- PASS: TestParseSingleRange/suffix (0.00s)1614 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1615 --- PASS: TestParseSingleRange/open-ended (0.00s)1616 --- PASS: TestParseSingleRange/closed (0.00s)1617 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1618 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1619 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1620 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1621 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1622 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1623 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1624 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1625 --- PASS: TestParseSingleRange/single_byte (0.00s)1626=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16272026/10/06 21:14:13 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=016282026/10/06 21:14:13 INFO Vacuumed table table=pending_closures16292026/10/06 21:14:13 INFO Vacuumed table table=pending_objects16302026/10/06 21:14:13 INFO Vacuumed table table=multipart_uploads16312026/10/06 21:14:13 INFO Received push request method=POST path=/api/pushes16322026/10/06 21:14:13 INFO Vacuumed table table=closures16332026/10/06 21:14:13 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16342026/10/06 21:14:13 INFO Vacuumed table table=objects1635=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token16362026/10/06 21:14:13 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign1637=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1638=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1639=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1640=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1641=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1642=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1643=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1644=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16452026/10/06 21:14:13 WARN Failed to register uploaded object key=9pfjdjhikjr9c8nhi3g7wgng6lzhsbbw.ls error="server returned 404: 404 page not found\n"16462026/10/06 21:14:13 INFO Signed narinfos id=2 count=116472026/10/06 21:14:13 INFO Uploading 1 narinfos16482026/10/06 21:14:13 INFO Received complete push request method=POST path=/api/pushes/2/complete16492026/10/06 21:14:13 WARN Failed to register uploaded object key=9pfjdjhikjr9c8nhi3g7wgng6lzhsbbw.narinfo error="server returned 404: 404 page not found\n"16502026/10/06 21:14:13 INFO Upload complete. (59ms)1651=== NAME TestNARDeduplicationMetadataUploadBug1652 metadata_upload_test.go:76: Retrieved narinfo from S3:1653 StorePath: /build/TestNARDeduplicationMetadataUploadBug3113717968/001/store/9pfjdjhikjr9c8nhi3g7wgng6lzhsbbw-file2.txt1654 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1655 Compression: zstd1656 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1657 NarSize: 1601658 References: 1659 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1660 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1661 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1662 {"version":1,"root":{"type":"regular","size":44}}1663--- PASS: TestNARDeduplicationMetadataUploadBug (0.70s)1664=== CONT TestPush_RejectsBadRequests/root_not_in_objects16652026/10/06 21:14:13 INFO Received push request method=POST path=/api/pushes1666=== CONT TestPush_RejectsBadRequests/no_objects16672026/10/06 21:14:13 INFO Received push request method=POST path=/api/pushes1668=== CONT TestPush_RejectsBadRequests/bad_root16692026/10/06 21:14:13 INFO Received push request method=POST path=/api/pushes1670=== CONT TestPush_RejectsBadRequests/no_roots16712026/10/06 21:14:13 INFO Received push request method=POST path=/api/pushes1672=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1673--- PASS: TestPush_RejectsBadRequests (0.78s)1674 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1675 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1676 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1677 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)16782026/10/06 21:14:13 INFO Received push request method=POST path=/api/pushes1679--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.26s)1680=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16812026/10/06 21:14:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16822026/10/06 21:14:13 INFO Uploading pkjg33cmsif3hxnlp0dmh2fqcl1v9lap-ca-test (144B)16832026/10/06 21:14:13 WARN Failed to register uploaded object key=pkjg33cmsif3hxnlp0dmh2fqcl1v9lap.ls error="server returned 404: 404 page not found\n"16842026/10/06 21:14:13 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16852026/10/06 21:14:13 WARN Failed to register uploaded object key=log/gj02lpq1kad6f7fl54a1pqy43cy0yi36-ca-test.drv error="server returned 404: 404 page not found\n"16862026/10/06 21:14:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16872026/10/06 21:14:13 INFO Signed narinfos id=1 count=116882026/10/06 21:14:13 INFO Uploading 1 narinfos16892026/10/06 21:14:13 INFO Received complete push request method=POST path=/api/pushes/1/complete16902026/10/06 21:14:13 WARN Failed to register uploaded object key=pkjg33cmsif3hxnlp0dmh2fqcl1v9lap.narinfo error="server returned 404: 404 page not found\n"16912026/10/06 21:14:13 INFO Upload complete. (100ms)1692--- PASS: TestService_ReadScope_PublicByDefault (0.22s)1693=== CONT TestResolveDBConnectionString/flag_wins1694=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1695=== CONT TestResolveDBConnectionString/missing_file_is_an_error1696=== CONT TestResolveDBConnectionString/file_when_flag_empty1697=== CONT TestResolveDBConnectionString/nothing_configured1698=== NAME TestClientCADerivations1699 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1372858980/001/store/pkjg33cmsif3hxnlp0dmh2fqcl1v9lap-ca-test1700 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1701 Compression: zstd1702 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1703 NarSize: 1441704 References: 1705 Deriver: /build/TestClientCADerivations1372858980/001/store/gj02lpq1kad6f7fl54a1pqy43cy0yi36-ca-test.drv1706 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1707 client_ca_test.go:185: Checking for realisation files in S3...1708--- PASS: TestResolveDBConnectionString (0.00s)1709 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1710 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1711 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1712 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1713 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1714=== CONT TestServerTLSConfig/no_client_CA1715=== CONT TestServerTLSConfig/not_a_PEM_file1716=== CONT TestServerTLSConfig/missing_CA_file1717--- PASS: TestServerTLSConfig (0.00s)1718 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1719 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1720 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1721=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17222026/10/06 21:14:13 INFO Received uploads request method=POST path=/1723=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17242026/10/06 21:14:13 INFO Received complete multipart upload request method=POST path=/1725=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17262026/10/06 21:14:13 INFO Received uploads request method=POST path=/1727=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17282026/10/06 21:14:13 INFO Received request for more parts method=POST path=/1729--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1730 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1731 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1732 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1733 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1734=== CONT TestClientErrorHandling/InvalidStorePath1735=== NAME TestClientCADerivations1736 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1737 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17382026/10/06 21:14:13 INFO Received uploads request method=POST path=/api/pending_closures17392026/10/06 21:14:13 INFO Received uploads request method=POST path=/api/pending_closures17402026/10/06 21:14:13 INFO Received uploads request method=POST path=/api/pending_closures17412026/10/06 21:14:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17422026/10/06 21:14:13 INFO Aborted multipart uploads count=0 kept=017432026/10/06 21:14:13 WARN Force mode enabled - objects will be deleted immediately without grace period17442026/10/06 21:14:13 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OGM5YmE0YWMtM2MxMi00M2VmLThmOWItOTYyMWVjMjEyZWFlLmExNjU0MWIwLWJkYzQtNDQ1Yy05YWZhLTc1OTI0OTQ3YzU4MngxNzkxMzIxMjUyOTI0MDk1OTQ3 parts=1017452026/10/06 21:14:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17462026/10/06 21:14:13 INFO Aborted multipart uploads count=0 kept=017472026/10/06 21:14:13 INFO Completed upload id=117482026/10/06 21:14:13 INFO Received uploads request method=POST path=/api/pending_closures17492026/10/06 21:14:13 INFO Received uploads request method=POST path=/api/pending_closures17502026/10/06 21:14:13 WARN Force mode enabled - objects will be deleted immediately without grace period17512026/10/06 21:14:13 INFO Received uploads request method=POST path=/api/pending_closures1752 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1753 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1754 error: binary cache 's3://bucket71?endpoint=http://localhost:37751®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1372858980/001/store'1755 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117562026/10/06 21:14:13 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=01757--- PASS: TestClientCADerivations (0.76s)1758=== CONT TestClientErrorHandling/InvalidAuthToken17592026/10/06 21:14:13 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=017602026/10/06 21:14:13 INFO Vacuumed table table=pending_closures17612026/10/06 21:14:13 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17622026/10/06 21:14:13 WARN Found objects in DB but missing from S3, will re-upload count=11763--- PASS: TestService_verifyS3Integrity (0.77s)1764=== CONT TestClientErrorHandling/ServerNotAvailable17652026/10/06 21:14:13 INFO Vacuumed table table=pending_objects17662026/10/06 21:14:13 INFO Vacuumed table table=pending_closures17672026/10/06 21:14:13 INFO Vacuumed table table=multipart_uploads17682026/10/06 21:14:13 INFO Vacuumed table table=closures17692026/10/06 21:14:13 INFO Vacuumed table table=objects17702026/10/06 21:14:13 INFO Vacuumed table table=pending_objects17712026/10/06 21:14:13 INFO Vacuumed table table=multipart_uploads17722026/10/06 21:14:13 INFO Vacuumed table table=closures17732026/10/06 21:14:13 INFO Vacuumed table table=objects1774--- PASS: TestSweepRechecksPendingAfterLocking (0.28s)1775=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17762026/10/06 21:14:13 INFO Received uploads request method=POST path=/1777--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.28s)1778=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17792026/10/06 21:14:13 INFO Received complete multipart upload request method=POST path=/1780--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.24s)1781=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17822026/10/06 21:14:13 INFO Received request for more parts method=POST path=/17832026/10/06 21:14:13 INFO lead: released remote=192.0.2.1:12341784--- PASS: TestLeadEndsOnShutdown (1.56s)1785=== CONT TestCacheConfigHandler/full_config,_no_issuer1786=== CONT TestCacheConfigHandler/no_signing_keys1787=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1788=== CONT TestCacheConfigHandler/no_cache_url_configured1789--- PASS: TestCacheConfigHandler (0.00s)1790 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1791 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1792 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1793 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1794=== CONT TestGCEndsOnShutdown/before_the_run1795=== RUN TestService_RequireScope_OIDC/builder_may_write1796=== PAUSE TestService_RequireScope_OIDC/builder_may_write1797=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1798=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1799=== RUN TestService_RequireScope_OIDC/ops_may_admin1800=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1801=== RUN TestService_RequireScope_OIDC/ops_may_not_write1802=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1803=== RUN TestService_RequireScope_OIDC/reader_may_not_write1804=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1805=== RUN TestService_RequireScope_OIDC/static_token_may_admin1806=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1807=== RUN TestService_RequireScope_OIDC/static_token_may_write1808=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1809=== RUN TestService_RequireScope_OIDC/reader_may_read1810=== PAUSE TestService_RequireScope_OIDC/reader_may_read1811=== RUN TestService_RequireScope_OIDC/writer_implies_read1812=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1813=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1814=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1815=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1816=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1817=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1818=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1819=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1820=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1821=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1822=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1823=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1824=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1825--- PASS: TestGetExistingObjectsLocksRows (0.27s)1826=== CONT TestPendingClosureWriteTimeout/empty1827=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1828=== CONT TestPendingClosureWriteTimeout/670k_objects1829=== CONT TestPendingClosureWriteTimeout/400_objects1830=== CONT TestIsValidUploadKey/narinfo1831=== CONT TestIsValidUploadKey/index.html1832=== CONT TestIsValidUploadKey/nix-cache-info1833=== CONT TestIsValidUploadKey/realisation_plus_in_output1834=== CONT TestIsValidUploadKey/realisation1835=== CONT TestIsValidUploadKey/build_log_equals1836=== CONT TestIsValidUploadKey/build_log_question_mark1837=== CONT TestIsValidUploadKey/build_log_plus_in_name1838=== CONT TestIsValidUploadKey/build_log_home-manager_file1839=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1840=== CONT TestIsValidUploadKey/build_log1841=== CONT TestIsValidUploadKey/listing1842=== CONT TestIsValidUploadKey/nar_plain1843=== CONT TestIsValidUploadKey/nar_xz1844=== CONT TestIsValidUploadKey/nar_zst1845=== CONT TestIsValidUploadKey/traversal_nar1846=== CONT TestIsValidUploadKey/unknown_type1847=== CONT TestIsValidUploadKey/empty_key1848=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1849=== CONT TestIsValidUploadKey/absolute1850=== CONT TestIsValidUploadKey/traversal1851=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1852=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1853--- PASS: TestIsValidUploadKey (0.00s)1854 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1855 --- PASS: TestIsValidUploadKey/index.html (0.00s)1856 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1857 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1858 --- PASS: TestIsValidUploadKey/realisation (0.00s)1859 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1860 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1861 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1862 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1863 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1864 --- PASS: TestIsValidUploadKey/build_log (0.00s)1865 --- PASS: TestIsValidUploadKey/listing (0.00s)1866 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1867 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1868 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1869 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1870 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1871 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1872 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1873 --- PASS: TestIsValidUploadKey/absolute (0.00s)1874 --- PASS: TestIsValidUploadKey/traversal (0.00s)1875 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1876=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18772026/10/06 21:14:13 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]1878=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1879=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18802026/10/06 21:14:13 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/present18812026/10/06 21:14:13 WARN Authentication failed token_preview=eyJhbGciOi...qAYOrmmYtA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1882=== CONT TestService_RequireScope_OIDC/builder_may_write1883--- PASS: TestService_AuthMiddleware_OIDC (0.40s)1884 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1885 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1886 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1887 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1888=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1889=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18902026/10/06 21:14:13 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]1891=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1892=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1893=== CONT TestService_RequireScope_OIDC/writer_implies_read1894=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1895=== CONT TestService_RequireScope_OIDC/reader_may_not_write1896=== CONT TestService_RequireScope_OIDC/static_token_may_write1897=== CONT TestService_RequireScope_OIDC/static_token_may_admin1898=== CONT TestService_RequireScope_OIDC/ops_may_admin1899=== CONT TestService_RequireScope_OIDC/ops_may_not_write1900=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1901=== CONT TestService_RequireScope_OIDC/reader_may_read1902--- PASS: TestService_RequireScope_OIDC (0.36s)1903 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1907 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1908 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1909 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1910 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1911 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1912 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1913 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1914 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1915 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1916 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)19172026/10/06 21:14:13 INFO Received uploads request method=POST path=/api/pending_closures19182026/10/06 21:14:13 INFO Aborted multipart uploads count=0 kept=019192026/10/06 21:14:13 WARN Force mode enabled - objects will be deleted immediately without grace period19202026/10/06 21:14:13 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=019212026/10/06 21:14:13 INFO Vacuumed table table=pending_closures19222026/10/06 21:14:13 INFO Vacuumed table table=pending_objects19232026/10/06 21:14:13 INFO Received uploads request method=POST path=/api/pending_closures19242026/10/06 21:14:13 INFO Vacuumed table table=multipart_uploads19252026/10/06 21:14:13 INFO Vacuumed table table=closures19262026/10/06 21:14:13 INFO Vacuumed table table=objects19272026/10/06 21:14:13 INFO Aborted multipart uploads count=0 kept=019282026/10/06 21:14:13 WARN Force mode enabled - objects will be deleted immediately without grace period19292026/10/06 21:14:13 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=019302026/10/06 21:14:13 INFO Vacuumed table table=pending_closures19312026/10/06 21:14:13 INFO Vacuumed table table=pending_objects19322026/10/06 21:14:13 INFO Vacuumed table table=multipart_uploads19332026/10/06 21:14:13 INFO Vacuumed table table=closures19342026/10/06 21:14:13 INFO Vacuumed table table=objects1935--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1936 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.32s)1937 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.31s)19382026/10/06 21:14:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.682893ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19392026/10/06 21:14:13 INFO lead: released remote=192.0.2.1:123419402026/10/06 21:14:13 INFO lead: acquired remote=192.0.2.1:123419412026/10/06 21:14:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19422026/10/06 21:14:13 INFO Aborted multipart uploads count=0 kept=019432026/10/06 21:14:13 WARN Force mode enabled - objects will be deleted immediately without grace period19442026-10-06 21:14:13.554 UTC [1809] ERROR: canceling statement due to user request19452026-10-06 21:14:13.554 UTC [1809] CONTEXT: PL/pgSQL expression "0"1946 PL/pgSQL function object_stats_apply() line 3 during statement block local variable initialization19472026-10-06 21:14:13.554 UTC [1809] STATEMENT: -- name: MarkStaleObjects :execrows1948 WITH RECURSIVE ct AS (1949 SELECT timezone('UTC', now()) AS now1950 ),1951 closure_reach AS (1952 -- Start with all closure keys1953 SELECT o.key, o.refs1954 FROM objects o1955 INNER JOIN closures c ON o.key = c.key1956 UNION1957 -- Recursively add all referenced objects1958 SELECT o.key, o.refs1959 FROM objects o1960 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1961 ),1962 reachable_objects AS (1963 SELECT DISTINCT key FROM closure_reach1964 ),1965 stale_objects AS (1966 SELECT o.key1967 FROM objects AS o, ct1968 WHERE1969 NOT EXISTS (1970 SELECT 11971 FROM reachable_objects ro1972 WHERE ro.key = o.key1973 )1974 AND NOT EXISTS (1975 SELECT 11976 FROM pending_objects AS po1977 WHERE po.key = o.key1978 )1979 AND o.deleted_at IS NULL -- Only mark fresh objects1980 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1981 FOR UPDATE1982 )1983 UPDATE objects1984 SET1985 deleted_at = ct.now,1986 first_deleted_at = COALESCE(first_deleted_at, ct.now)1987 FROM stale_objects, ct1988 WHERE objects.key = stale_objects.key1989 19902026/10/06 21:14:13 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OGM5YmE0YWMtM2MxMi00M2VmLThmOWItOTYyMWVjMjEyZWFlLjM1ZGYyMDBiLTA1YWMtNDgxYy04ZWY2LTMxNDViYTg3OGE4ZngxNzkxMzIxMjUzMjE4Njc4MjU4 parts=1019912026/10/06 21:14:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19922026/10/06 21:14:13 INFO Aborted multipart uploads count=0 kept=019932026/10/06 21:14:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19942026/10/06 21:14:13 INFO Completed upload id=119952026/10/06 21:14:13 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000019962026/10/06 21:14:13 INFO Received uploads request method=POST path=/api/pending_closures19972026/10/06 21:14:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures19982026/10/06 21:14:13 WARN Force mode enabled - objects will be deleted immediately without grace period19992026/10/06 21:14:13 INFO Received uploads request method=POST path=/api/pending_closures20002026/10/06 21:14:13 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37751/bucket97/?delete=\": context canceled"20012026/10/06 21:14:13 INFO Aborted multipart uploads count=0 kept=02002--- PASS: TestGCEndsOnShutdown (0.00s)2003 --- PASS: TestGCEndsOnShutdown/before_the_run (0.18s)2004 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.21s)2005 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.22s)20062026/10/06 21:14:13 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=020072026/10/06 21:14:13 INFO Vacuumed table table=pending_closures20082026/10/06 21:14:13 INFO Vacuumed table table=pending_objects20092026/10/06 21:14:13 INFO Vacuumed table table=multipart_uploads20102026/10/06 21:14:13 INFO Vacuumed table table=closures20112026/10/06 21:14:13 INFO Vacuumed table table=objects20122026/10/06 21:14:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20132026/10/06 21:14:13 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002014--- PASS: TestService_createPendingClosureHandler (0.63s)2015--- PASS: TestDeleteClosuresRacingPins (1.63s)20162026/10/06 21:14:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=392.755232ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2017--- PASS: TestPushWaitsForSweepHoldingRow (0.75s)2018=== NAME TestOrphanedObjectsGCStressTest2019 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2020--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2021 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.77s)2022 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.79s)2023=== NAME TestOrphanedObjectsGCStressTest2024 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20252026/10/06 21:14:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=764.638792ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2026 orphaned_objects_gc_test.go:503: Stress test completed successfully:2027 orphaned_objects_gc_test.go:504: - Active objects preserved: 202028 orphaned_objects_gc_test.go:505: - Objects deleted: 2102029 orphaned_objects_gc_test.go:506: - Total GC'd: 2102030--- PASS: TestOrphanedObjectsGCStressTest (2.20s)2031--- PASS: TestPendingClosureWriteTimeout (0.00s)2032 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2033 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2034 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2035 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.02s)2036--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2037 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2038 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2039 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.12s)20402026/10/06 21:14:14 INFO lead: released remote=192.0.2.1:12342041--- PASS: TestLeadElectsOneAndHandsOver (2.81s)20422026/10/06 21:14:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.749946626s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20432026/10/06 21:14:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020442026/10/06 21:14:14 INFO Received create pin request method=POST path=/api/pins/myapp20452026/10/06 21:14:14 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3214984705/001/store/bp6gaccj4rpki9hcsf39myif32skz3h5-pinned-file.txt narinfo_key=bp6gaccj4rpki9hcsf39myif32skz3h5.narinfo20462026/10/06 21:14:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures20472026/10/06 21:14:14 INFO Garbage collection started20482026/10/06 21:14:14 INFO Aborted multipart uploads count=0 kept=020492026/10/06 21:14:14 WARN Force mode enabled - objects will be deleted immediately without grace period20502026/10/06 21:14:14 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=020512026/10/06 21:14:14 INFO Vacuumed table table=pending_closures20522026/10/06 21:14:14 INFO Vacuumed table table=pending_objects20532026/10/06 21:14:14 INFO Vacuumed table table=multipart_uploads20542026/10/06 21:14:14 INFO Vacuumed table table=closures20552026/10/06 21:14:14 INFO Vacuumed table table=objects20562026/10/06 21:14:15 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02057=== NAME TestClientIntegration2058 client_integration_test.go:323: Objects in database after GC:2059 client_integration_test.go:323: Successfully deleted all objects with GC --force2060--- PASS: TestClientIntegration (2.76s)2061--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.94s)20622026/10/06 21:14:16 WARN Rate limiter enabled after throttle name=s3-test rate=520632026/10/06 21:14:16 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2064=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2065 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102066 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002067--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.50s)20682026/10/06 21:14:16 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-config20692026/10/06 21:14:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.040768ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20702026/10/06 21:14:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.910369ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2071=== NAME TestPinProtectsFromGC2072 client_integration_test.go:840: Pin successfully protected closure from garbage collection2073--- PASS: TestPinProtectsFromGC (4.83s)2074--- PASS: TestConnectWaitsForAPeerMigration (5.13s)20752026/10/06 21:14:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=875.489625ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20762026/10/06 21:14:18 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.725942874s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20772026/10/06 21:14:18 INFO Aborted multipart uploads count=1 kept=020782026/10/06 21:14:18 INFO Received cleanup request method=DELETE path=/api/pending_closures20792026/10/06 21:14:18 INFO Aborted multipart uploads count=1 kept=02080--- PASS: TestPendingCleanupUsesOneCutoff (6.48s)20812026/10/06 21:14:19 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"20822026/10/06 21:14:19 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-config20832026/10/06 21:14:20 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.87243ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20842026/10/06 21:14:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=399.954415ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20852026/10/06 21:14:20 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=874.075273ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20862026/10/06 21:14:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.498070605s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20872026/10/06 21:14:23 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_closures20882026/10/06 21:14:23 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.676167ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20892026/10/06 21:14:23 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=432.984183ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20902026/10/06 21:14:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=871.29558ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20912026/10/06 21:14:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.517936424s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2092--- PASS: TestClientErrorHandling (0.00s)2093 --- PASS: TestClientErrorHandling/InvalidStorePath (0.31s)2094 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.30s)2095 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.86s)2096PASS20972026-10-06 21:14:26.392 UTC [129] LOG: received smart shutdown request20982026-10-06 21:14:26.397 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120992026-10-06 21:14:26.409 UTC [134] LOG: shutting down21002026-10-06 21:14:26.409 UTC [134] LOG: checkpoint starting: shutdown immediate21012026-10-06 21:14:27.317 UTC [134] LOG: checkpoint complete: wrote 10925 buffers (66.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.186 s, sync=0.690 s, total=0.909 s; sync files=33373, longest=0.002 s, average=0.001 s; distance=484072 kB, estimate=484072 kB; lsn=0/1F01FCF0, redo lsn=0/1F01FCF021022026-10-06 21:14:27.396 UTC [129] LOG: database system is shut down2103Running OIDC tests...2104=== RUN TestAudienceForIssuer2105=== PAUSE TestAudienceForIssuer2106=== RUN TestGlobMatch2107=== PAUSE TestGlobMatch2108=== RUN TestValidateToken_ValidToken2109=== PAUSE TestValidateToken_ValidToken2110=== RUN TestValidateToken_WrongAudience2111=== PAUSE TestValidateToken_WrongAudience2112=== RUN TestValidateToken_Expired2113=== PAUSE TestValidateToken_Expired2114=== RUN TestValidateToken_BoundClaimsMismatch2115=== PAUSE TestValidateToken_BoundClaimsMismatch2116=== RUN TestValidateToken_BoundSubjectMismatch2117=== PAUSE TestValidateToken_BoundSubjectMismatch2118=== RUN TestValidateToken_MultipleProviders2119=== PAUSE TestValidateToken_MultipleProviders2120=== RUN TestValidateToken_NoMatchingProvider2121=== PAUSE TestValidateToken_NoMatchingProvider2122=== RUN TestValidateToken_KubernetesServiceAccount2123=== PAUSE TestValidateToken_KubernetesServiceAccount2124=== RUN TestNewValidator_KubernetesRequiresCA2125=== PAUSE TestNewValidator_KubernetesRequiresCA2126=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2127=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2128=== RUN TestPins_ReservedForMatchingRule2129=== PAUSE TestPins_ReservedForMatchingRule2130=== RUN TestPins_TopLevelShorthand2131=== PAUSE TestPins_TopLevelShorthand2132=== RUN TestPins_ConfigValidation2133=== PAUSE TestPins_ConfigValidation2134=== RUN TestScopes_LegacyProviderDefaultsToWrite2135=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2136=== RUN TestScopes_Rules2137=== PAUSE TestScopes_Rules2138=== RUN TestScopes_ConfigValidation2139=== PAUSE TestScopes_ConfigValidation2140=== CONT TestAudienceForIssuer2141=== CONT TestValidateToken_BoundClaimsMismatch2142--- PASS: TestAudienceForIssuer (0.00s)2143=== CONT TestValidateToken_KubernetesServiceAccount2144=== CONT TestValidateToken_MultipleProviders2145=== CONT TestValidateToken_Expired2146=== CONT TestValidateToken_WrongAudience2147=== CONT TestValidateToken_ValidToken2148=== CONT TestGlobMatch2149=== RUN TestGlobMatch/foo_foo2150=== PAUSE TestGlobMatch/foo_foo2151=== RUN TestGlobMatch/foo_bar2152=== PAUSE TestGlobMatch/foo_bar2153=== RUN TestGlobMatch/*_2154=== PAUSE TestGlobMatch/*_2155=== RUN TestGlobMatch/*_anything2156=== PAUSE TestGlobMatch/*_anything2157=== RUN TestGlobMatch/foo*_foo2158=== PAUSE TestGlobMatch/foo*_foo2159=== RUN TestGlobMatch/foo*_foobar2160=== PAUSE TestGlobMatch/foo*_foobar2161=== CONT TestValidateToken_BoundSubjectMismatch2162=== CONT TestValidateToken_NoMatchingProvider2163=== CONT TestPins_ConfigValidation2164=== CONT TestScopes_ConfigValidation2165=== CONT TestScopes_Rules2166=== CONT TestScopes_LegacyProviderDefaultsToWrite2167=== CONT TestPins_ReservedForMatchingRule2168=== CONT TestPins_TopLevelShorthand2169=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2170=== CONT TestNewValidator_KubernetesRequiresCA2171=== RUN TestGlobMatch/foo*_bar2172=== PAUSE TestGlobMatch/foo*_bar2173=== RUN TestGlobMatch/*bar_bar2174=== PAUSE TestGlobMatch/*bar_bar2175=== RUN TestGlobMatch/*bar_foobar2176=== PAUSE TestGlobMatch/*bar_foobar2177=== RUN TestGlobMatch/*bar_foo2178=== PAUSE TestGlobMatch/*bar_foo2179=== RUN TestGlobMatch/foo*bar_foobar2180=== PAUSE TestGlobMatch/foo*bar_foobar2181=== RUN TestGlobMatch/foo*bar_foo123bar2182=== PAUSE TestGlobMatch/foo*bar_foo123bar2183=== RUN TestGlobMatch/foo*bar_foobarbaz2184=== PAUSE TestGlobMatch/foo*bar_foobarbaz2185=== RUN TestGlobMatch/*/*_foo/bar2186=== PAUSE TestGlobMatch/*/*_foo/bar2187=== RUN TestGlobMatch/*/*_foo2188=== PAUSE TestGlobMatch/*/*_foo2189=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2190=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2191=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02192=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02193=== RUN TestGlobMatch/refs/*/main_refs/heads/main2194=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2195=== RUN TestGlobMatch/fo?_foo2196=== PAUSE TestGlobMatch/fo?_foo2197=== RUN TestGlobMatch/fo?_fo2198=== PAUSE TestGlobMatch/fo?_fo2199=== RUN TestGlobMatch/fo?_fooo2200=== PAUSE TestGlobMatch/fo?_fooo2201=== RUN TestGlobMatch/?oo_foo2202=== PAUSE TestGlobMatch/?oo_foo2203=== RUN TestGlobMatch/?oo_boo2204=== PAUSE TestGlobMatch/?oo_boo2205=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2206=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2207=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2208=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2209=== CONT TestGlobMatch/foo_foo2210=== CONT TestGlobMatch/*/*_foo2211--- PASS: TestScopes_ConfigValidation (0.00s)2212=== CONT TestGlobMatch/?oo_foo2213=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2214=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2215=== CONT TestGlobMatch/?oo_boo2216=== CONT TestGlobMatch/fo?_foo2217=== CONT TestGlobMatch/fo?_fooo2218=== CONT TestGlobMatch/fo?_fo2219=== CONT TestGlobMatch/foo*bar_foo123bar2220=== CONT TestGlobMatch/*/*_foo/bar2221=== CONT TestGlobMatch/foo*bar_foobarbaz2222=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02223=== CONT TestGlobMatch/refs/*/main_refs/heads/main2224=== CONT TestGlobMatch/*bar_bar2225=== CONT TestGlobMatch/*bar_foobar2226=== CONT TestGlobMatch/foo_bar2227=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2228=== CONT TestGlobMatch/*bar_foo2229=== CONT TestGlobMatch/foo*bar_foobar2230=== CONT TestGlobMatch/foo*_foo2231=== CONT TestGlobMatch/foo*_bar2232=== CONT TestGlobMatch/foo*_foobar2233=== CONT TestGlobMatch/*_2234=== CONT TestGlobMatch/*_anything2235--- PASS: TestGlobMatch (0.00s)2236 --- PASS: TestGlobMatch/foo_foo (0.00s)2237 --- PASS: TestGlobMatch/*/*_foo (0.00s)2238 --- PASS: TestGlobMatch/?oo_foo (0.00s)2239 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2240 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2241 --- PASS: TestGlobMatch/?oo_boo (0.00s)2242 --- PASS: TestGlobMatch/fo?_foo (0.00s)2243 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2244 --- PASS: TestGlobMatch/fo?_fo (0.00s)2245 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2246 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2247 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2248 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2249 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2250 --- PASS: TestGlobMatch/*bar_bar (0.00s)2251 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2252 --- PASS: TestGlobMatch/foo_bar (0.00s)2253 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2254 --- PASS: TestGlobMatch/*bar_foo (0.00s)2255 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2256 --- PASS: TestGlobMatch/foo*_foo (0.00s)2257 --- PASS: TestGlobMatch/foo*_bar (0.00s)2258 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2259 --- PASS: TestGlobMatch/*_ (0.00s)2260 --- PASS: TestGlobMatch/*_anything (0.00s)2261--- PASS: TestPins_ConfigValidation (0.00s)22622026/10/06 21:14:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33879/oidc2263--- PASS: TestValidateToken_Expired (0.04s)22642026/10/06 21:14:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42957/oidc2265--- PASS: TestPins_TopLevelShorthand (0.07s)22662026/10/06 21:14:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43709/oidc22672026/10/06 21:14:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44105/oidc2268--- PASS: TestValidateToken_ValidToken (0.08s)2269--- PASS: TestValidateToken_WrongAudience (0.08s)22702026/10/06 21:14:29 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4412722712026/10/06 21:14:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44485/oidc2272--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.08s)2273--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)22742026/10/06 21:14:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35395/oidc2275--- PASS: TestValidateToken_BoundSubjectMismatch (0.13s)22762026/10/06 21:14:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40711/oidc2277--- PASS: TestValidateToken_NoMatchingProvider (0.14s)22782026/10/06 21:14:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34249/oidc2279--- PASS: TestValidateToken_BoundClaimsMismatch (0.16s)22802026/10/06 21:14:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41269/oidc22812026/10/06 21:14:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35785/oidc22822026/10/06 21:14:29 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35889/oidc2283--- PASS: TestPins_ReservedForMatchingRule (0.22s)2284--- PASS: TestValidateToken_MultipleProviders (0.22s)22852026/10/06 21:14:29 http: TLS handshake error from 127.0.0.1:48958: remote error: tls: bad certificate2286--- PASS: TestNewValidator_KubernetesRequiresCA (0.22s)22872026/10/06 21:14:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35427/oidc2288--- PASS: TestScopes_Rules (0.23s)22892026/10/06 21:14:29 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232290--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.34s)2291PASS2292Running hook tests...2293=== RUN TestSendPathsEmpty2294=== PAUSE TestSendPathsEmpty2295=== RUN TestQueueEnqueueAndFetch2296=== PAUSE TestQueueEnqueueAndFetch2297=== RUN TestQueueDeduplication2298=== PAUSE TestQueueDeduplication2299=== RUN TestQueueRemove2300=== PAUSE TestQueueRemove2301=== RUN TestQueueFetchBatchLimit2302=== PAUSE TestQueueFetchBatchLimit2303=== RUN TestQueueRetryMovesToBack2304=== PAUSE TestQueueRetryMovesToBack2305=== RUN TestQueueFetchRemoveLifecycle2306=== PAUSE TestQueueFetchRemoveLifecycle2307=== RUN TestQueueConcurrentWriters2308=== PAUSE TestQueueConcurrentWriters2309=== RUN TestQueueRemoveLargeClosure2310=== PAUSE TestQueueRemoveLargeClosure2311=== RUN TestServerClientIntegration2312=== PAUSE TestServerClientIntegration2313=== RUN TestServerQueueError2314=== PAUSE TestServerQueueError2315=== RUN TestGetListenerSocketActivation2316 server_test.go:210: === RUN TestGetListenerSocketActivation2317 --- PASS: TestGetListenerSocketActivation (0.00s)2318 PASS2319 2320--- PASS: TestGetListenerSocketActivation (0.01s)2321=== RUN TestDrainIsolatesPoisonPath2322=== PAUSE TestDrainIsolatesPoisonPath2323=== RUN TestRunNotBlockedByPoisonHead2324=== PAUSE TestRunNotBlockedByPoisonHead2325=== RUN TestDrainGivesUpWhenServerDown2326=== PAUSE TestDrainGivesUpWhenServerDown2327=== RUN TestFailedPathPrunedByLaterClosure2328=== PAUSE TestFailedPathPrunedByLaterClosure2329=== RUN TestWorkerUploadsAndRemoves2330=== PAUSE TestWorkerUploadsAndRemoves2331=== RUN TestWorkerSkipsGCdPaths2332=== PAUSE TestWorkerSkipsGCdPaths2333=== RUN TestWorkerPrunesClosureDeps2334=== PAUSE TestWorkerPrunesClosureDeps2335=== RUN TestDrainTimeout2336=== PAUSE TestDrainTimeout2337=== CONT TestSendPathsEmpty2338--- PASS: TestSendPathsEmpty (0.00s)2339=== CONT TestWorkerSkipsGCdPaths2340=== CONT TestDrainTimeout2341=== CONT TestDrainGivesUpWhenServerDown2342=== CONT TestRunNotBlockedByPoisonHead2343=== CONT TestDrainIsolatesPoisonPath2344=== CONT TestServerQueueError2345=== CONT TestServerClientIntegration2346=== CONT TestQueueRemoveLargeClosure2347=== CONT TestQueueConcurrentWriters2348=== CONT TestQueueFetchRemoveLifecycle2349=== CONT TestQueueRetryMovesToBack23502026/10/06 21:14:29 ERROR Failed to queue paths error="permission denied" count=12351=== CONT TestQueueFetchBatchLimit2352=== CONT TestQueueRemove2353=== CONT TestQueueDeduplication2354=== CONT TestQueueEnqueueAndFetch2355=== CONT TestFailedPathPrunedByLaterClosure2356=== CONT TestWorkerUploadsAndRemoves2357=== CONT TestWorkerPrunesClosureDeps2358--- PASS: TestServerQueueError (0.00s)2359--- PASS: TestServerClientIntegration (0.00s)23602026/10/06 21:14:29 INFO Upload queue status pending=223612026/10/06 21:14:29 INFO Uploading batch count=123622026/10/06 21:14:29 INFO Upload queue status pending=223632026/10/06 21:14:29 INFO Uploading batch count=423642026/10/06 21:14:29 ERROR Upload failed error="upload failed" count=423652026/10/06 21:14:29 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1127060546/002/nonexistent23662026/10/06 21:14:29 INFO Upload queue status pending=223672026/10/06 21:14:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath569004364/002/bbb23682026/10/06 21:14:29 INFO Uploading batch count=223692026/10/06 21:14:29 INFO Uploading batch count=223702026/10/06 21:14:29 INFO Uploading batch count=223712026/10/06 21:14:29 ERROR Upload failed error="upload failed" count=223722026/10/06 21:14:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3787587502/002/a23732026/10/06 21:14:29 INFO Uploading batch count=123742026/10/06 21:14:29 INFO Uploading batch count=123752026/10/06 21:14:29 ERROR Upload failed error="upload failed" count=12376--- PASS: TestQueueEnqueueAndFetch (0.01s)23772026/10/06 21:14:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3787587502/002/b23782026/10/06 21:14:29 INFO Upload queue status pending=32379--- PASS: TestQueueFetchBatchLimit (0.01s)2380--- PASS: TestQueueRetryMovesToBack (0.01s)23812026/10/06 21:14:29 INFO Uploading batch count=123822026/10/06 21:14:29 ERROR Upload failed error="upload failed" count=123832026/10/06 21:14:29 INFO Uploading batch count=223842026/10/06 21:14:29 ERROR Upload failed error="upload failed" count=223852026/10/06 21:14:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3787587502/002/c2386--- PASS: TestQueueRemove (0.01s)23872026/10/06 21:14:29 INFO Uploading batch count=123882026/10/06 21:14:29 INFO Uploading batch count=123892026/10/06 21:14:29 ERROR Upload failed error="upload failed" count=12390--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23912026/10/06 21:14:29 INFO Uploading batch count=12392--- PASS: TestQueueDeduplication (0.01s)23932026/10/06 21:14:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3787587502/002/d23942026/10/06 21:14:29 INFO Uploading batch count=123952026/10/06 21:14:29 ERROR Upload failed error="upload failed" count=123962026/10/06 21:14:29 INFO Uploading batch count=223972026/10/06 21:14:29 ERROR Upload failed error="upload failed" count=223982026/10/06 21:14:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3787587502/002/e23992026/10/06 21:14:29 INFO Uploading batch count=124002026/10/06 21:14:29 ERROR Upload failed error="upload failed" count=124012026/10/06 21:14:29 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3787587502/002/f2402--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)24032026/10/06 21:14:29 ERROR Drain finished with paths left in queue remaining=124042026/10/06 21:14:29 ERROR Drain finished with paths left in queue remaining=102405--- PASS: TestDrainIsolatesPoisonPath (0.02s)2406--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2407--- PASS: TestWorkerSkipsGCdPaths (0.03s)2408--- PASS: TestWorkerUploadsAndRemoves (0.03s)2409--- PASS: TestWorkerPrunesClosureDeps (0.03s)2410--- PASS: TestQueueRemoveLargeClosure (0.10s)2411--- PASS: TestQueueConcurrentWriters (0.21s)24122026/10/06 21:14:29 ERROR Upload failed error="context deadline exceeded" count=224132026/10/06 21:14:29 ERROR Drain finished with paths left in queue remaining=42414--- PASS: TestDrainTimeout (0.22s)24152026/10/06 21:14:30 INFO Uploading batch count=124162026/10/06 21:14:30 INFO Uploading batch count=124172026/10/06 21:14:30 INFO Uploading batch count=124182026/10/06 21:14:30 ERROR Upload failed error="upload failed" count=124192026/10/06 21:14:30 INFO Uploading batch count=124202026/10/06 21:14:30 ERROR Upload failed error="upload failed" count=124212026/10/06 21:14:30 INFO Uploading batch count=124222026/10/06 21:14:30 ERROR Upload failed error="upload failed" count=124232026/10/06 21:14:30 INFO Uploading batch count=124242026/10/06 21:14:30 ERROR Upload failed error="upload failed" count=124252026/10/06 21:14:30 ERROR Drain finished with paths left in queue remaining=12426--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2427PASS2428Running signing tests...2429=== RUN TestExternalSigner2430=== PAUSE TestExternalSigner2431=== RUN TestExternalSignerWrongPublicKey2432=== PAUSE TestExternalSignerWrongPublicKey2433=== RUN TestExternalSignerErrors2434=== PAUSE TestExternalSignerErrors2435=== RUN TestExternalSignerRestartsAfterCrash2436=== PAUSE TestExternalSignerRestartsAfterCrash2437=== RUN TestExternalSignerProgramErrorKeepsProcess2438=== PAUSE TestExternalSignerProgramErrorKeepsProcess2439=== RUN TestExternalSignerClose2440=== PAUSE TestExternalSignerClose2441=== RUN TestExternalSignerRejectsInvalidPublicKey2442=== PAUSE TestExternalSignerRejectsInvalidPublicKey2443=== RUN TestExternalSignerCancellation2444=== PAUSE TestExternalSignerCancellation2445=== RUN TestGenerateFingerprint2446=== PAUSE TestGenerateFingerprint2447=== RUN TestParseSigningKey2448=== PAUSE TestParseSigningKey2449=== RUN TestSign2450=== PAUSE TestSign2451=== RUN TestSignBatch2452=== PAUSE TestSignBatch2453=== RUN TestNilKeyPublicKey2454=== PAUSE TestNilKeyPublicKey2455=== RUN TestSignErrors2456=== PAUSE TestSignErrors2457=== CONT TestExternalSigner2458=== CONT TestExternalSignerCancellation2459=== CONT TestSign2460=== CONT TestSignBatch2461=== CONT TestExternalSignerProgramErrorKeepsProcess2462=== CONT TestExternalSignerRejectsInvalidPublicKey2463=== RUN TestExternalSignerRejectsInvalidPublicKey/#002464=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002465=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2466=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2467=== CONT TestExternalSignerClose2468=== CONT TestParseSigningKey2469=== RUN TestParseSigningKey/valid_32-byte_key2470=== PAUSE TestParseSigningKey/valid_32-byte_key2471=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2472=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2473=== RUN TestParseSigningKey/no_colon2474=== CONT TestGenerateFingerprint2475=== RUN TestGenerateFingerprint/basic_with_references2476=== PAUSE TestGenerateFingerprint/basic_with_references2477=== RUN TestGenerateFingerprint/no_references2478=== CONT TestExternalSignerErrors2479=== CONT TestExternalSignerRestartsAfterCrash2480=== CONT TestExternalSignerWrongPublicKey2481=== CONT TestSignErrors2482=== CONT TestNilKeyPublicKey2483--- PASS: TestNilKeyPublicKey (0.00s)2484=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2485=== PAUSE TestParseSigningKey/no_colon2486=== RUN TestParseSigningKey/empty_name2487=== PAUSE TestGenerateFingerprint/no_references2488=== PAUSE TestParseSigningKey/empty_name2489=== RUN TestParseSigningKey/invalid_base642490=== PAUSE TestParseSigningKey/invalid_base642491=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2492=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2493=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2494=== RUN TestParseSigningKey/wrong_length2495=== PAUSE TestParseSigningKey/wrong_length2496=== CONT TestParseSigningKey/valid_32-byte_key2497=== RUN TestExternalSignerErrors/wrong_signature_name2498=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2499=== CONT TestParseSigningKey/wrong_length2500=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2501=== CONT TestParseSigningKey/empty_name2502=== CONT TestParseSigningKey/no_colon2503=== CONT TestParseSigningKey/invalid_base642504=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2505=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2506=== PAUSE TestExternalSignerErrors/wrong_signature_name2507=== RUN TestGenerateFingerprint/invalid_nar_hash_length2508=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2509=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2510=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2511=== CONT TestExternalSignerRejectsInvalidPublicKey/#002512=== RUN TestExternalSignerErrors/program_error2513=== PAUSE TestExternalSignerErrors/program_error2514=== RUN TestExternalSignerErrors/exit_at_startup2515=== PAUSE TestExternalSignerErrors/exit_at_startup2516=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2517=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2518=== RUN TestGenerateFingerprint/invalid_store_path_prefix2519=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2520=== RUN TestGenerateFingerprint/invalid_reference_prefix2521=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2522=== CONT TestGenerateFingerprint/basic_with_references2523=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2524=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2525=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2526--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2527 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2528 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2529 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2530 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2531 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2532=== RUN TestExternalSignerErrors/exit_on_request2533--- PASS: TestSign (0.00s)2534=== CONT TestGenerateFingerprint/invalid_nar_hash_length2535=== PAUSE TestExternalSignerErrors/exit_on_request2536=== RUN TestExternalSignerErrors/invalid_JSON2537=== CONT TestGenerateFingerprint/invalid_reference_prefix2538--- PASS: TestParseSigningKey (0.00s)2539 --- PASS: TestParseSigningKey/wrong_length (0.00s)2540 --- PASS: TestParseSigningKey/empty_name (0.00s)2541 --- PASS: TestParseSigningKey/no_colon (0.00s)2542 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2543 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2544 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2545=== CONT TestGenerateFingerprint/invalid_store_path_prefix2546=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2547=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2548=== CONT TestGenerateFingerprint/no_references2549=== RUN TestSignErrors/nil_key2550=== PAUSE TestSignErrors/nil_key2551=== RUN TestSignErrors/nil_narinfo2552=== PAUSE TestExternalSignerErrors/invalid_JSON2553=== RUN TestExternalSignerErrors/too_few_signatures2554--- PASS: TestGenerateFingerprint (0.00s)2555 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2556 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2557 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2558 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2559 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2560 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2561 --- PASS: TestGenerateFingerprint/no_references (0.00s)2562=== PAUSE TestSignErrors/nil_narinfo2563=== RUN TestSignErrors/invalid_narinfo2564=== PAUSE TestExternalSignerErrors/too_few_signatures2565=== RUN TestExternalSignerErrors/null2566=== PAUSE TestExternalSignerErrors/null2567=== PAUSE TestSignErrors/invalid_narinfo2568=== RUN TestSignErrors/canceled2569=== RUN TestExternalSignerErrors/wrong_id2570=== PAUSE TestExternalSignerErrors/wrong_id2571=== RUN TestExternalSignerErrors/null_signatures2572=== PAUSE TestExternalSignerErrors/null_signatures2573=== PAUSE TestSignErrors/canceled2574=== RUN TestExternalSignerErrors/unrequested_key2575=== CONT TestSignErrors/nil_key2576=== CONT TestSignErrors/nil_narinfo2577=== CONT TestSignErrors/invalid_narinfo2578=== CONT TestSignErrors/canceled2579=== PAUSE TestExternalSignerErrors/unrequested_key2580=== RUN TestExternalSignerErrors/invalid_signature_base642581--- PASS: TestSignBatch (0.00s)2582=== PAUSE TestExternalSignerErrors/invalid_signature_base642583=== RUN TestExternalSignerErrors/wrong_signature_length2584--- PASS: TestSignErrors (0.00s)2585 --- PASS: TestSignErrors/nil_key (0.00s)2586 --- PASS: TestSignErrors/nil_narinfo (0.00s)2587 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2588 --- PASS: TestSignErrors/canceled (0.00s)2589=== PAUSE TestExternalSignerErrors/wrong_signature_length2590=== RUN TestExternalSignerErrors/wrong_shape2591=== PAUSE TestExternalSignerErrors/wrong_shape2592=== RUN TestExternalSignerErrors/missing_signatures2593=== PAUSE TestExternalSignerErrors/missing_signatures2594=== RUN TestExternalSignerErrors/wrong_signatures_shape2595=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2596=== RUN TestExternalSignerErrors/missing_signature_name2597=== PAUSE TestExternalSignerErrors/missing_signature_name2598=== CONT TestExternalSignerErrors/wrong_signature_name2599=== CONT TestExternalSignerErrors/unrequested_key2600=== CONT TestExternalSignerErrors/wrong_signature_length2601=== CONT TestExternalSignerErrors/invalid_JSON2602=== CONT TestExternalSignerErrors/exit_at_startup2603=== CONT TestExternalSignerErrors/invalid_signature_base642604=== CONT TestExternalSignerErrors/missing_signatures2605=== CONT TestExternalSignerErrors/wrong_id2606--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2607--- PASS: TestExternalSignerClose (0.00s)2608=== CONT TestExternalSignerErrors/missing_signature_name2609=== CONT TestExternalSignerErrors/wrong_signatures_shape2610=== CONT TestExternalSignerErrors/too_few_signatures2611=== CONT TestExternalSignerErrors/null_signatures2612=== CONT TestExternalSignerErrors/null2613=== CONT TestExternalSignerErrors/wrong_shape2614=== CONT TestExternalSignerErrors/exit_on_request2615=== CONT TestExternalSignerErrors/program_error2616--- PASS: TestExternalSignerWrongPublicKey (0.00s)2617--- PASS: TestExternalSigner (0.01s)2618--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2619--- PASS: TestExternalSignerErrors (0.00s)2620 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2621 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2622 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2623 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2624 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2625 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2626 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2627 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2628 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2629 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2630 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2631 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2632 --- PASS: TestExternalSignerErrors/program_error (0.00s)2633 --- PASS: TestExternalSignerErrors/null (0.01s)2634 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2635 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2636--- PASS: TestExternalSignerCancellation (0.02s)2637PASS2638Running OpenBao signer tests...2639=== RUN TestSign2640=== PAUSE TestSign2641=== RUN TestSignErrors2642=== PAUSE TestSignErrors2643=== RUN TestServe2644=== PAUSE TestServe2645=== RUN TestServeRejectsGarbage2646=== PAUSE TestServeRejectsGarbage2647=== CONT TestSign2648=== CONT TestServe2649=== CONT TestSignErrors2650=== CONT TestServeRejectsGarbage2651=== RUN TestSignErrors/http_error2652=== PAUSE TestSignErrors/http_error2653--- PASS: TestServeRejectsGarbage (0.00s)2654=== RUN TestSignErrors/invalid_json2655=== PAUSE TestSignErrors/invalid_json2656=== RUN TestSignErrors/no_prefix2657=== PAUSE TestSignErrors/no_prefix2658=== RUN TestSignErrors/invalid_base642659=== PAUSE TestSignErrors/invalid_base642660=== CONT TestSignErrors/http_error2661=== CONT TestSignErrors/no_prefix2662=== CONT TestSignErrors/invalid_base642663--- PASS: TestServe (0.00s)2664=== CONT TestSignErrors/invalid_json2665--- PASS: TestSign (0.00s)2666--- PASS: TestSignErrors (0.00s)2667 --- PASS: TestSignErrors/invalid_json (0.00s)2668 --- PASS: TestSignErrors/invalid_base64 (0.00s)2669 --- PASS: TestSignErrors/no_prefix (0.00s)2670 --- PASS: TestSignErrors/http_error (0.00s)2671PASS