niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #392
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestScriptTokenScriptFails101=== CONT TestResolveStorePath102=== CONT TestClientSignaturesByStorePath103--- PASS: TestClientSignaturesByStorePath (0.00s)104=== CONT TestFileTokenReadsAndCaches105=== CONT TestStreamPushReportsSignatures106=== CONT TestStreamPushRequestLine107=== CONT TestStreamPushGivesUpOnDeadServer108=== CONT TestStreamPushIsolatesFailures109--- PASS: TestFileTokenReadsAndCaches (0.00s)110=== CONT TestScriptTokenEmptyCommand111=== CONT TestStreamPushBatchesUnderLoad112=== CONT TestStreamPushReportsEveryPath113=== CONT TestShellSplit114=== CONT TestDoWithRetry_BodyReplayedViaGetBody115=== CONT TestShellSplitErrors116=== CONT TestFileTokenEmpty117=== CONT TestScriptTokenCachesUntilRefresh118=== CONT TestScriptTokenEmptyToken119=== CONT TestScriptTokenNoExpiryRerunsEveryCall120=== CONT TestScriptTokenBadJSON121=== CONT TestDumpPathWriterError122=== CONT TestStaticToken123=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess124=== CONT TestFileTokenMissing125=== CONT TestRateLimiterFeedback126=== CONT TestUploadMultipart_PartsInParallel127=== CONT TestPathInfoCACompatibility128--- PASS: TestResolveStorePath (0.00s)1292026/10/07 06:17:57 ERROR Upload failed error="bad path" count=3130--- PASS: TestScriptTokenScriptFails (0.00s)131=== RUN TestRateLimiterFeedback/429_enables_limiter132=== PAUSE TestRateLimiterFeedback/429_enables_limiter133--- PASS: TestScriptTokenEmptyCommand (0.00s)1342026/10/07 06:17:57 ERROR Upload failed error="connection refused" count=20135=== RUN TestRateLimiterFeedback/503_enables_limiter1362026/10/07 06:17:57 ERROR Server seems unavailable, giving up on batch untried=17137=== PAUSE TestRateLimiterFeedback/503_enables_limiter138=== RUN TestPathInfoCACompatibility/null_ca_field139--- PASS: TestShellSplitErrors (0.00s)140--- PASS: TestShellSplit (0.00s)141=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter142=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter143=== CONT TestDumpPathSingleFile144=== CONT TestDumpPathMatchesNix145=== PAUSE TestPathInfoCACompatibility/null_ca_field1462026/10/07 06:17:57 WARN Rate limiter enabled after throttle name=server-test rate=5147=== CONT TestParsePathInfoJSONMultiplePaths148=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths149=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths150=== CONT TestParsePathInfoJSON151=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter152=== RUN TestPathInfoCACompatibility/old_string_format_-_text153--- PASS: TestFileTokenEmpty (0.00s)154=== CONT TestUploadMultipart_SupersededByPeer155=== RUN TestParsePathInfoJSON/Nix_format156=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter157=== RUN TestUploadMultipart_SupersededByPeer/exists158=== CONT TestPathInfoHashCompatibility159=== CONT TestPartSizeForNAR1602026/10/07 06:17:57 ERROR Upload failed error=boom count=1161=== CONT TestEncodeNixBase32WithRealHash1622026/10/07 06:17:57 ERROR Upload failed error=boom count=1163=== CONT TestEncodeNixBase32164=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun1652026/10/07 06:17:57 WARN Rate limiter enabled after throttle name=server-test rate=5166=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)167=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)168=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1692026/10/07 06:17:57 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:46023170=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon171=== RUN TestPartSizeForNAR/zero_stays_at_minimum172--- PASS: TestStaticToken (0.00s)173--- PASS: TestStreamPushReportsEveryPath (0.03s)174=== CONT TestFilterOversizedClosures1752026/10/07 06:17:57 WARN Rate limiter backed off name=server-test rate=51762026/10/07 06:17:57 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:46023177=== RUN TestFilterOversizedClosures/no_limit_keeps_everything178=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything179--- PASS: TestStreamPushIsolatesFailures (0.03s)180--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)181--- PASS: TestEncodeNixBase32WithRealHash (0.00s)182--- PASS: TestStreamPushReportsSignatures (0.03s)183--- PASS: TestFileTokenMissing (0.00s)184=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text185=== CONT TestConvertHashToNix32186=== RUN TestConvertHashToNix32/SRI_format_to_Nix32187--- PASS: TestDoServerRequestAttachesToken (0.03s)188=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive189--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)190=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths191=== PAUSE TestUploadMultipart_SupersededByPeer/exists192=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths193=== RUN TestEncodeNixBase32/test_string_hash194=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI195=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI196=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512197=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512198=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum199=== PAUSE TestParsePathInfoJSON/Nix_format200=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped201=== RUN TestPartSizeForNAR/small_stays_at_minimum202=== PAUSE TestPartSizeForNAR/small_stays_at_minimum203=== CONT TestGetStorePathHash204=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32205=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum206=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum207=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts208=== CONT TestCaseHackSuffix2092026/10/07 06:17:57 INFO Garbage collection started210=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts211=== RUN TestPartSizeForNAR/1_TiB212=== PAUSE TestPartSizeForNAR/1_TiB213=== RUN TestPartSizeForNAR/5_TiB_S3_max_object214=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object215=== CONT TestSetClientTLSErrors216=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive217=== RUN TestPathInfoCACompatibility/new_structured_format_-_text218=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text219=== RUN TestUploadMultipart_SupersededByPeer/missing220=== CONT TestSetClientTLSDoesNotMutateDefaultTransport221=== PAUSE TestEncodeNixBase32/test_string_hash222=== RUN TestEncodeNixBase32/empty_input223=== PAUSE TestEncodeNixBase32/empty_input224=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica225--- PASS: TestScriptTokenEmptyToken (0.00s)226=== CONT TestRegisterUploadedObjectReusesConnections227=== RUN TestParsePathInfoJSON/Lix_format228=== PAUSE TestParsePathInfoJSON/Lix_format229=== RUN TestGetStorePathHash/valid_store_path230=== PAUSE TestGetStorePathHash/valid_store_path231=== RUN TestConvertHashToNix32/already_Nix32_format232=== PAUSE TestConvertHashToNix32/already_Nix32_format233=== RUN TestGetStorePathHash/basename_without_hyphen_should_error234=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error235=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error236--- PASS: TestScriptTokenBadJSON (0.00s)237=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error238=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error239=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error240=== CONT TestRateLimiterFeedback/429_enables_limiter241=== PAUSE TestUploadMultipart_SupersededByPeer/missing242=== CONT TestRateLimiterFeedback/503_enables_limiter2432026/10/07 06:17:57 INFO Garbage collection started244=== CONT TestSetClientTLS245=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter246=== RUN TestSetClientTLSErrors/missing_cert_file2472026/10/07 06:17:57 WARN Rate limiter enabled after throttle name=server-test rate=52482026/10/07 06:17:57 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:386172492026/10/07 06:17:57 WARN Rate limiter enabled after throttle name=server-test rate=5250--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)2512026/10/07 06:17:57 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:46829252=== PAUSE TestSetClientTLSErrors/missing_cert_file2532026/10/07 06:17:57 WARN Rate limiter backed off name=server-test rate=5254=== RUN TestSetClientTLSErrors/missing_key_file255=== PAUSE TestSetClientTLSErrors/missing_key_file256=== RUN TestSetClientTLSErrors/missing_ca_file257=== PAUSE TestSetClientTLSErrors/missing_ca_file258=== RUN TestSetClientTLSErrors/invalid_ca_file259=== PAUSE TestSetClientTLSErrors/invalid_ca_file260=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths261=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter262=== RUN TestParsePathInfoJSON/empty_input263=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)264=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2652026/10/07 06:17:57 WARN Rate limiter backed off name=server-test rate=5266--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)267 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)268 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)2692026/10/07 06:17:57 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=0270--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)271=== PAUSE TestParsePathInfoJSON/empty_input272=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI273=== RUN TestParsePathInfoJSON/whitespace_only274=== PAUSE TestParsePathInfoJSON/whitespace_only275=== RUN TestParsePathInfoJSON/invalid_JSON276=== PAUSE TestParsePathInfoJSON/invalid_JSON277=== CONT TestGetStorePathHash/valid_store_path278=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon279=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error280=== CONT TestGetStorePathHash/basename_without_hyphen_should_error281=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method282=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method283=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error284=== CONT TestSetClientTLSErrors/missing_cert_file285=== CONT TestSetClientTLSErrors/missing_key_file286=== CONT TestParsePathInfoJSON/Nix_format287=== CONT TestParsePathInfoJSON/invalid_JSON288=== RUN TestSetClientTLS/rejects_connection_without_client_cert289=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert290=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA291=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA292=== RUN TestSetClientTLS/preserves_debug_logging_transport293=== PAUSE TestSetClientTLS/preserves_debug_logging_transport294=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped295=== RUN TestFilterOversizedClosures/all_closures_skipped296=== PAUSE TestFilterOversizedClosures/all_closures_skipped297--- PASS: TestRateLimiterFeedback (0.03s)298 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)299 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)300 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)301 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)302--- PASS: TestGetStorePathHash (0.00s)303 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)304 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)305 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)306 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)307=== CONT TestParsePathInfoJSON/empty_input308=== CONT TestPathInfoCACompatibility/null_ca_field309=== CONT TestUploadMultipart_SupersededByPeer/missing310=== CONT TestParsePathInfoJSON/Lix_format311=== CONT TestPathInfoCACompatibility/new_structured_format_-_text312=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive313=== CONT TestPathInfoCACompatibility/old_string_format_-_text314=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512315--- PASS: TestPathInfoHashCompatibility (0.00s)316 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)317 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)318 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)319 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)320=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method321--- PASS: TestPathInfoCACompatibility (0.03s)322 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)323 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)324 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)325 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)326 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)327=== CONT TestEncodeNixBase32/test_string_hash3282026/10/07 06:17:57 WARN Garbage collection finished on another replica. Its statistics are not available here329--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)330=== CONT TestFilterOversizedClosures/all_closures_skipped3312026/10/07 06:17:57 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=50332=== CONT TestSetClientTLS/rejects_connection_without_client_cert333=== CONT TestSetClientTLS/preserves_debug_logging_transport334=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3352026/10/07 06:17:57 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000336=== CONT TestUploadMultipart_SupersededByPeer/exists337=== RUN TestPartSizeForNAR/capped_at_5_GiB338=== PAUSE TestPartSizeForNAR/capped_at_5_GiB339=== CONT TestPartSizeForNAR/zero_stays_at_minimum340=== CONT TestFilterOversizedClosures/no_limit_keeps_everything341--- PASS: TestFilterOversizedClosures (0.00s)342 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)343 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)344 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)345=== CONT TestPartSizeForNAR/capped_at_5_GiB346=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum347=== CONT TestPartSizeForNAR/small_stays_at_minimum348=== CONT TestEncodeNixBase32/empty_input349--- PASS: TestEncodeNixBase32 (0.00s)350 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)351 --- PASS: TestEncodeNixBase32/empty_input (0.00s)352=== CONT TestPartSizeForNAR/5_TiB_S3_max_object353=== CONT TestSetClientTLSErrors/invalid_ca_file354=== CONT TestSetClientTLSErrors/missing_ca_file355--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)356 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)357 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)358--- PASS: TestSetClientTLSErrors (0.00s)359 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)360 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)361 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)362 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)363=== CONT TestParsePathInfoJSON/whitespace_only364--- PASS: TestParsePathInfoJSON (0.00s)365 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)366 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)367 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)368 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)369 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)370=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA371=== CONT TestPartSizeForNAR/1_TiB372=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts373--- PASS: TestPartSizeForNAR (0.01s)374 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)376 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)377 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)378 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)379 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)380 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)381=== RUN TestConvertHashToNix32/invalid_format382=== PAUSE TestConvertHashToNix32/invalid_format383=== CONT TestConvertHashToNix32/SRI_format_to_Nix32384=== CONT TestConvertHashToNix32/invalid_format385--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)386=== CONT TestConvertHashToNix32/already_Nix32_format387--- PASS: TestConvertHashToNix32 (0.01s)388 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)389 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)390 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)391--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)3922026/10/07 06:17:57 http: TLS handshake error from 127.0.0.1:47400: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.00s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)397--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)398--- PASS: TestDumpPathSingleFile (0.03s)399--- PASS: TestStreamPushRequestLine (0.06s)400--- PASS: TestCaseHackSuffix (0.03s)401--- PASS: TestDumpPathWriterError (0.06s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.11s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres4062624561/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/postgres4062624561/data -l logfile start434435/build/postgres4062624561:5432 - no response4362026-10-07 06:17:58.770 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-07 06:17:58.771 UTC [128] LOG: listening on Unix socket "/build/postgres4062624561/.s.PGSQL.5432"4382026-10-07 06:17:58.775 UTC [135] LOG: database system was shut down at 2026-10-07 06:17:58 UTC4392026-10-07 06:17:58.778 UTC [128] LOG: database system is ready to accept connections440/build/postgres4062624561:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestDeleteClosuresRacingPins478=== PAUSE TestDeleteClosuresRacingPins479=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== RUN TestResolveDBConnectionString482=== PAUSE TestResolveDBConnectionString483=== RUN TestConnectWaitsForAPeerMigration484=== PAUSE TestConnectWaitsForAPeerMigration485=== RUN TestLeadElectsOneAndHandsOver486=== PAUSE TestLeadElectsOneAndHandsOver487=== RUN TestLeadIncumbentWinsAfterRestart4882026/10/07 06:17:59 INFO lead: acquired remote=192.0.2.1:12344892026/10/07 06:17:59 INFO lead: released remote=192.0.2.1:12344902026/10/07 06:17:59 INFO lead: acquired remote=192.0.2.1:12344912026/10/07 06:18:00 INFO lead: released remote=192.0.2.1:1234492--- PASS: TestLeadIncumbentWinsAfterRestart (1.83s)493=== RUN TestLeadIncumbentAnnouncesAtOnce494=== PAUSE TestLeadIncumbentAnnouncesAtOnce495=== RUN TestLeadEndsOnShutdown496=== PAUSE TestLeadEndsOnShutdown497=== RUN TestLeadEndsWhenItsConnectionHangs4982026/10/07 06:18:01 INFO lead: acquired remote=192.0.2.1:12344992026-10-07 06:18:02.406 UTC [380] FATAL: terminating connection due to administrator command5002026/10/07 06:18:02 INFO lead: acquired remote=192.0.2.1:12345012026/10/07 06:18:03 WARN lead: lock connection lost error="timeout: context deadline exceeded"5022026/10/07 06:18:03 INFO lead: released remote=192.0.2.1:12345032026/10/07 06:18:04 INFO lead: released remote=192.0.2.1:1234504--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)505=== RUN TestGCAdvisoryLockBlocksConcurrentRun506=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestForceGCDuringPushOffersSweptObject524=== PAUSE TestForceGCDuringPushOffersSweptObject525=== RUN TestFailedS3DeleteKeepsTombstone526=== PAUSE TestFailedS3DeleteKeepsTombstone527=== RUN TestSweepSkipsRowsLockedByPush528=== PAUSE TestSweepSkipsRowsLockedByPush529=== RUN TestRegisterCompletedObjectNeedsPendingRow530=== PAUSE TestRegisterCompletedObjectNeedsPendingRow531=== RUN TestGetExistingObjectsLocksRows532=== PAUSE TestGetExistingObjectsLocksRows533=== RUN TestSweepRechecksPendingAfterLocking534=== PAUSE TestSweepRechecksPendingAfterLocking535=== RUN TestPushWaitsForSweepHoldingRow536=== PAUSE TestPushWaitsForSweepHoldingRow537=== RUN TestCommitRacingPendingCleanupKeepsObjects538=== PAUSE TestCommitRacingPendingCleanupKeepsObjects539=== RUN TestGCEndsOnShutdown540=== PAUSE TestGCEndsOnShutdown541=== RUN TestGCTaskStore_StartNew542=== PAUSE TestGCTaskStore_StartNew543=== RUN TestGCTaskStore_DeduplicateSameParams544=== PAUSE TestGCTaskStore_DeduplicateSameParams545=== RUN TestGCTaskStore_ConflictDifferentParams546=== PAUSE TestGCTaskStore_ConflictDifferentParams547=== RUN TestGCTaskStore_GetEmpty548=== PAUSE TestGCTaskStore_GetEmpty549=== RUN TestGCTaskStore_GetReturnsLatest550=== PAUSE TestGCTaskStore_GetReturnsLatest551=== RUN TestGCTaskStore_CompletedAllowsNewTask552=== PAUSE TestGCTaskStore_CompletedAllowsNewTask553=== RUN TestGCTaskStore_PhaseUpdates554=== PAUSE TestGCTaskStore_PhaseUpdates555=== RUN TestGCTaskStore_Fail556=== PAUSE TestGCTaskStore_Fail557=== RUN TestGracefulShutdownDrainsInflight558=== PAUSE TestGracefulShutdownDrainsInflight559=== RUN TestService_healthCheckHandler560=== PAUSE TestService_healthCheckHandler561=== RUN TestService_readinessHandler562=== PAUSE TestService_readinessHandler563=== RUN TestGenerateLandingPage564=== PAUSE TestGenerateLandingPage565=== RUN TestCacheConfigHandlerMaxNarSize566=== PAUSE TestCacheConfigHandlerMaxNarSize567=== RUN TestCreatePendingClosureRejectsOversizedNAR568=== PAUSE TestCreatePendingClosureRejectsOversizedNAR569=== RUN TestNARDeduplicationMetadataUploadBug570=== PAUSE TestNARDeduplicationMetadataUploadBug571=== RUN TestMetricsInventory572=== PAUSE TestMetricsInventory573=== RUN TestMetricsCommit574=== PAUSE TestMetricsCommit575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== RUN TestPendingCleanupUsesOneCutoff584=== PAUSE TestPendingCleanupUsesOneCutoff585=== RUN TestObjectStatsTrigger586=== PAUSE TestObjectStatsTrigger587=== RUN TestObjectStatsLargeCommit588=== PAUSE TestObjectStatsLargeCommit589=== RUN TestOrphanedObjectsGC590=== PAUSE TestOrphanedObjectsGC591=== RUN TestOrphanedObjectsGCStressTest592=== PAUSE TestOrphanedObjectsGCStressTest593=== RUN TestCreatePin_ReservedPins594=== PAUSE TestCreatePin_ReservedPins595=== RUN TestPresentReportsOnlyClosureRoots596=== PAUSE TestPresentReportsOnlyClosureRoots597=== RUN TestPresentRefreshesOnlyStaleClosures598=== PAUSE TestPresentRefreshesOnlyStaleClosures599=== RUN TestPresentNotReportedWhileGCDeletesClosure600=== PAUSE TestPresentNotReportedWhileGCDeletesClosure601=== RUN TestParseSingleRange602=== PAUSE TestParseSingleRange603=== RUN TestProxyHeadersOnlyTrustedOnSocket6042026/10/07 06:18:04 INFO Starting HTTP server address=127.0.0.1:340756052026/10/07 06:18:04 INFO Starting HTTP server address=proxy.sock6062026/10/07 06:18:04 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6072026/10/07 06:18:04 INFO Shutdown signal received, draining in-flight requests timeout=10s608--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)609=== RUN TestIsValidCachePath610=== PAUSE TestIsValidCachePath611=== RUN TestReadProxyNarinfo612=== PAUSE TestReadProxyNarinfo613=== RUN TestReadProxyNarinfoAlreadyDecompressed614=== PAUSE TestReadProxyNarinfoAlreadyDecompressed615=== RUN TestReadProxyContentNegotiation616=== PAUSE TestReadProxyContentNegotiation617=== RUN TestReadProxyNarStreaming618=== PAUSE TestReadProxyNarStreaming619=== RUN TestReadProxy404620=== PAUSE TestReadProxy404621=== RUN TestReadProxyInvalidPath622=== PAUSE TestReadProxyInvalidPath623=== RUN TestReadProxyHead624=== PAUSE TestReadProxyHead625=== RUN TestReadProxyOutlastsServerWriteTimeout626=== PAUSE TestReadProxyOutlastsServerWriteTimeout627=== RUN TestReadProxyConditionalGet628=== PAUSE TestReadProxyConditionalGet629=== RUN TestReadProxyRootRedirectsToIndexHTML630=== PAUSE TestReadProxyRootRedirectsToIndexHTML631=== RUN TestReadProxyDisabled632=== PAUSE TestReadProxyDisabled633=== RUN TestReadRedirectNar634=== PAUSE TestReadRedirectNar635=== RUN TestReadRedirectKeepsNarinfoProxied636=== PAUSE TestReadRedirectKeepsNarinfoProxied637=== RUN TestReadProxyRangeRequest638=== PAUSE TestReadProxyRangeRequest639=== RUN TestReadRedirectUsesPublicS3URL640=== PAUSE TestReadRedirectUsesPublicS3URL641=== RUN TestPush_OverlappingRootsStoreOneRowPerKey642=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey643=== RUN TestPush_CompleteCommitsEveryRoot644=== PAUSE TestPush_CompleteCommitsEveryRoot645=== RUN TestPush_RepeatedRootCommitsOnce646=== PAUSE TestPush_RepeatedRootCommitsOnce647=== RUN TestPush_CompleteWaitsForCleanupOfThePush648=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush649=== RUN TestPush_RootsAreLockedInByteOrder650=== PAUSE TestPush_RootsAreLockedInByteOrder651=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit652=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit653=== RUN TestPush_RejectsBadRequests654=== PAUSE TestPush_RejectsBadRequests655=== RUN TestPush_SignsNarinfosOfItsPendingObjects656=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects657=== RUN TestRedundantMultipartUpload658=== PAUSE TestRedundantMultipartUpload659=== RUN TestCompleteMultipartUpload_ErrorButObjectExists660=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists661=== RUN TestCompletedNarNotReofferedAcrossClosures662=== PAUSE TestCompletedNarNotReofferedAcrossClosures663=== RUN TestPresignedUploadRegisteredBeforeCommit664=== PAUSE TestPresignedUploadRegisteredBeforeCommit665=== RUN TestService_Rustfstest666=== PAUSE TestService_Rustfstest667=== RUN TestParseSize668=== PAUSE TestParseSize669=== RUN TestSkippedUploadsHandler670=== PAUSE TestSkippedUploadsHandler671=== RUN TestSystemdListenerNotActivated672--- PASS: TestSystemdListenerNotActivated (0.00s)673=== RUN TestWatchdogBeatsWhenHealthy674--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)675=== RUN TestWatchdogSkipsWhenUnhealthy6762026/10/07 06:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/07 06:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/07 06:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6792026/10/07 06:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6802026/10/07 06:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6812026/10/07 06:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/07 06:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/07 06:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/07 06:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/07 06:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"686--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)687=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle688=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle689=== RUN TestProxyWriteTimeout690=== PAUSE TestProxyWriteTimeout691=== RUN TestPendingClosureWriteTimeout692=== PAUSE TestPendingClosureWriteTimeout693=== RUN TestIsValidUploadKey694=== PAUSE TestIsValidUploadKey695=== RUN TestUploadHandlersRejectInvalidKeys696=== PAUSE TestUploadHandlersRejectInvalidKeys697=== RUN TestUploadHandlersRejectOversizedBody698=== PAUSE TestUploadHandlersRejectOversizedBody699=== RUN TestService_cleanupPendingClosuresHandler700=== PAUSE TestService_cleanupPendingClosuresHandler701=== RUN TestService_createPendingClosureHandler702=== PAUSE TestService_createPendingClosureHandler703=== RUN TestService_verifyS3Integrity704=== PAUSE TestService_verifyS3Integrity705=== RUN TestCompleteMultipartUnregistered706=== PAUSE TestCompleteMultipartUnregistered707=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT708=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT709=== CONT TestSkippedUploadsHandler710=== CONT TestGracefulShutdownDrainsInflight711=== CONT TestPush_CompleteWaitsForCleanupOfThePush712=== CONT TestUploadHandlersRejectOversizedBody713=== CONT TestService_AuthMiddleware7142026/10/07 06:18:04 INFO Starting HTTP server address=127.0.0.1:44345715=== CONT TestService_healthCheckHandler716=== CONT TestService_Rustfstest717=== CONT TestPresignedUploadRegisteredBeforeCommit718=== CONT TestCompletedNarNotReofferedAcrossClosures7192026/10/07 06:18:04 INFO Shutdown signal received, draining in-flight requests timeout=10s7202026/10/07 06:18:04 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000721=== CONT TestCompleteMultipartUpload_ErrorButObjectExists722=== CONT TestRedundantMultipartUpload723=== CONT TestPush_SignsNarinfosOfItsPendingObjects724=== CONT TestPush_RejectsBadRequests725=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit726=== CONT TestPush_RootsAreLockedInByteOrder727=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT728=== CONT TestCompleteMultipartUnregistered729=== CONT TestService_verifyS3Integrity730=== CONT TestService_createPendingClosureHandler731=== CONT TestService_cleanupPendingClosuresHandler732=== CONT TestParseSingleRange733=== RUN TestParseSingleRange/none734=== PAUSE TestParseSingleRange/none735=== RUN TestParseSingleRange/unknown_unit736=== PAUSE TestParseSingleRange/unknown_unit737=== RUN TestParseSingleRange/multi-range_ignored738=== PAUSE TestParseSingleRange/multi-range_ignored739=== RUN TestParseSingleRange/malformed_no_dash740=== PAUSE TestParseSingleRange/malformed_no_dash741=== RUN TestParseSingleRange/malformed_both_empty742=== PAUSE TestParseSingleRange/malformed_both_empty743=== RUN TestParseSingleRange/malformed_end_before_start744=== PAUSE TestParseSingleRange/malformed_end_before_start745=== RUN TestParseSingleRange/closed746=== PAUSE TestParseSingleRange/closed747=== RUN TestParseSingleRange/open-ended748=== PAUSE TestParseSingleRange/open-ended749=== RUN TestParseSingleRange/end_clamped_to_size750=== CONT TestPush_RepeatedRootCommitsOnce751=== CONT TestPush_CompleteCommitsEveryRoot752=== CONT TestParseSize753=== CONT TestReadRedirectUsesPublicS3URL754--- PASS: TestSkippedUploadsHandler (0.02s)755--- PASS: TestParseSize (0.00s)756=== CONT TestPush_OverlappingRootsStoreOneRowPerKey757=== PAUSE TestParseSingleRange/end_clamped_to_size758=== RUN TestParseSingleRange/suffix759=== PAUSE TestParseSingleRange/suffix760=== RUN TestParseSingleRange/suffix_exceeds_size761=== PAUSE TestParseSingleRange/suffix_exceeds_size762=== RUN TestParseSingleRange/single_byte763=== PAUSE TestParseSingleRange/single_byte764=== RUN TestParseSingleRange/start_past_EOF765=== PAUSE TestParseSingleRange/start_past_EOF766=== RUN TestParseSingleRange/start_far_past_EOF767=== PAUSE TestParseSingleRange/start_far_past_EOF768=== CONT TestReadRedirectKeepsNarinfoProxied769--- PASS: TestGracefulShutdownDrainsInflight (0.14s)770=== CONT TestPendingClosureWriteTimeout771=== RUN TestPendingClosureWriteTimeout/empty772=== PAUSE TestPendingClosureWriteTimeout/empty773=== RUN TestPendingClosureWriteTimeout/400_objects774=== PAUSE TestPendingClosureWriteTimeout/400_objects775=== RUN TestPendingClosureWriteTimeout/670k_objects776=== PAUSE TestPendingClosureWriteTimeout/670k_objects777=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline778=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline779=== CONT TestReadProxyRangeRequest780=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart781=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart782=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts783=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts784=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure785=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure786=== CONT TestReadRedirectNar787--- PASS: TestService_healthCheckHandler (0.27s)788=== CONT TestReadProxyDisabled7892026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures7902026/10/07 06:18:04 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7912026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures7922026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes793--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.31s)794=== CONT TestUploadHandlersRejectInvalidKeys795=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info796=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info797=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal798=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal799=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key800=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key801=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key802=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key803=== CONT TestReadProxyRootRedirectsToIndexHTML8042026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures8052026/10/07 06:18:04 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"806--- PASS: TestService_AuthMiddleware (0.34s)807=== CONT TestIsValidUploadKey808=== RUN TestIsValidUploadKey/narinfo809=== PAUSE TestIsValidUploadKey/narinfo810=== RUN TestIsValidUploadKey/nar_zst811=== PAUSE TestIsValidUploadKey/nar_zst812=== RUN TestIsValidUploadKey/nar_xz813=== PAUSE TestIsValidUploadKey/nar_xz814=== RUN TestIsValidUploadKey/nar_plain815=== PAUSE TestIsValidUploadKey/nar_plain816=== RUN TestIsValidUploadKey/listing817=== PAUSE TestIsValidUploadKey/listing818=== RUN TestIsValidUploadKey/build_log819=== PAUSE TestIsValidUploadKey/build_log820=== RUN TestIsValidUploadKey/build_log_home-manager_file821=== PAUSE TestIsValidUploadKey/build_log_home-manager_file822=== RUN TestIsValidUploadKey/build_log_plus_in_name823=== PAUSE TestIsValidUploadKey/build_log_plus_in_name824=== RUN TestIsValidUploadKey/build_log_question_mark825=== PAUSE TestIsValidUploadKey/build_log_question_mark826=== RUN TestIsValidUploadKey/build_log_equals827=== PAUSE TestIsValidUploadKey/build_log_equals828=== RUN TestIsValidUploadKey/realisation829=== PAUSE TestIsValidUploadKey/realisation830=== RUN TestIsValidUploadKey/realisation_plus_in_output831=== PAUSE TestIsValidUploadKey/realisation_plus_in_output832=== RUN TestIsValidUploadKey/nix-cache-info833=== PAUSE TestIsValidUploadKey/nix-cache-info834=== RUN TestIsValidUploadKey/index.html835=== PAUSE TestIsValidUploadKey/index.html836=== RUN TestIsValidUploadKey/narinfo_key,_nar_type837=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type838=== RUN TestIsValidUploadKey/nar_key,_narinfo_type839=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type840=== RUN TestIsValidUploadKey/listing_key,_narinfo_type841=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type842=== RUN TestIsValidUploadKey/traversal843=== PAUSE TestIsValidUploadKey/traversal844=== RUN TestIsValidUploadKey/traversal_nar845=== PAUSE TestIsValidUploadKey/traversal_nar846=== RUN TestIsValidUploadKey/absolute847=== PAUSE TestIsValidUploadKey/absolute848=== RUN TestIsValidUploadKey/empty_key849=== PAUSE TestIsValidUploadKey/empty_key850=== RUN TestIsValidUploadKey/unknown_type851=== PAUSE TestIsValidUploadKey/unknown_type852=== CONT TestReadProxyConditionalGet8532026/10/07 06:18:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8542026/10/07 06:18:04 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTNjYzUwYTYtZDFiZC00NjJmLTlhMmYtODUzNGFmNWEzOTY4LjcxNWFkOTAxLTZkODgtNGM5Ny1hZTQ5LTc0MTA5Y2MzOTQ1ZngxNzkxMzUzODg0NjY3OTcwNjY28552026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures8562026/10/07 06:18:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTNjYzUwYTYtZDFiZC00NjJmLTlhMmYtODUzNGFmNWEzOTY4LjcxNWFkOTAxLTZkODgtNGM5Ny1hZTQ5LTc0MTA5Y2MzOTQ1ZngxNzkxMzUzODg0NjY3OTcwNjY2 parts=1857--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.34s)858=== CONT TestReadProxyOutlastsServerWriteTimeout8592026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures860--- PASS: TestService_Rustfstest (0.38s)861=== CONT TestReadProxyContentNegotiation8622026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures8632026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes8642026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8652026/10/07 06:18:04 INFO Signed narinfos id=1 count=18662026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8672026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8682026/10/07 06:18:04 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8692026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8702026/10/07 06:18:04 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8712026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8722026/10/07 06:18:04 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18732026/10/07 06:18:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8742026/10/07 06:18:04 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo875--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.34s)876=== CONT TestReadProxyNarStreaming877=== RUN TestPush_RejectsBadRequests/no_roots878=== PAUSE TestPush_RejectsBadRequests/no_roots879=== RUN TestPush_RejectsBadRequests/no_objects880=== PAUSE TestPush_RejectsBadRequests/no_objects881=== RUN TestPush_RejectsBadRequests/bad_root882=== PAUSE TestPush_RejectsBadRequests/bad_root883=== RUN TestPush_RejectsBadRequests/root_not_in_objects884=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects885=== CONT TestReadProxyNarinfoAlreadyDecompressed8862026/10/07 06:18:04 INFO Received cleanup request method=DELETE path=/api/pending_closures8872026/10/07 06:18:04 INFO Aborted multipart uploads count=0 kept=08882026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures8892026/10/07 06:18:04 INFO Received cleanup request method=DELETE path=/api/pending_closures8902026/10/07 06:18:04 INFO Aborted multipart uploads count=1 kept=08912026/10/07 06:18:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8922026-10-07 06:18:04.802 UTC [462] ERROR: Closure does not exist: id=18932026-10-07 06:18:04.802 UTC [462] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8942026-10-07 06:18:04.802 UTC [462] STATEMENT: -- name: CommitPendingClosure :one895 SELECT commit_pending_closure($1::bigint)::bigint896 897--- PASS: TestService_cleanupPendingClosuresHandler (0.39s)898=== CONT TestReadProxyHead8992026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures900--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.40s)901=== CONT TestReadProxyNarinfo9022026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures9032026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures9042026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures9052026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes9062026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/1/complete9072026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes9082026/10/07 06:18:04 INFO Completed push id=1 objects=4 duration=8.757917ms909--- PASS: TestPush_RepeatedRootCommitsOnce (0.45s)910=== CONT TestReadProxyInvalidPath9112026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/1/complete9122026/10/07 06:18:04 INFO Completed push id=1 objects=4 duration=9.837486ms9132026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes914--- PASS: TestReadRedirectUsesPublicS3URL (0.48s)915=== CONT TestIsValidCachePath916=== RUN TestIsValidCachePath/narinfo917=== PAUSE TestIsValidCachePath/narinfo918=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars919=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars920=== RUN TestIsValidCachePath/nar_zst921=== PAUSE TestIsValidCachePath/nar_zst922=== RUN TestIsValidCachePath/nar_xz923=== PAUSE TestIsValidCachePath/nar_xz924=== RUN TestIsValidCachePath/nar_bz2925=== PAUSE TestIsValidCachePath/nar_bz2926=== RUN TestIsValidCachePath/nar_uncompressed927=== PAUSE TestIsValidCachePath/nar_uncompressed928=== RUN TestIsValidCachePath/ls929=== PAUSE TestIsValidCachePath/ls930=== RUN TestIsValidCachePath/log931=== PAUSE TestIsValidCachePath/log932=== RUN TestIsValidCachePath/realisation933=== PAUSE TestIsValidCachePath/realisation934=== RUN TestIsValidCachePath/nix-cache-info935=== PAUSE TestIsValidCachePath/nix-cache-info936=== RUN TestIsValidCachePath/index.html937=== PAUSE TestIsValidCachePath/index.html938=== RUN TestIsValidCachePath/traversal_parent939=== PAUSE TestIsValidCachePath/traversal_parent940=== RUN TestIsValidCachePath/traversal_in_middle941=== PAUSE TestIsValidCachePath/traversal_in_middle942=== RUN TestIsValidCachePath/invalid_char_e943=== PAUSE TestIsValidCachePath/invalid_char_e944=== RUN TestIsValidCachePath/invalid_char_u945=== PAUSE TestIsValidCachePath/invalid_char_u946=== RUN TestIsValidCachePath/random_path947=== PAUSE TestIsValidCachePath/random_path948=== RUN TestIsValidCachePath/empty949=== PAUSE TestIsValidCachePath/empty950=== RUN TestIsValidCachePath/leading_slash951=== PAUSE TestIsValidCachePath/leading_slash952=== RUN TestIsValidCachePath/wrong_extension953=== PAUSE TestIsValidCachePath/wrong_extension954=== RUN TestIsValidCachePath/short_hash955=== PAUSE TestIsValidCachePath/short_hash956=== CONT TestReadProxy404957--- PASS: TestReadRedirectKeepsNarinfoProxied (0.49s)958=== CONT TestSweepRechecksPendingAfterLocking9592026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes9602026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/1/complete9612026/10/07 06:18:04 INFO Received uploads request method=POST path=/api/pending_closures9622026/10/07 06:18:04 INFO Aborted multipart uploads count=0 kept=09632026/10/07 06:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period9642026/10/07 06:18:04 INFO Completed push id=1 objects=6 duration=16.258803ms965--- PASS: TestPush_CompleteCommitsEveryRoot (0.54s)966=== CONT TestGCTaskStore_ConflictDifferentParams967--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)968=== CONT TestGCTaskStore_DeduplicateSameParams969--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)970=== CONT TestGCTaskStore_Fail971--- PASS: TestGCTaskStore_Fail (0.00s)972=== CONT TestGCTaskStore_StartNew973--- PASS: TestGCTaskStore_StartNew (0.00s)974=== CONT TestGCBugBareHashReferences9752026-10-07 06:18:04.962 UTC [482] ERROR: Push does not exist: id=19762026-10-07 06:18:04.962 UTC [482] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9772026-10-07 06:18:04.962 UTC [482] STATEMENT: SELECT commit_push($1)978--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.63s)979=== CONT TestGCEndsOnShutdown980=== RUN TestGCEndsOnShutdown/before_the_run981=== PAUSE TestGCEndsOnShutdown/before_the_run982=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete983=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete984=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark985=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark986=== CONT TestCommitRacingPendingCleanupKeepsObjects9872026/10/07 06:18:04 INFO Received push request method=POST path=/api/pushes9882026/10/07 06:18:04 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=09892026/10/07 06:18:04 INFO Vacuumed table table=pending_closures9902026/10/07 06:18:04 INFO Vacuumed table table=pending_objects9912026/10/07 06:18:04 INFO Vacuumed table table=multipart_uploads9922026/10/07 06:18:04 INFO Vacuumed table table=closures9932026/10/07 06:18:04 INFO Vacuumed table table=objects9942026/10/07 06:18:04 INFO Received complete push request method=POST path=/api/pushes/2/complete995--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.57s)996=== CONT TestPushWaitsForSweepHoldingRow9972026/10/07 06:18:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9982026/10/07 06:18:04 INFO Completed push id=2 objects=4 duration=4.160396ms9992026/10/07 06:18:04 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1000--- PASS: TestCompleteMultipartUnregistered (0.57s)1001=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1002--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.58s)1003=== CONT TestProxyWriteTimeout1004=== RUN TestProxyWriteTimeout/narinfo1005=== PAUSE TestProxyWriteTimeout/narinfo1006=== RUN TestProxyWriteTimeout/1_GiB_nar1007=== PAUSE TestProxyWriteTimeout/1_GiB_nar1008=== RUN TestProxyWriteTimeout/10_GiB_nar1009=== PAUSE TestProxyWriteTimeout/10_GiB_nar1010=== RUN TestProxyWriteTimeout/unknown_size1011=== PAUSE TestProxyWriteTimeout/unknown_size1012=== CONT TestGetExistingObjectsLocksRows10132026/10/07 06:18:05 INFO Received push request method=POST path=/api/pushes1014--- PASS: TestReadProxyRangeRequest (0.57s)1015=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle10162026-10-07 06:18:05.054 UTC [539] ERROR: could not obtain lock on row in relation "closures"10172026-10-07 06:18:05.054 UTC [539] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10182026-10-07 06:18:05.054 UTC [539] ERROR: could not obtain lock on row in relation "closures"10192026-10-07 06:18:05.054 UTC [539] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10202026-10-07 06:18:05.055 UTC [539] ERROR: could not obtain lock on row in relation "closures"10212026-10-07 06:18:05.055 UTC [539] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10222026-10-07 06:18:05.055 UTC [539] ERROR: could not obtain lock on row in relation "closures"10232026-10-07 06:18:05.055 UTC [539] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10242026-10-07 06:18:05.055 UTC [539] ERROR: could not obtain lock on row in relation "closures"10252026-10-07 06:18:05.055 UTC [539] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1026--- PASS: TestPush_RootsAreLockedInByteOrder (0.64s)1027=== CONT TestGCSweepDeliversEachKeyOnce10282026/10/07 06:18:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1029--- PASS: TestReadRedirectNar (0.55s)1030=== CONT TestRegisterCompletedObjectNeedsPendingRow1031--- PASS: TestReadProxyDisabled (0.47s)1032=== CONT TestFailedS3DeleteKeepsTombstone10332026/10/07 06:18:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTNjYzUwYTYtZDFiZC00NjJmLTlhMmYtODUzNGFmNWEzOTY4LmU3OGQyNzg0LWYyM2MtNDY4Yy04OTdjLWIyM2Q0ZTUxNzVhMHgxNzkxMzUzODg0NzAyNDM1NTMw parts=1210342026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures10352026/10/07 06:18:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10362026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures1037--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.46s)1038=== CONT TestTombstonedObjectOfferedWithoutWaiting10392026/10/07 06:18:05 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTNjYzUwYTYtZDFiZC00NjJmLTlhMmYtODUzNGFmNWEzOTY4LjBkNDA5M2I5LWYxOWItNGUzZi1hY2NmLWVkZjg3ZjIwMTNjNHgxNzkxMzUzODg0NzM0MDk1ODcw parts=1210402026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures1041--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.78s)1042=== CONT TestForceGCDuringPushOffersSweptObject1043=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1044=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1045=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1046=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1047=== CONT TestSweepSkipsRowsLockedByPush10482026/10/07 06:18:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1049--- PASS: TestReadProxyConditionalGet (0.47s)1050=== CONT TestGCSweepSkipsPendingObjects10512026/10/07 06:18:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTNjYzUwYTYtZDFiZC00NjJmLTlhMmYtODUzNGFmNWEzOTY4LjIxNjhlNWYzLTAxZDItNDRkNy1hMjRlLWQxNTFiM2ZlZWQzZHgxNzkxMzUzODg0ODM4NjcwNTkz parts=1010522026/10/07 06:18:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10532026/10/07 06:18:05 INFO Completed upload id=1 objects=2 duration=3.993035ms10542026/10/07 06:18:05 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010552026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures10562026/10/07 06:18:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures10572026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=010582026/10/07 06:18:05 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=010592026/10/07 06:18:05 INFO Vacuumed table table=pending_closures10602026/10/07 06:18:05 INFO Vacuumed table table=pending_objects10612026/10/07 06:18:05 INFO Vacuumed table table=multipart_uploads10622026/10/07 06:18:05 INFO Vacuumed table table=closures10632026/10/07 06:18:05 INFO Vacuumed table table=objects10642026/10/07 06:18:05 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001065--- PASS: TestReadProxyNarStreaming (0.46s)1066=== CONT TestClientWithDependencies1067--- PASS: TestService_createPendingClosureHandler (0.80s)1068=== CONT TestDeduplicatedObjectsRecordedAsPending1069--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.47s)1070=== CONT TestGCAdvisoryLockBlocksConcurrentRun1071--- PASS: TestReadProxyContentNegotiation (0.53s)1072=== CONT TestPushDedupSurvivesConcurrentGC1073--- PASS: TestReadProxyHead (0.46s)1074=== CONT TestGCTaskStore_GetReturnsLatest1075--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1076=== CONT TestGCTaskStore_PhaseUpdates1077--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1078=== CONT TestGCTaskStore_CompletedAllowsNewTask1079--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1080=== CONT TestGCTaskStore_GetEmpty1081--- PASS: TestGCTaskStore_GetEmpty (0.00s)1082=== CONT TestLeadEndsOnShutdown10832026/10/07 06:18:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10842026/10/07 06:18:05 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTNjYzUwYTYtZDFiZC00NjJmLTlhMmYtODUzNGFmNWEzOTY4LjU1ZDgzOGE3LTE5YzUtNDkxMC1hYzI5LTFiNjU3NjljNmE1ZXgxNzkxMzUzODg0OTYzMjAyNDky parts=1010852026/10/07 06:18:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10862026/10/07 06:18:05 INFO Completed upload id=1 objects=2 duration=3.881114ms10872026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures10882026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures1089--- PASS: TestReadProxyInvalidPath (0.42s)1090=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10912026/10/07 06:18:05 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10922026/10/07 06:18:05 WARN Found objects in DB but missing from S3, will re-upload count=11093--- PASS: TestService_verifyS3Integrity (0.88s)1094=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1095--- PASS: TestReadProxy404 (0.43s)1096=== CONT TestLeadIncumbentAnnouncesAtOnce10972026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=010982026/10/07 06:18:05 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>10992026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period1100--- PASS: TestReadProxyNarinfo (0.54s)1101=== CONT TestPresentNotReportedWhileGCDeletesClosure1102=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1103=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1104=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1105=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1106=== CONT TestLeadElectsOneAndHandsOver11072026/10/07 06:18:05 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=011082026/10/07 06:18:05 INFO Vacuumed table table=pending_closures11092026/10/07 06:18:05 INFO Vacuumed table table=pending_objects11102026/10/07 06:18:05 INFO Vacuumed table table=multipart_uploads11112026/10/07 06:18:05 INFO Vacuumed table table=closures11122026/10/07 06:18:05 INFO Vacuumed table table=objects1113--- PASS: TestSweepRechecksPendingAfterLocking (0.47s)1114=== CONT TestDeleteClosuresRacingPins11152026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures11162026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=011172026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period11182026/10/07 06:18:05 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=011192026/10/07 06:18:05 INFO Vacuumed table table=pending_closures11202026/10/07 06:18:05 INFO Vacuumed table table=pending_objects11212026/10/07 06:18:05 INFO Vacuumed table table=multipart_uploads11222026/10/07 06:18:05 INFO Vacuumed table table=closures11232026/10/07 06:18:05 INFO Vacuumed table table=objects1124--- PASS: TestGetExistingObjectsLocksRows (0.44s)1125=== CONT TestPresentRefreshesOnlyStaleClosures1126--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.48s)1127=== CONT TestConnectWaitsForAPeerMigration11282026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures11292026/10/07 06:18:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11302026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures11312026/10/07 06:18:05 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTNjYzUwYTYtZDFiZC00NjJmLTlhMmYtODUzNGFmNWEzOTY4LjM5NDY0ZmVjLTA3YTUtNGFjNC1iNWQyLTMyN2MxOGYzMzhmNHgxNzkxMzUzODg1MTA5Nzc5OTY2 error="Get \"http://127.0.0.1:1/bucket9/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11322026/10/07 06:18:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTNjYzUwYTYtZDFiZC00NjJmLTlhMmYtODUzNGFmNWEzOTY4LmFiNWU4OTFhLTdkNDYtNDcyNi04NjYwLWRhMDFlOWQyMDgwYngxNzkxMzUzODg1MDkzOTI4MjQ2 parts=1211332026/10/07 06:18:05 INFO Received cleanup request method=DELETE path=/api/pending_closures11342026/10/07 06:18:05 INFO Aborted multipart uploads count=1 kept=01135--- PASS: TestRedundantMultipartUpload (1.13s)1136=== CONT TestClientFallsBackToClosures1137--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.42s)1138=== CONT TestPresentReportsOnlyClosureRoots11392026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures11402026/10/07 06:18:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11412026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=011422026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period11432026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures11442026/10/07 06:18:05 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=011452026/10/07 06:18:05 INFO Vacuumed table table=pending_closures11462026/10/07 06:18:05 INFO Vacuumed table table=pending_objects1147--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.44s)1148=== CONT TestResolveDBConnectionString1149=== RUN TestResolveDBConnectionString/flag_wins1150=== PAUSE TestResolveDBConnectionString/flag_wins11512026/10/07 06:18:05 INFO Vacuumed table table=multipart_uploads1152=== RUN TestResolveDBConnectionString/file_when_flag_empty1153=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1154=== RUN TestResolveDBConnectionString/missing_file_is_an_error1155=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1156=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1157=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1158=== RUN TestResolveDBConnectionString/nothing_configured1159=== PAUSE TestResolveDBConnectionString/nothing_configured11602026/10/07 06:18:05 INFO Vacuumed table table=closures1161=== CONT TestClientPushesUseOnePush11622026/10/07 06:18:05 INFO Vacuumed table table=objects1163--- PASS: TestGCSweepDeliversEachKeyOnce (0.49s)1164=== CONT TestCacheConfigHandler1165=== RUN TestCacheConfigHandler/full_config,_no_issuer1166=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1167=== RUN TestCacheConfigHandler/no_cache_url_configured1168=== PAUSE TestCacheConfigHandler/no_cache_url_configured1169=== RUN TestCacheConfigHandler/no_signing_keys1170=== PAUSE TestCacheConfigHandler/no_signing_keys1171=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1172=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1173=== CONT TestPinProtectsFromGC11742026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=011752026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures1176--- PASS: TestGCBugBareHashReferences (0.62s)1177=== CONT TestClientErrorHandling1178=== RUN TestClientErrorHandling/InvalidStorePath1179=== PAUSE TestClientErrorHandling/InvalidStorePath1180=== RUN TestClientErrorHandling/InvalidAuthToken1181=== PAUSE TestClientErrorHandling/InvalidAuthToken1182=== RUN TestClientErrorHandling/ServerNotAvailable1183=== PAUSE TestClientErrorHandling/ServerNotAvailable1184=== CONT TestClientCADerivations11852026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period11862026/10/07 06:18:05 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=011872026/10/07 06:18:05 INFO Vacuumed table table=pending_closures11882026/10/07 06:18:05 INFO Vacuumed table table=pending_objects11892026/10/07 06:18:05 INFO Vacuumed table table=multipart_uploads11902026/10/07 06:18:05 INFO Vacuumed table table=closures11912026/10/07 06:18:05 INFO Vacuumed table table=objects11922026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=011932026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=011942026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=011952026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period11962026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period11972026/10/07 06:18:05 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=011982026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period11992026/10/07 06:18:05 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=012002026/10/07 06:18:05 INFO Vacuumed table table=pending_closures12012026/10/07 06:18:05 INFO Vacuumed table table=pending_closures12022026/10/07 06:18:05 INFO Vacuumed table table=pending_objects12032026/10/07 06:18:05 INFO Vacuumed table table=multipart_uploads12042026/10/07 06:18:05 INFO Vacuumed table table=closures12052026/10/07 06:18:05 INFO Vacuumed table table=pending_objects12062026/10/07 06:18:05 INFO Vacuumed table table=multipart_uploads12072026/10/07 06:18:05 INFO Vacuumed table table=closures12082026/10/07 06:18:05 INFO Vacuumed table table=objects12092026/10/07 06:18:05 INFO Vacuumed table table=objects1210--- PASS: TestSweepSkipsRowsLockedByPush (0.50s)1211=== CONT TestClientSharedPathCommittedMidPush12122026/10/07 06:18:05 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12132026/10/07 06:18:05 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1214--- PASS: TestFailedS3DeleteKeepsTombstone (0.54s)1215=== CONT TestCacheStatsHandler12162026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures1217--- PASS: TestGCSweepSkipsPendingObjects (0.48s)1218=== CONT TestClientMultipleUploads1219--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.41s)1220=== CONT TestObjectStatsLargeCommit12212026/10/07 06:18:05 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"1222--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.41s)1223=== CONT TestCreatePin_ReservedPins1224--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.66s)1225=== CONT TestGCMetrics12262026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures12272026/10/07 06:18:05 INFO lead: acquired remote=192.0.2.1:12341228=== NAME TestClientWithDependencies1229 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies4111023093/001/store/i3hmy3wk1v9sjjhyp1rm73ws87hdk714-test-script12302026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures1231 client_integration_test.go:615: Found 1 dependencies (including self)1232--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.42s)1233=== CONT TestPendingCleanupUsesOneCutoff12342026/10/07 06:18:05 INFO lead: acquired remote=192.0.2.1:123412352026/10/07 06:18:05 INFO lead: released remote=192.0.2.1:12341236--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.40s)1237=== CONT TestOrphanedObjectsGCStressTest12382026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=012392026/10/07 06:18:05 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=012402026/10/07 06:18:05 INFO lead: acquired remote=192.0.2.1:123412412026/10/07 06:18:05 INFO Vacuumed table table=pending_closures12422026/10/07 06:18:05 INFO Vacuumed table table=pending_objects12432026/10/07 06:18:05 INFO Vacuumed table table=multipart_uploads12442026/10/07 06:18:05 INFO Vacuumed table table=closures12452026/10/07 06:18:05 INFO Vacuumed table table=objects12462026/10/07 06:18:05 INFO Aborted multipart uploads count=0 kept=012472026/10/07 06:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period12482026/10/07 06:18:05 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=012492026/10/07 06:18:05 INFO Vacuumed table table=pending_closures12502026/10/07 06:18:05 INFO Vacuumed table table=pending_objects12512026/10/07 06:18:05 INFO Vacuumed table table=multipart_uploads12522026/10/07 06:18:05 INFO Vacuumed table table=closures12532026/10/07 06:18:05 INFO Vacuumed table table=objects1254--- PASS: TestPushDedupSurvivesConcurrentGC (0.54s)1255=== CONT TestObjectStatsTrigger12562026/10/07 06:18:05 INFO Received push request method=POST path=/api/pushes12572026/10/07 06:18:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12582026/10/07 06:18:05 INFO Uploading i3hmy3wk1v9sjjhyp1rm73ws87hdk714-test-script (136B)12592026/10/07 06:18:05 WARN Failed to register uploaded object key=log/sawcbp7hdy7m1y7xymhiz18a4b2bfqg5-test-script.drv error="server returned 404: 404 page not found\n"12602026/10/07 06:18:05 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12612026/10/07 06:18:05 WARN Failed to register uploaded object key=i3hmy3wk1v9sjjhyp1rm73ws87hdk714.ls error="server returned 404: 404 page not found\n"12622026/10/07 06:18:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12632026/10/07 06:18:05 INFO Signed narinfos id=1 count=112642026/10/07 06:18:05 INFO Uploading 1 narinfos12652026/10/07 06:18:05 INFO Received complete push request method=POST path=/api/pushes/1/complete12662026/10/07 06:18:05 WARN Failed to register uploaded object key=i3hmy3wk1v9sjjhyp1rm73ws87hdk714.narinfo error="server returned 404: 404 page not found\n"1267--- PASS: TestPresentRefreshesOnlyStaleClosures (0.37s)1268=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12692026/10/07 06:18:05 INFO Completed push id=1 objects=4 duration=5.585929ms12702026/10/07 06:18:05 INFO Upload complete. (58ms)1271=== NAME TestClientWithDependencies1272 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4111023093/001/store) requires matching store prefix1273--- PASS: TestClientWithDependencies (0.59s)1274=== CONT TestService_ReadScope_PublicByDefault12752026/10/07 06:18:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45127/oidc1276--- PASS: TestPresentReportsOnlyClosureRoots (0.36s)1277=== CONT TestService_RequireScope_OIDC1278--- PASS: TestPushWaitsForSweepHoldingRow (0.92s)1279=== CONT TestService_AuthMiddleware_OIDC1280=== NAME TestPinProtectsFromGC1281 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1601719818/001/store/xjmar0x89jmlwnck4bjwnr1jb2sazd19-pinned-file.txt1282 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1601719818/001/store/jjlmp97dy9ifxpibrx0x27jqd9hhyxb3-unpinned-file.txt1283--- PASS: TestCacheStatsHandler (0.31s)1284=== CONT TestMetricsInventory1285--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.69s)1286=== CONT TestService_ReadAuthMiddleware12872026/10/07 06:18:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40719/oidc1288=== NAME TestClientCADerivations1289 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations939891663/001/store/7283cp45p9kiwcvy7ys3r1hhj0n6xd2w-ca-test12902026/10/07 06:18:05 INFO Received push request method=POST path=/api/pushes12912026/10/07 06:18:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12922026/10/07 06:18:05 INFO Uploading xjmar0x89jmlwnck4bjwnr1jb2sazd19-pinned-file.txt (128B)12932026/10/07 06:18:05 INFO Received uploads request method=POST path=/api/pending_closures12942026/10/07 06:18:06 WARN Failed to register uploaded object key=xjmar0x89jmlwnck4bjwnr1jb2sazd19.ls error="server returned 404: 404 page not found\n"12952026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12962026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12972026/10/07 06:18:06 INFO Signed narinfos id=1 count=112982026/10/07 06:18:06 INFO Received uploads request method=POST path=/api/pending_closures12992026/10/07 06:18:06 INFO Uploading 1 narinfos13002026/10/07 06:18:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13012026/10/07 06:18:06 INFO Uploading fwli8bzm16m1fy5zczqdxaiirwspvjq1-shared-dep (136B)13022026/10/07 06:18:06 INFO Uploading an3pbkxg7l3gzx9dik1kf7qch170hscq-b (216B)13032026/10/07 06:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete13042026/10/07 06:18:06 WARN Failed to register uploaded object key=xjmar0x89jmlwnck4bjwnr1jb2sazd19.narinfo error="server returned 404: 404 page not found\n"13052026/10/07 06:18:06 WARN Failed to register uploaded object key=760y6i8xmg5qg76nq60hzdpbq6pf7hfs.ls error="server returned 404: 404 page not found\n"13062026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13072026/10/07 06:18:06 WARN Failed to register uploaded object key=fwli8bzm16m1fy5zczqdxaiirwspvjq1.ls error="server returned 404: 404 page not found\n"13082026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/1qj76f4zvsa23p8ljq1c6bfnk69jimwgszkgqp9fi1zfzrnl0ka1.nar.zst error="server returned 404: 404 page not found\n"13092026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13102026/10/07 06:18:06 WARN Failed to register uploaded object key=an3pbkxg7l3gzx9dik1kf7qch170hscq.ls error="server returned 404: 404 page not found\n"13112026/10/07 06:18:06 INFO Signed narinfos id=2 count=213122026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13132026/10/07 06:18:06 INFO Signed narinfos id=1 count=213142026/10/07 06:18:06 INFO Uploading 4 narinfos13152026/10/07 06:18:06 INFO Completed push id=1 objects=3 duration=6.561938ms13162026/10/07 06:18:06 INFO Upload complete. (57ms)13172026/10/07 06:18:06 WARN Failed to register uploaded object key=fwli8bzm16m1fy5zczqdxaiirwspvjq1.narinfo error="server returned 404: 404 page not found\n"13182026/10/07 06:18:06 WARN Failed to register uploaded object key=an3pbkxg7l3gzx9dik1kf7qch170hscq.narinfo error="server returned 404: 404 page not found\n"13192026/10/07 06:18:06 WARN Failed to register uploaded object key=760y6i8xmg5qg76nq60hzdpbq6pf7hfs.narinfo error="server returned 404: 404 page not found\n"1320 client_ca_test.go:139: Found 1 dependencies (including self)13212026/10/07 06:18:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13222026/10/07 06:18:06 WARN Failed to register uploaded object key=fwli8bzm16m1fy5zczqdxaiirwspvjq1.narinfo error="server returned 404: 404 page not found\n"13232026/10/07 06:18:06 INFO Aborted multipart uploads count=0 kept=013242026/10/07 06:18:06 INFO Completed upload id=1 objects=6 duration=13.368098ms13252026/10/07 06:18:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13262026/10/07 06:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period13272026/10/07 06:18:06 INFO Completed upload id=2 objects=6 duration=1.523753ms13282026/10/07 06:18:06 INFO Upload complete. (76ms)13292026/10/07 06:18:06 INFO Received uploads request method=POST path=/api/pending_closures1330=== NAME TestClientFallsBackToClosures1331 client_pushes_test.go:112: Retrieved narinfo from S3:1332 StorePath: /build/TestClientFallsBackToClosures1319972488/001/store/fwli8bzm16m1fy5zczqdxaiirwspvjq1-shared-dep1333 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1334 Compression: zstd1335 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821336 NarSize: 1361337 References: 1338 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13392026/10/07 06:18:06 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=013402026/10/07 06:18:06 INFO Vacuumed table table=pending_closures1341 client_pushes_test.go:112: Retrieved narinfo from S3:1342 StorePath: /build/TestClientFallsBackToClosures1319972488/001/store/760y6i8xmg5qg76nq60hzdpbq6pf7hfs-a1343 URL: nar/1qj76f4zvsa23p8ljq1c6bfnk69jimwgszkgqp9fi1zfzrnl0ka1.nar.zst1344 Compression: zstd1345 NarHash: sha256:1qj76f4zvsa23p8ljq1c6bfnk69jimwgszkgqp9fi1zfzrnl0ka11346 NarSize: 2161347 References: /build/TestClientFallsBackToClosures1319972488/001/store/fwli8bzm16m1fy5zczqdxaiirwspvjq1-shared-dep1348 CA: text:sha256:0xir9y24lk1h11gwiq402c04bx786cvwrpmy77qnjisbz23kmkm313492026/10/07 06:18:06 INFO Vacuumed table table=pending_objects13502026/10/07 06:18:06 INFO Vacuumed table table=multipart_uploads13512026/10/07 06:18:06 INFO Vacuumed table table=closures1352=== NAME TestClientMultipleUploads1353 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads380973719/001/store/fcf966c0100w787ai1n6n8a8bmpj26bj-test-file-0.txt13542026/10/07 06:18:06 INFO Vacuumed table table=objects1355=== NAME TestClientFallsBackToClosures1356 client_pushes_test.go:112: Retrieved narinfo from S3:1357 StorePath: /build/TestClientFallsBackToClosures1319972488/001/store/an3pbkxg7l3gzx9dik1kf7qch170hscq-b1358 URL: nar/1qj76f4zvsa23p8ljq1c6bfnk69jimwgszkgqp9fi1zfzrnl0ka1.nar.zst1359 Compression: zstd1360 NarHash: sha256:1qj76f4zvsa23p8ljq1c6bfnk69jimwgszkgqp9fi1zfzrnl0ka11361 NarSize: 2161362 References: /build/TestClientFallsBackToClosures1319972488/001/store/fwli8bzm16m1fy5zczqdxaiirwspvjq1-shared-dep1363 CA: text:sha256:0xir9y24lk1h11gwiq402c04bx786cvwrpmy77qnjisbz23kmkm31364--- PASS: TestGCMetrics (0.39s)1365=== CONT TestMultipartCleanup13662026/10/07 06:18:06 INFO Received uploads request method=POST path=/api/pending_closures1367--- PASS: TestClientFallsBackToClosures (0.56s)1368=== CONT TestService_NativeMTLS13692026/10/07 06:18:06 INFO Received cleanup request method=DELETE path=/api/pending_closures13702026/10/07 06:18:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36873/oidc13712026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes13722026/10/07 06:18:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13732026/10/07 06:18:06 INFO Uploading rk0v1s8j9dja8p5g55h6jym71hfc616y-shared-dep (136B)13742026/10/07 06:18:06 INFO Uploading rq95lbycf3xdq22mf104vlvm6y9a3d6s-b (216B)13752026/10/07 06:18:06 WARN Failed to register uploaded object key=3wydxvcry8xkdfi37g0lmq86jvmq4jhv.ls error="server returned 404: 404 page not found\n"13762026/10/07 06:18:06 WARN Failed to register uploaded object key=rk0v1s8j9dja8p5g55h6jym71hfc616y.ls error="server returned 404: 404 page not found\n"13772026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13782026/10/07 06:18:06 WARN Failed to register uploaded object key=rq95lbycf3xdq22mf104vlvm6y9a3d6s.ls error="server returned 404: 404 page not found\n"13792026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13802026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/04hlnihrga9fq93qb1sggq8cqaqcfps0hqaaz866mp0qcwr69aq8.nar.zst error="server returned 404: 404 page not found\n"13812026/10/07 06:18:06 INFO Signed narinfos id=1 count=313822026/10/07 06:18:06 INFO Uploading 3 narinfos1383=== NAME TestClientMultipleUploads1384 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads380973719/001/store/79dlawyfkw0wxsv8jbp8xmlh6vwkn5yv-test-file-1.txt13852026/10/07 06:18:06 WARN Failed to register uploaded object key=3wydxvcry8xkdfi37g0lmq86jvmq4jhv.narinfo error="server returned 404: 404 page not found\n"13862026/10/07 06:18:06 WARN Failed to register uploaded object key=rk0v1s8j9dja8p5g55h6jym71hfc616y.narinfo error="server returned 404: 404 page not found\n"13872026/10/07 06:18:06 WARN Failed to register uploaded object key=rq95lbycf3xdq22mf104vlvm6y9a3d6s.narinfo error="server returned 404: 404 page not found\n"13882026/10/07 06:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete13892026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes13902026/10/07 06:18:06 INFO Completed push id=1 objects=8 duration=6.398396ms13912026/10/07 06:18:06 INFO Upload complete. (59ms)1392=== NAME TestClientPushesUseOnePush1393 client_pushes_test.go:97: Retrieved narinfo from S3:1394 StorePath: /build/TestClientPushesUseOnePush1637573817/001/store/rk0v1s8j9dja8p5g55h6jym71hfc616y-shared-dep1395 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1396 Compression: zstd1397 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821398 NarSize: 1361399 References: 1400 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14012026/10/07 06:18:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14022026/10/07 06:18:06 INFO Uploading jjlmp97dy9ifxpibrx0x27jqd9hhyxb3-unpinned-file.txt (128B)1403 client_pushes_test.go:97: Retrieved narinfo from S3:1404 StorePath: /build/TestClientPushesUseOnePush1637573817/001/store/3wydxvcry8xkdfi37g0lmq86jvmq4jhv-a1405 URL: nar/04hlnihrga9fq93qb1sggq8cqaqcfps0hqaaz866mp0qcwr69aq8.nar.zst1406 Compression: zstd1407 NarHash: sha256:04hlnihrga9fq93qb1sggq8cqaqcfps0hqaaz866mp0qcwr69aq81408 NarSize: 2161409 References: /build/TestClientPushesUseOnePush1637573817/001/store/rk0v1s8j9dja8p5g55h6jym71hfc616y-shared-dep1410 CA: text:sha256:1b3cmykvg5bdb452wizp98v9y80h9zya4gxgp7snlsv8cyqiqz3b14112026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes14122026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14132026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14142026/10/07 06:18:06 WARN Failed to register uploaded object key=jjlmp97dy9ifxpibrx0x27jqd9hhyxb3.ls error="server returned 404: 404 page not found\n"14152026/10/07 06:18:06 INFO Signed narinfos id=2 count=114162026/10/07 06:18:06 INFO Uploading 1 narinfos1417 client_pushes_test.go:97: Retrieved narinfo from S3:1418 StorePath: /build/TestClientPushesUseOnePush1637573817/001/store/rq95lbycf3xdq22mf104vlvm6y9a3d6s-b1419 URL: nar/04hlnihrga9fq93qb1sggq8cqaqcfps0hqaaz866mp0qcwr69aq8.nar.zst1420 Compression: zstd1421 NarHash: sha256:04hlnihrga9fq93qb1sggq8cqaqcfps0hqaaz866mp0qcwr69aq81422 NarSize: 2161423 References: /build/TestClientPushesUseOnePush1637573817/001/store/rk0v1s8j9dja8p5g55h6jym71hfc616y-shared-dep1424 CA: text:sha256:1b3cmykvg5bdb452wizp98v9y80h9zya4gxgp7snlsv8cyqiqz3b1425--- PASS: TestObjectStatsTrigger (0.31s)1426=== CONT TestOrphanedObjectsGC14272026/10/07 06:18:06 INFO Received complete push request method=POST path=/api/pushes/2/complete14282026/10/07 06:18:06 WARN Failed to register uploaded object key=jjlmp97dy9ifxpibrx0x27jqd9hhyxb3.narinfo error="server returned 404: 404 page not found\n"1429--- PASS: TestClientPushesUseOnePush (0.54s)1430=== CONT TestMetricsCommit14312026/10/07 06:18:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14322026/10/07 06:18:06 WARN mTLS auth: bound subjects configured but subject DN unavailable14332026/10/07 06:18:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1434--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.29s)1435=== CONT TestServerTLSConfig1436=== RUN TestServerTLSConfig/no_client_CA1437=== PAUSE TestServerTLSConfig/no_client_CA1438=== RUN TestServerTLSConfig/missing_CA_file1439=== PAUSE TestServerTLSConfig/missing_CA_file1440=== RUN TestServerTLSConfig/not_a_PEM_file1441=== PAUSE TestServerTLSConfig/not_a_PEM_file1442=== CONT TestGenerateLandingPage1443--- PASS: TestGenerateLandingPage (0.00s)1444=== CONT TestService_readinessHandler14452026/10/07 06:18:06 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14462026/10/07 06:18:06 INFO Uploading 9kzmyl5x9f3qc3168m7m8ypwf5g06d0r-top (224B)14472026/10/07 06:18:06 INFO Uploading cjv3j8fl93x20fix85bmmqxjxzr82lxc-shared-dep (136B)14482026/10/07 06:18:06 INFO Completed push id=2 objects=3 duration=7.708348ms14492026/10/07 06:18:06 INFO Upload complete. (56ms)14502026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/0isdlv7kj9iv5hm8znhd4a2lwv1dyc38s0klfnsr84f4bciwhf3c.nar.zst error="server returned 404: 404 page not found\n"14512026/10/07 06:18:06 WARN Failed to register uploaded object key=9kzmyl5x9f3qc3168m7m8ypwf5g06d0r.ls error="server returned 404: 404 page not found\n"14522026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14532026/10/07 06:18:06 WARN Failed to register uploaded object key=cjv3j8fl93x20fix85bmmqxjxzr82lxc.ls error="server returned 404: 404 page not found\n"14542026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14552026/10/07 06:18:06 INFO Signed narinfos id=1 count=214562026/10/07 06:18:06 INFO Uploading 2 narinfos1457=== NAME TestClientMultipleUploads1458 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads380973719/001/store/zkihwyn7fwxngab5vhl6irkdxp8k8hqa-test-file-2.txt14592026/10/07 06:18:06 WARN Failed to register uploaded object key=9kzmyl5x9f3qc3168m7m8ypwf5g06d0r.narinfo error="server returned 404: 404 page not found\n"14602026/10/07 06:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete14612026/10/07 06:18:06 WARN Failed to register uploaded object key=cjv3j8fl93x20fix85bmmqxjxzr82lxc.narinfo error="server returned 404: 404 page not found\n"14622026/10/07 06:18:06 INFO Completed push id=1 objects=6 duration=7.702688ms14632026/10/07 06:18:06 INFO Upload complete. (68ms)1464=== NAME TestClientSharedPathCommittedMidPush1465 client_integration_test.go:680: Retrieved narinfo from S3:1466 StorePath: /build/TestClientSharedPathCommittedMidPush312995983/001/store/cjv3j8fl93x20fix85bmmqxjxzr82lxc-shared-dep1467 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1468 Compression: zstd1469 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821470 NarSize: 1361471 References: 1472 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1473--- PASS: TestService_ReadScope_PublicByDefault (0.31s)1474=== CONT TestCacheConfigHandlerMaxNarSize1475--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1476=== CONT TestClientIntegration1477=== NAME TestClientSharedPathCommittedMidPush1478 client_integration_test.go:680: Retrieved narinfo from S3:1479 StorePath: /build/TestClientSharedPathCommittedMidPush312995983/001/store/9kzmyl5x9f3qc3168m7m8ypwf5g06d0r-top1480 URL: nar/0isdlv7kj9iv5hm8znhd4a2lwv1dyc38s0klfnsr84f4bciwhf3c.nar.zst1481 Compression: zstd1482 NarHash: sha256:0isdlv7kj9iv5hm8znhd4a2lwv1dyc38s0klfnsr84f4bciwhf3c1483 NarSize: 2241484 References: /build/TestClientSharedPathCommittedMidPush312995983/001/store/cjv3j8fl93x20fix85bmmqxjxzr82lxc-shared-dep1485 CA: text:sha256:1h8yhf2s0g9cih05yprm9vwq904q55936fbdxr8nv11wrjr0jns414862026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes1487--- PASS: TestClientSharedPathCommittedMidPush (0.51s)1488=== CONT TestCreatePendingClosureRejectsOversizedNAR14892026/10/07 06:18:06 INFO Received uploads request method=POST path=/api/pending_closures1490--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1491=== CONT TestService_AuthMiddleware_MTLSProxyHeader14922026/10/07 06:18:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14932026/10/07 06:18:06 INFO Uploading 7283cp45p9kiwcvy7ys3r1hhj0n6xd2w-ca-test (144B)14942026/10/07 06:18:06 WARN Failed to register uploaded object key=log/wljw15iyw6qxg8lzbjjdp91nsadrjq9g-ca-test.drv error="server returned 404: 404 page not found\n"14952026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14962026/10/07 06:18:06 WARN Failed to register uploaded object key=7283cp45p9kiwcvy7ys3r1hhj0n6xd2w.ls error="server returned 404: 404 page not found\n"14972026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14982026/10/07 06:18:06 INFO Signed narinfos id=1 count=114992026/10/07 06:18:06 INFO Uploading 1 narinfos15002026/10/07 06:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete15012026/10/07 06:18:06 WARN Failed to register uploaded object key=7283cp45p9kiwcvy7ys3r1hhj0n6xd2w.narinfo error="server returned 404: 404 page not found\n"15022026/10/07 06:18:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures15032026/10/07 06:18:06 INFO Garbage collection started15042026/10/07 06:18:06 INFO Completed push id=1 objects=4 duration=11.914505ms15052026/10/07 06:18:06 INFO Upload complete. (103ms)15062026/10/07 06:18:06 INFO Aborted multipart uploads count=0 kept=015072026/10/07 06:18:06 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15082026/10/07 06:18:06 WARN Refused reserved pin name=worker-x86_64-linux15092026/10/07 06:18:06 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15102026/10/07 06:18:06 INFO Received create pin request method=POST path=/api/pins/my-app15112026/10/07 06:18:06 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1512--- PASS: TestCreatePin_ReservedPins (0.51s)1513=== CONT TestNARDeduplicationMetadataUploadBug1514=== NAME TestClientCADerivations1515 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations939891663/001/store/7283cp45p9kiwcvy7ys3r1hhj0n6xd2w-ca-test1516 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1517 Compression: zstd1518 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1519 NarSize: 1441520 References: 1521 Deriver: /build/TestClientCADerivations939891663/001/store/wljw15iyw6qxg8lzbjjdp91nsadrjq9g-ca-test.drv1522 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1523 client_ca_test.go:185: Checking for realisation files in S3...1524 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1525 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15262026/10/07 06:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period15272026/10/07 06:18:06 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=015282026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes15292026/10/07 06:18:06 INFO Vacuumed table table=pending_closures1530--- PASS: TestMetricsInventory (0.26s)1531=== CONT TestParseSingleRange/none1532=== CONT TestParseSingleRange/open-ended1533=== CONT TestParseSingleRange/start_far_past_EOF1534=== CONT TestParseSingleRange/start_past_EOF1535=== CONT TestParseSingleRange/single_byte1536=== CONT TestParseSingleRange/suffix_exceeds_size1537=== CONT TestParseSingleRange/suffix1538=== CONT TestParseSingleRange/end_clamped_to_size1539=== CONT TestParseSingleRange/malformed_both_empty1540=== CONT TestParseSingleRange/closed1541=== CONT TestParseSingleRange/malformed_end_before_start1542=== CONT TestParseSingleRange/multi-range_ignored1543=== CONT TestParseSingleRange/malformed_no_dash1544=== CONT TestParseSingleRange/unknown_unit1545=== CONT TestPendingClosureWriteTimeout/empty1546=== CONT TestPendingClosureWriteTimeout/670k_objects1547=== CONT TestPendingClosureWriteTimeout/400_objects1548=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1549--- PASS: TestParseSingleRange (0.00s)1550 --- PASS: TestParseSingleRange/none (0.00s)1551 --- PASS: TestParseSingleRange/open-ended (0.00s)1552 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1553 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1554 --- PASS: TestParseSingleRange/single_byte (0.00s)1555 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1556 --- PASS: TestParseSingleRange/suffix (0.00s)1557 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1558 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1559 --- PASS: TestParseSingleRange/closed (0.00s)1560 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1561 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1562 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1563 --- PASS: TestParseSingleRange/unknown_unit (0.00s)15642026/10/07 06:18:06 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15652026/10/07 06:18:06 INFO Uploading fcf966c0100w787ai1n6n8a8bmpj26bj-test-file-0.txt (160B)15662026/10/07 06:18:06 INFO Uploading zkihwyn7fwxngab5vhl6irkdxp8k8hqa-test-file-2.txt (160B)15672026/10/07 06:18:06 INFO Uploading 79dlawyfkw0wxsv8jbp8xmlh6vwkn5yv-test-file-1.txt (160B)1568--- PASS: TestService_ReadAuthMiddleware (0.21s)1569=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15702026/10/07 06:18:06 INFO Received complete multipart upload request method=POST path=/15712026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15722026/10/07 06:18:06 WARN Failed to register uploaded object key=fcf966c0100w787ai1n6n8a8bmpj26bj.ls error="server returned 404: 404 page not found\n"15732026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15742026/10/07 06:18:06 WARN Failed to register uploaded object key=zkihwyn7fwxngab5vhl6irkdxp8k8hqa.ls error="server returned 404: 404 page not found\n"15752026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15762026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15772026/10/07 06:18:06 WARN Failed to register uploaded object key=79dlawyfkw0wxsv8jbp8xmlh6vwkn5yv.ls error="server returned 404: 404 page not found\n"15782026/10/07 06:18:06 INFO Signed narinfos id=1 count=315792026/10/07 06:18:06 INFO Uploading 3 narinfos15802026/10/07 06:18:06 INFO Vacuumed table table=pending_objects15812026/10/07 06:18:06 INFO Vacuumed table table=multipart_uploads15822026/10/07 06:18:06 INFO Vacuumed table table=closures15832026/10/07 06:18:06 WARN Failed to register uploaded object key=zkihwyn7fwxngab5vhl6irkdxp8k8hqa.narinfo error="server returned 404: 404 page not found\n"15842026/10/07 06:18:06 WARN Failed to register uploaded object key=79dlawyfkw0wxsv8jbp8xmlh6vwkn5yv.narinfo error="server returned 404: 404 page not found\n"15852026/10/07 06:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete15862026/10/07 06:18:06 WARN Failed to register uploaded object key=fcf966c0100w787ai1n6n8a8bmpj26bj.narinfo error="server returned 404: 404 page not found\n"15872026/10/07 06:18:06 INFO Vacuumed table table=objects15882026/10/07 06:18:06 INFO Completed push id=1 objects=9 duration=6.638879ms15892026/10/07 06:18:06 INFO Upload complete. (62ms)1590=== NAME TestClientMultipleUploads1591 client_integration_test.go:369: Uploaded 3 paths in 97.130858ms1592=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1593=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1594=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1595=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1596=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1597=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1598=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1599=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1600=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16012026/10/07 06:18:06 INFO Received uploads request method=POST path=/1602--- PASS: TestClientMultipleUploads (0.59s)1603=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16042026/10/07 06:18:06 INFO Received request for more parts method=POST path=/16052026/10/07 06:18:06 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16062026/10/07 06:18:06 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1607--- PASS: TestService_NativeMTLS (0.19s)1608=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16092026/10/07 06:18:06 INFO Received uploads request method=POST path=/1610=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16112026/10/07 06:18:06 INFO Received complete multipart upload request method=POST path=/1612=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16132026/10/07 06:18:06 INFO Received request for more parts method=POST path=/1614=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16152026/10/07 06:18:06 INFO Received uploads request method=POST path=/1616--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1617 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1618 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1619 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1620 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1621=== CONT TestIsValidUploadKey/narinfo1622=== CONT TestIsValidUploadKey/unknown_type1623=== CONT TestIsValidUploadKey/empty_key1624=== CONT TestIsValidUploadKey/absolute1625=== CONT TestIsValidUploadKey/traversal_nar1626=== CONT TestIsValidUploadKey/traversal1627=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1628=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1629=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1630=== CONT TestIsValidUploadKey/index.html1631=== CONT TestIsValidUploadKey/nix-cache-info1632=== CONT TestIsValidUploadKey/realisation_plus_in_output1633=== CONT TestIsValidUploadKey/build_log1634=== CONT TestIsValidUploadKey/listing1635=== CONT TestIsValidUploadKey/nar_plain1636=== CONT TestIsValidUploadKey/nar_xz1637=== CONT TestIsValidUploadKey/nar_zst1638=== CONT TestIsValidUploadKey/build_log_equals1639=== CONT TestIsValidUploadKey/realisation1640=== CONT TestIsValidUploadKey/build_log_home-manager_file1641=== CONT TestIsValidUploadKey/build_log_question_mark1642=== CONT TestIsValidUploadKey/build_log_plus_in_name1643--- PASS: TestIsValidUploadKey (0.00s)1644 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1645 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1646 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1647 --- PASS: TestIsValidUploadKey/absolute (0.00s)1648 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1649 --- PASS: TestIsValidUploadKey/traversal (0.00s)1650 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1651 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1652 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1653 --- PASS: TestIsValidUploadKey/index.html (0.00s)1654 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1655 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1656 --- PASS: TestIsValidUploadKey/build_log (0.00s)1657 --- PASS: TestIsValidUploadKey/listing (0.00s)1658 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1659 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1660 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1661 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1662 --- PASS: TestIsValidUploadKey/realisation (0.00s)1663 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1664 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1665 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1666=== CONT TestPush_RejectsBadRequests/no_roots16672026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes1668=== CONT TestPush_RejectsBadRequests/root_not_in_objects16692026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes1670=== CONT TestPush_RejectsBadRequests/bad_root16712026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes1672=== CONT TestPush_RejectsBadRequests/no_objects16732026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes1674=== CONT TestIsValidCachePath/narinfo1675--- PASS: TestPush_RejectsBadRequests (0.35s)1676 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1677 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1678 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1679 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1680=== CONT TestIsValidCachePath/index.html1681=== CONT TestIsValidCachePath/short_hash1682=== CONT TestIsValidCachePath/wrong_extension1683=== CONT TestIsValidCachePath/leading_slash1684=== CONT TestIsValidCachePath/invalid_char_e1685=== CONT TestIsValidCachePath/traversal_in_middle1686=== CONT TestIsValidCachePath/traversal_parent1687=== CONT TestIsValidCachePath/empty1688=== CONT TestIsValidCachePath/invalid_char_u1689=== CONT TestIsValidCachePath/nar_uncompressed1690=== CONT TestIsValidCachePath/nix-cache-info1691=== CONT TestIsValidCachePath/random_path1692=== CONT TestIsValidCachePath/realisation1693=== CONT TestIsValidCachePath/ls1694=== CONT TestIsValidCachePath/log1695=== CONT TestIsValidCachePath/nar_xz1696=== CONT TestIsValidCachePath/nar_bz21697=== CONT TestIsValidCachePath/nar_zst1698=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1699--- PASS: TestIsValidCachePath (0.00s)1700 --- PASS: TestIsValidCachePath/narinfo (0.00s)1701 --- PASS: TestIsValidCachePath/index.html (0.00s)1702 --- PASS: TestIsValidCachePath/short_hash (0.00s)1703 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1704 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1705 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1706 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1707 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1708 --- PASS: TestIsValidCachePath/empty (0.00s)1709 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1710 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1711 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1712 --- PASS: TestIsValidCachePath/random_path (0.00s)1713 --- PASS: TestIsValidCachePath/realisation (0.00s)1714 --- PASS: TestIsValidCachePath/ls (0.00s)1715 --- PASS: TestIsValidCachePath/log (0.00s)1716 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1717 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1718 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1719 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1720=== CONT TestGCEndsOnShutdown/before_the_run1721=== NAME TestClientCADerivations1722 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1723 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1724 error: binary cache 's3://bucket67?endpoint=http://localhost:35851®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations939891663/001/store'1725 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11726=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1727--- PASS: TestClientCADerivations (0.68s)1728=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1729=== CONT TestProxyWriteTimeout/narinfo1730=== CONT TestProxyWriteTimeout/10_GiB_nar1731=== CONT TestProxyWriteTimeout/1_GiB_nar1732=== CONT TestProxyWriteTimeout/unknown_size1733--- PASS: TestProxyWriteTimeout (0.00s)1734 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1735 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1736 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1737 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1738=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17392026/10/07 06:18:06 INFO Received uploads request method=POST path=/api/pending_closures1740=== RUN TestService_RequireScope_OIDC/builder_may_write1741=== PAUSE TestService_RequireScope_OIDC/builder_may_write1742=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1743=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1744=== RUN TestService_RequireScope_OIDC/ops_may_admin1745=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1746=== RUN TestService_RequireScope_OIDC/ops_may_not_write1747=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1748=== RUN TestService_RequireScope_OIDC/reader_may_not_write1749=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1750=== RUN TestService_RequireScope_OIDC/static_token_may_admin1751=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1752=== RUN TestService_RequireScope_OIDC/static_token_may_write1753=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1754=== RUN TestService_RequireScope_OIDC/reader_may_read1755=== PAUSE TestService_RequireScope_OIDC/reader_may_read1756=== RUN TestService_RequireScope_OIDC/writer_implies_read1757=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1758=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1759=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1760=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1761=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1762=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1763=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1764=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1765=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1766=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1767=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1768=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17692026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes17702026/10/07 06:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete17712026/10/07 06:18:06 WARN readiness check failed error="closed pool"1772--- PASS: TestService_readinessHandler (0.22s)1773=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale17742026/10/07 06:18:06 INFO Completed push id=1 objects=4 duration=10.889076ms17752026/10/07 06:18:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17762026/10/07 06:18:06 INFO Completed upload id=2 objects=2 duration=1.652634ms1777--- PASS: TestMetricsCommit (0.24s)1778=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1779--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.26s)1780=== CONT TestResolveDBConnectionString/flag_wins1781=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1782=== CONT TestResolveDBConnectionString/nothing_configured1783=== CONT TestResolveDBConnectionString/missing_file_is_an_error1784=== CONT TestResolveDBConnectionString/file_when_flag_empty1785=== 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: TestResolveDBConnectionString (0.00s)1790 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1791 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1792 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1793 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1794 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1795=== CONT TestClientErrorHandling/InvalidStorePath1796--- PASS: TestCacheConfigHandler (0.00s)1797 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1798 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1799 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1800 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)18012026/10/07 06:18:06 INFO Received cleanup request method=DELETE path=/api/pending_closures18022026/10/07 06:18:06 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket84/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18032026/10/07 06:18:06 INFO Aborted multipart uploads count=0 kept=118042026/10/07 06:18:06 INFO Received cleanup request method=DELETE path=/api/pending_closures18052026/10/07 06:18:06 INFO Aborted multipart uploads count=1 kept=01806=== NAME TestClientIntegration1807 client_integration_test.go:286: Created store path: /build/TestClientIntegration4115627369/002/store/sicnphh6p2xfmshr01wf26riq11smgh7-test-file.txt1808--- PASS: TestMultipartCleanup (0.36s)1809=== CONT TestClientErrorHandling/InvalidAuthToken18102026/10/07 06:18:06 INFO Received uploads request method=POST path=/api/pending_closures1811=== NAME TestNARDeduplicationMetadataUploadBug1812 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug684569688/001/store/v7xqw2g893367k7dd4zx0mm91xm09p63-file1.txt1813=== CONT TestClientErrorHandling/ServerNotAvailable18142026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes18152026/10/07 06:18:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18162026/10/07 06:18:06 INFO Uploading sicnphh6p2xfmshr01wf26riq11smgh7-test-file.txt (152B)18172026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18182026/10/07 06:18:06 WARN Failed to register uploaded object key=sicnphh6p2xfmshr01wf26riq11smgh7.ls error="server returned 404: 404 page not found\n"18192026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18202026/10/07 06:18:06 INFO Signed narinfos id=1 count=118212026/10/07 06:18:06 INFO Uploading 1 narinfos18222026/10/07 06:18:06 INFO Aborted multipart uploads count=0 kept=018232026/10/07 06:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete18242026/10/07 06:18:06 WARN Failed to register uploaded object key=sicnphh6p2xfmshr01wf26riq11smgh7.narinfo error="server returned 404: 404 page not found\n"18252026/10/07 06:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period18262026/10/07 06:18:06 INFO Completed push id=1 objects=3 duration=4.658841ms18272026/10/07 06:18:06 INFO Upload complete. (56ms)18282026/10/07 06:18:06 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:35851/bucket93/?delete=\": context canceled"1829=== CONT TestServerTLSConfig/no_client_CA1830=== CONT TestServerTLSConfig/missing_CA_file1831=== CONT TestServerTLSConfig/not_a_PEM_file1832--- PASS: TestServerTLSConfig (0.00s)1833 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1834 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1835 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1836=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1837=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1838=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18392026/10/07 06:18:06 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]1840=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18412026/10/07 06:18:06 WARN Authentication failed token_preview=eyJhbGciOi...9SBeM2qX6A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1842=== CONT TestService_RequireScope_OIDC/builder_may_write1843--- PASS: TestService_AuthMiddleware_OIDC (0.31s)1844 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1845 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1846 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1847 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1848=== CONT TestService_RequireScope_OIDC/reader_may_read1849=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1850=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18512026/10/07 06:18:06 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]1852=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1853=== CONT TestService_RequireScope_OIDC/writer_implies_read1854=== CONT TestService_RequireScope_OIDC/reader_may_not_write1855=== CONT TestService_RequireScope_OIDC/static_token_may_write1856=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1857=== CONT TestService_RequireScope_OIDC/static_token_may_admin1858=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1859=== CONT TestService_RequireScope_OIDC/ops_may_admin1860=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1861=== CONT TestService_RequireScope_OIDC/ops_may_not_write1862--- PASS: TestService_RequireScope_OIDC (0.43s)1863 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1864 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1865 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1866 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1867 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1868 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1869 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1870 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1871 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1872 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1873 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1874 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1875 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1876 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)18772026/10/07 06:18:06 INFO Aborted multipart uploads count=0 kept=018782026/10/07 06:18:06 INFO Received uploads request method=POST path=/api/pending_closures18792026/10/07 06:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period18802026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes18812026/10/07 06:18:06 INFO Aborted multipart uploads count=0 kept=018822026/10/07 06:18:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18832026/10/07 06:18:06 INFO Uploading v7xqw2g893367k7dd4zx0mm91xm09p63-file1.txt (160B)18842026/10/07 06:18:06 INFO All 1 paths already cached18852026/10/07 06:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period1886=== NAME TestClientIntegration1887 client_integration_test.go:312: Retrieved narinfo from S3:1888 StorePath: /build/TestClientIntegration4115627369/002/store/sicnphh6p2xfmshr01wf26riq11smgh7-test-file.txt1889 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1890 Compression: zstd1891 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11892 NarSize: 1521893 References: 1894 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk118952026/10/07 06:18:06 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18962026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18972026/10/07 06:18:06 WARN Failed to register uploaded object key=v7xqw2g893367k7dd4zx0mm91xm09p63.ls error="server returned 404: 404 page not found\n"18982026/10/07 06:18:06 INFO Signed narinfos id=1 count=118992026/10/07 06:18:06 INFO Uploading 1 narinfos1900 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)19012026/10/07 06:18:06 INFO Received uploads request method=POST path=/api/pending_closures1902 client_integration_test.go:313: Decompressed .ls content (64 bytes):1903 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1904 client_integration_test.go:316: Testing garbage collection...19052026/10/07 06:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete19062026/10/07 06:18:06 WARN Failed to register uploaded object key=v7xqw2g893367k7dd4zx0mm91xm09p63.narinfo error="server returned 404: 404 page not found\n"1907--- PASS: TestGCEndsOnShutdown (0.00s)1908 --- PASS: TestGCEndsOnShutdown/before_the_run (0.23s)1909 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.24s)1910 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.27s)19112026/10/07 06:18:06 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/present19122026/10/07 06:18:06 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=019132026/10/07 06:18:06 INFO Vacuumed table table=pending_closures19142026/10/07 06:18:06 INFO Vacuumed table table=pending_objects19152026/10/07 06:18:06 INFO Completed push id=1 objects=3 duration=5.370967ms19162026/10/07 06:18:06 INFO Upload complete. (55ms)19172026/10/07 06:18:06 INFO Vacuumed table table=multipart_uploads19182026/10/07 06:18:06 INFO Vacuumed table table=closures1919=== NAME TestNARDeduplicationMetadataUploadBug1920 metadata_upload_test.go:54: Retrieved narinfo from S3:1921 StorePath: /build/TestNARDeduplicationMetadataUploadBug684569688/001/store/v7xqw2g893367k7dd4zx0mm91xm09p63-file1.txt1922 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1923 Compression: zstd1924 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1925 NarSize: 1601926 References: 1927 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf19282026/10/07 06:18:06 INFO Vacuumed table table=objects19292026/10/07 06:18:06 INFO Aborted multipart uploads count=0 kept=01930 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1931 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1932 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}19332026/10/07 06:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period19342026/10/07 06:18:06 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=019352026/10/07 06:18:06 INFO Vacuumed table table=pending_closures19362026/10/07 06:18:06 INFO Vacuumed table table=pending_objects19372026/10/07 06:18:06 INFO Vacuumed table table=multipart_uploads19382026/10/07 06:18:06 INFO Vacuumed table table=closures19392026/10/07 06:18:06 INFO Vacuumed table table=objects1940--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1941 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.28s)1942 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.28s)19432026/10/07 06:18:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures19442026/10/07 06:18:06 INFO Garbage collection started19452026/10/07 06:18:06 INFO Aborted multipart uploads count=0 kept=01946=== NAME TestNARDeduplicationMetadataUploadBug1947 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug684569688/001/store/d8aqm94n8a80fqlqbm34a6ph8s906x7z-file2.txt19482026/10/07 06:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period19492026/10/07 06:18:06 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=019502026/10/07 06:18:06 INFO Vacuumed table table=pending_closures19512026/10/07 06:18:06 INFO Vacuumed table table=pending_objects19522026/10/07 06:18:06 INFO Vacuumed table table=multipart_uploads19532026/10/07 06:18:06 INFO Vacuumed table table=closures19542026/10/07 06:18:06 INFO Vacuumed table table=objects19552026/10/07 06:18:06 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.151496ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1956=== NAME TestOrphanedObjectsGC1957 orphaned_objects_gc_test.go:287: GC Test Summary:1958 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1959 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1960 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1961 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1962 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1963--- PASS: TestOrphanedObjectsGC (0.55s)19642026/10/07 06:18:06 INFO Received push request method=POST path=/api/pushes19652026/10/07 06:18:06 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19662026/10/07 06:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19672026/10/07 06:18:06 INFO Signed narinfos id=2 count=119682026/10/07 06:18:06 WARN Failed to register uploaded object key=d8aqm94n8a80fqlqbm34a6ph8s906x7z.ls error="server returned 404: 404 page not found\n"19692026/10/07 06:18:06 INFO Uploading 1 narinfos19702026/10/07 06:18:06 INFO Received complete push request method=POST path=/api/pushes/2/complete19712026/10/07 06:18:06 WARN Failed to register uploaded object key=d8aqm94n8a80fqlqbm34a6ph8s906x7z.narinfo error="server returned 404: 404 page not found\n"19722026/10/07 06:18:06 INFO Completed push id=2 objects=3 duration=1.752695ms19732026/10/07 06:18:06 INFO Upload complete. (48ms)1974=== NAME TestNARDeduplicationMetadataUploadBug1975 metadata_upload_test.go:76: Retrieved narinfo from S3:1976 StorePath: /build/TestNARDeduplicationMetadataUploadBug684569688/001/store/d8aqm94n8a80fqlqbm34a6ph8s906x7z-file2.txt1977 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1978 Compression: zstd1979 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1980 NarSize: 1601981 References: 1982 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf19832026/10/07 06:18:06 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1984 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1985 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1986 {"version":1,"root":{"type":"regular","size":44}}1987--- PASS: TestNARDeduplicationMetadataUploadBug (0.50s)19882026/10/07 06:18:06 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19892026/10/07 06:18:06 INFO lead: released remote=192.0.2.1:12341990--- PASS: TestLeadEndsOnShutdown (1.47s)19912026/10/07 06:18:06 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=429.484286ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1992--- PASS: TestObjectStatsLargeCommit (1.29s)19932026/10/07 06:18:06 INFO lead: released remote=192.0.2.1:123419942026/10/07 06:18:07 INFO lead: acquired remote=192.0.2.1:12341995--- PASS: TestDeleteClosuresRacingPins (1.66s)1996--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)1997 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.73s)1998 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.73s)1999=== NAME TestOrphanedObjectsGCStressTest2000 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2001 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2002--- PASS: TestPendingClosureWriteTimeout (0.00s)2003 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2004 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2005 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2006 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.05s)2007--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)2008 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2009 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2010 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.02s)20112026/10/07 06:18:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=797.42794ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2012=== NAME TestOrphanedObjectsGCStressTest2013 orphaned_objects_gc_test.go:503: Stress test completed successfully:2014 orphaned_objects_gc_test.go:504: - Active objects preserved: 202015 orphaned_objects_gc_test.go:505: - Objects deleted: 2102016 orphaned_objects_gc_test.go:506: - Total GC'd: 2102017--- PASS: TestOrphanedObjectsGCStressTest (1.64s)20182026/10/07 06:18:08 INFO lead: released remote=192.0.2.1:12342019--- PASS: TestLeadElectsOneAndHandsOver (2.71s)20202026/10/07 06:18:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.567974753s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20212026/10/07 06:18:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020222026/10/07 06:18:08 INFO Received create pin request method=POST path=/api/pins/myapp20232026/10/07 06:18:08 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1601719818/001/store/xjmar0x89jmlwnck4bjwnr1jb2sazd19-pinned-file.txt narinfo_key=xjmar0x89jmlwnck4bjwnr1jb2sazd19.narinfo20242026/10/07 06:18:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures20252026/10/07 06:18:08 INFO Garbage collection started20262026/10/07 06:18:08 INFO Aborted multipart uploads count=0 kept=020272026/10/07 06:18:08 WARN Force mode enabled - objects will be deleted immediately without grace period20282026/10/07 06:18:08 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=020292026/10/07 06:18:08 INFO Vacuumed table table=pending_closures20302026/10/07 06:18:08 INFO Vacuumed table table=pending_objects20312026/10/07 06:18:08 INFO Vacuumed table table=multipart_uploads20322026/10/07 06:18:08 INFO Vacuumed table table=closures20332026/10/07 06:18:08 INFO Vacuumed table table=objects20342026/10/07 06:18:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02035=== NAME TestClientIntegration2036 client_integration_test.go:323: Objects in database after GC:2037 client_integration_test.go:323: Successfully deleted all objects with GC --force2038--- PASS: TestClientIntegration (2.45s)2039--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.67s)20402026/10/07 06:18:09 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-config20412026/10/07 06:18:09 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.861573ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20422026/10/07 06:18:09 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=429.017049ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2043=== NAME TestPinProtectsFromGC2044 client_integration_test.go:840: Pin successfully protected closure from garbage collection2045--- PASS: TestPinProtectsFromGC (4.60s)20462026/10/07 06:18:10 WARN Rate limiter enabled after throttle name=s3-test rate=520472026/10/07 06:18:10 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2048=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2049 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102050 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002051--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.33s)20522026/10/07 06:18:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=866.584221ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2053--- PASS: TestConnectWaitsForAPeerMigration (5.12s)20542026/10/07 06:18:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.452149905s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20552026/10/07 06:18:12 INFO Aborted multipart uploads count=1 kept=020562026/10/07 06:18:12 INFO Received cleanup request method=DELETE path=/api/pending_closures20572026/10/07 06:18:12 INFO Aborted multipart uploads count=1 kept=02058--- PASS: TestPendingCleanupUsesOneCutoff (6.36s)20592026/10/07 06:18:12 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"20602026/10/07 06:18:12 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-config20612026/10/07 06:18:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.093052ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20622026/10/07 06:18:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=423.80436ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20632026/10/07 06:18:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=762.1613ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20642026/10/07 06:18:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.670404417s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20652026/10/07 06:18:15 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_closures20662026/10/07 06:18:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.124491ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20672026/10/07 06:18:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=368.675573ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20682026/10/07 06:18:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=723.96064ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20692026/10/07 06:18:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.648895302s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2070--- PASS: TestClientErrorHandling (0.00s)2071 --- PASS: TestClientErrorHandling/InvalidStorePath (0.22s)2072 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.29s)2073 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.50s)2074PASS20752026-10-07 06:18:19.227 UTC [128] LOG: received smart shutdown request20762026-10-07 06:18:19.231 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 120772026-10-07 06:18:19.245 UTC [133] LOG: shutting down20782026-10-07 06:18:19.246 UTC [133] LOG: checkpoint starting: shutdown immediate20792026-10-07 06:18:20.018 UTC [133] LOG: checkpoint complete: wrote 10428 buffers (63.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.168 s, sync=0.571 s, total=0.773 s; sync files=34046, longest=0.007 s, average=0.001 s; distance=531548 kB, estimate=531548 kB; lsn=0/21E7CFD0, redo lsn=0/21E7CFD020802026-10-07 06:18:20.096 UTC [128] LOG: database system is shut down2081Running OIDC tests...2082=== RUN TestAudienceForIssuer2083=== PAUSE TestAudienceForIssuer2084=== RUN TestGlobMatch2085=== PAUSE TestGlobMatch2086=== RUN TestValidateToken_ValidToken2087=== PAUSE TestValidateToken_ValidToken2088=== RUN TestValidateToken_WrongAudience2089=== PAUSE TestValidateToken_WrongAudience2090=== RUN TestValidateToken_Expired2091=== PAUSE TestValidateToken_Expired2092=== RUN TestValidateToken_BoundClaimsMismatch2093=== PAUSE TestValidateToken_BoundClaimsMismatch2094=== RUN TestValidateToken_BoundSubjectMismatch2095=== PAUSE TestValidateToken_BoundSubjectMismatch2096=== RUN TestValidateToken_MultipleProviders2097=== PAUSE TestValidateToken_MultipleProviders2098=== RUN TestValidateToken_NoMatchingProvider2099=== PAUSE TestValidateToken_NoMatchingProvider2100=== RUN TestValidateToken_KubernetesServiceAccount2101=== PAUSE TestValidateToken_KubernetesServiceAccount2102=== RUN TestNewValidator_KubernetesRequiresCA2103=== PAUSE TestNewValidator_KubernetesRequiresCA2104=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2105=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2106=== RUN TestPins_ReservedForMatchingRule2107=== PAUSE TestPins_ReservedForMatchingRule2108=== RUN TestPins_TopLevelShorthand2109=== PAUSE TestPins_TopLevelShorthand2110=== RUN TestPins_ConfigValidation2111=== PAUSE TestPins_ConfigValidation2112=== RUN TestScopes_LegacyProviderDefaultsToWrite2113=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2114=== RUN TestScopes_Rules2115=== PAUSE TestScopes_Rules2116=== RUN TestScopes_ConfigValidation2117=== PAUSE TestScopes_ConfigValidation2118=== CONT TestAudienceForIssuer2119=== CONT TestValidateToken_BoundClaimsMismatch2120=== CONT TestValidateToken_NoMatchingProvider2121=== CONT TestValidateToken_KubernetesServiceAccount2122--- PASS: TestAudienceForIssuer (0.00s)2123=== CONT TestValidateToken_ValidToken2124=== CONT TestValidateToken_WrongAudience2125=== CONT TestGlobMatch2126=== RUN TestGlobMatch/foo_foo2127=== PAUSE TestGlobMatch/foo_foo2128=== RUN TestGlobMatch/foo_bar2129=== PAUSE TestGlobMatch/foo_bar2130=== RUN TestGlobMatch/*_2131=== PAUSE TestGlobMatch/*_2132=== RUN TestGlobMatch/*_anything2133=== PAUSE TestGlobMatch/*_anything2134=== RUN TestGlobMatch/foo*_foo2135=== PAUSE TestGlobMatch/foo*_foo2136=== RUN TestGlobMatch/foo*_foobar2137=== PAUSE TestGlobMatch/foo*_foobar2138=== RUN TestGlobMatch/foo*_bar2139=== PAUSE TestGlobMatch/foo*_bar2140=== RUN TestGlobMatch/*bar_bar2141=== PAUSE TestGlobMatch/*bar_bar2142=== RUN TestGlobMatch/*bar_foobar2143=== PAUSE TestGlobMatch/*bar_foobar2144=== RUN TestGlobMatch/*bar_foo2145=== PAUSE TestGlobMatch/*bar_foo2146=== RUN TestGlobMatch/foo*bar_foobar2147=== PAUSE TestGlobMatch/foo*bar_foobar2148=== RUN TestGlobMatch/foo*bar_foo123bar2149=== PAUSE TestGlobMatch/foo*bar_foo123bar2150=== RUN TestGlobMatch/foo*bar_foobarbaz2151=== PAUSE TestGlobMatch/foo*bar_foobarbaz2152=== RUN TestGlobMatch/*/*_foo/bar2153=== PAUSE TestGlobMatch/*/*_foo/bar2154=== RUN TestGlobMatch/*/*_foo2155=== PAUSE TestGlobMatch/*/*_foo2156=== CONT TestScopes_ConfigValidation2157=== CONT TestPins_ConfigValidation2158=== CONT TestScopes_Rules2159=== CONT TestScopes_LegacyProviderDefaultsToWrite2160=== CONT TestValidateToken_Expired2161=== CONT TestValidateToken_MultipleProviders2162=== CONT TestPins_ReservedForMatchingRule2163=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2164--- PASS: TestScopes_ConfigValidation (0.00s)2165=== CONT TestPins_TopLevelShorthand2166=== CONT TestValidateToken_BoundSubjectMismatch2167--- PASS: TestPins_ConfigValidation (0.00s)2168=== CONT TestNewValidator_KubernetesRequiresCA2169=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2170=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2171=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02172=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02173=== RUN TestGlobMatch/refs/*/main_refs/heads/main2174=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2175=== RUN TestGlobMatch/fo?_foo2176=== PAUSE TestGlobMatch/fo?_foo2177=== RUN TestGlobMatch/fo?_fo2178=== PAUSE TestGlobMatch/fo?_fo2179=== RUN TestGlobMatch/fo?_fooo2180=== PAUSE TestGlobMatch/fo?_fooo2181=== RUN TestGlobMatch/?oo_foo2182=== PAUSE TestGlobMatch/?oo_foo2183=== RUN TestGlobMatch/?oo_boo2184=== PAUSE TestGlobMatch/?oo_boo2185=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2186=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2187=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2188=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2189=== CONT TestGlobMatch/foo_foo2190=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2191=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2192=== CONT TestGlobMatch/?oo_boo2193=== CONT TestGlobMatch/foo*bar_foobar2194=== CONT TestGlobMatch/*bar_foo2195=== CONT TestGlobMatch/*bar_foobar2196=== CONT TestGlobMatch/*bar_bar2197=== CONT TestGlobMatch/foo*_bar2198=== CONT TestGlobMatch/foo*_foobar2199=== CONT TestGlobMatch/foo*_foo2200=== CONT TestGlobMatch/*_anything2201=== CONT TestGlobMatch/*_2202=== CONT TestGlobMatch/foo_bar2203=== CONT TestGlobMatch/refs/*/main_refs/heads/main2204=== CONT TestGlobMatch/foo*bar_foobarbaz2205=== CONT TestGlobMatch/foo*bar_foo123bar2206=== CONT TestGlobMatch/?oo_foo2207=== CONT TestGlobMatch/fo?_fooo2208=== CONT TestGlobMatch/fo?_fo2209=== CONT TestGlobMatch/fo?_foo2210=== CONT TestGlobMatch/*/*_foo2211=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02212=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2213=== CONT TestGlobMatch/*/*_foo/bar2214--- PASS: TestGlobMatch (0.00s)2215 --- PASS: TestGlobMatch/foo_foo (0.00s)2216 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2217 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2218 --- PASS: TestGlobMatch/?oo_boo (0.00s)2219 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2220 --- PASS: TestGlobMatch/*bar_foo (0.00s)2221 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2222 --- PASS: TestGlobMatch/*bar_bar (0.00s)2223 --- PASS: TestGlobMatch/foo*_bar (0.00s)2224 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2225 --- PASS: TestGlobMatch/foo*_foo (0.00s)2226 --- PASS: TestGlobMatch/*_anything (0.00s)2227 --- PASS: TestGlobMatch/*_ (0.00s)2228 --- PASS: TestGlobMatch/foo_bar (0.00s)2229 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2230 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2231 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2232 --- PASS: TestGlobMatch/?oo_foo (0.00s)2233 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2234 --- PASS: TestGlobMatch/fo?_fo (0.00s)2235 --- PASS: TestGlobMatch/fo?_foo (0.00s)2236 --- PASS: TestGlobMatch/*/*_foo (0.00s)2237 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2238 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2239 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)22402026/10/07 06:18:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322412026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40561/oidc2242--- PASS: TestValidateToken_Expired (0.04s)2243--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)22442026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37257/oidc22452026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38223/oidc22462026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39379/oidc2247--- PASS: TestScopes_Rules (0.09s)22482026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40583/oidc2249--- PASS: TestPins_ReservedForMatchingRule (0.09s)2250--- PASS: TestValidateToken_ValidToken (0.09s)2251--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)22522026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35195/oidc2253--- PASS: TestPins_TopLevelShorthand (0.10s)22542026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43321/oidc2255--- PASS: TestValidateToken_BoundClaimsMismatch (0.11s)22562026/10/07 06:18:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36219/oidc22572026/10/07 06:18:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35135/oidc2258--- PASS: TestValidateToken_MultipleProviders (0.14s)22592026/10/07 06:18:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34915/oidc2260--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.15s)22612026/10/07 06:18:22 http: TLS handshake error from 127.0.0.1:52074: remote error: tls: bad certificate2262--- PASS: TestNewValidator_KubernetesRequiresCA (0.21s)22632026/10/07 06:18:22 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37465/oidc2264--- PASS: TestValidateToken_NoMatchingProvider (0.25s)22652026/10/07 06:18:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43749/oidc2266--- PASS: TestValidateToken_WrongAudience (0.29s)22672026/10/07 06:18:22 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:447352268--- PASS: TestValidateToken_KubernetesServiceAccount (0.34s)2269PASS2270Running hook tests...2271=== RUN TestSendPathsEmpty2272=== PAUSE TestSendPathsEmpty2273=== RUN TestQueueEnqueueAndFetch2274=== PAUSE TestQueueEnqueueAndFetch2275=== RUN TestQueueDeduplication2276=== PAUSE TestQueueDeduplication2277=== RUN TestQueueRemove2278=== PAUSE TestQueueRemove2279=== RUN TestQueueFetchBatchLimit2280=== PAUSE TestQueueFetchBatchLimit2281=== RUN TestQueueRetryMovesToBack2282=== PAUSE TestQueueRetryMovesToBack2283=== RUN TestQueueFetchRemoveLifecycle2284=== PAUSE TestQueueFetchRemoveLifecycle2285=== RUN TestQueueConcurrentWriters2286=== PAUSE TestQueueConcurrentWriters2287=== RUN TestQueueRemoveLargeClosure2288=== PAUSE TestQueueRemoveLargeClosure2289=== RUN TestServerClientIntegration2290=== PAUSE TestServerClientIntegration2291=== RUN TestServerQueueError2292=== PAUSE TestServerQueueError2293=== RUN TestGetListenerSocketActivation2294 server_test.go:210: === RUN TestGetListenerSocketActivation2295 --- PASS: TestGetListenerSocketActivation (0.00s)2296 PASS2297 2298--- PASS: TestGetListenerSocketActivation (0.01s)2299=== RUN TestDrainIsolatesPoisonPath2300=== PAUSE TestDrainIsolatesPoisonPath2301=== RUN TestRunNotBlockedByPoisonHead2302=== PAUSE TestRunNotBlockedByPoisonHead2303=== RUN TestDrainGivesUpWhenServerDown2304=== PAUSE TestDrainGivesUpWhenServerDown2305=== RUN TestFailedPathPrunedByLaterClosure2306=== PAUSE TestFailedPathPrunedByLaterClosure2307=== RUN TestWorkerUploadsAndRemoves2308=== PAUSE TestWorkerUploadsAndRemoves2309=== RUN TestWorkerSkipsGCdPaths2310=== PAUSE TestWorkerSkipsGCdPaths2311=== RUN TestWorkerPrunesClosureDeps2312=== PAUSE TestWorkerPrunesClosureDeps2313=== RUN TestDrainTimeout2314=== PAUSE TestDrainTimeout2315=== CONT TestSendPathsEmpty2316=== CONT TestFailedPathPrunedByLaterClosure2317=== CONT TestServerQueueError2318--- PASS: TestSendPathsEmpty (0.00s)2319=== CONT TestQueueFetchRemoveLifecycle2320=== CONT TestQueueRetryMovesToBack2321=== CONT TestQueueConcurrentWriters2322=== CONT TestQueueFetchBatchLimit23232026/10/07 06:18:22 ERROR Failed to queue paths error="permission denied" count=12324=== CONT TestQueueRemove2325=== CONT TestDrainGivesUpWhenServerDown2326=== CONT TestQueueDeduplication2327--- PASS: TestServerQueueError (0.00s)2328=== CONT TestRunNotBlockedByPoisonHead2329=== CONT TestQueueEnqueueAndFetch2330=== CONT TestServerClientIntegration2331=== CONT TestWorkerPrunesClosureDeps2332=== CONT TestDrainTimeout2333=== CONT TestQueueRemoveLargeClosure2334=== CONT TestDrainIsolatesPoisonPath2335--- PASS: TestServerClientIntegration (0.00s)2336=== CONT TestWorkerSkipsGCdPaths2337=== CONT TestWorkerUploadsAndRemoves23382026/10/07 06:18:22 INFO Uploading batch count=423392026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=423402026/10/07 06:18:22 INFO Upload queue status pending=223412026/10/07 06:18:22 INFO Uploading batch count=123422026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1923577564/002/bbb23432026/10/07 06:18:22 INFO Uploading batch count=223442026/10/07 06:18:22 INFO Uploading batch count=123452026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=12346--- PASS: TestQueueDeduplication (0.01s)23472026/10/07 06:18:22 INFO Uploading batch count=123482026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=12349--- PASS: TestQueueRemove (0.01s)23502026/10/07 06:18:22 INFO Upload queue status pending=32351--- PASS: TestQueueRetryMovesToBack (0.01s)23522026/10/07 06:18:22 INFO Uploading batch count=123532026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=123542026/10/07 06:18:22 INFO Upload queue status pending=22355--- PASS: TestQueueEnqueueAndFetch (0.01s)23562026/10/07 06:18:22 INFO Uploading batch count=123572026/10/07 06:18:22 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1709339347/002/nonexistent2358--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23592026/10/07 06:18:22 INFO Uploading batch count=223602026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=223612026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown584620270/002/a23622026/10/07 06:18:22 INFO Uploading batch count=12363--- PASS: TestQueueFetchBatchLimit (0.01s)23642026/10/07 06:18:22 INFO Uploading batch count=123652026/10/07 06:18:22 INFO Uploading batch count=123662026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=123672026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown584620270/002/b23682026/10/07 06:18:22 INFO Upload queue status pending=223692026/10/07 06:18:22 INFO Uploading batch count=223702026/10/07 06:18:22 INFO Uploading batch count=223712026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=223722026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown584620270/002/c23732026/10/07 06:18:22 INFO Uploading batch count=123742026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=123752026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown584620270/002/d23762026/10/07 06:18:22 ERROR Drain finished with paths left in queue remaining=123772026/10/07 06:18:22 INFO Uploading batch count=223782026/10/07 06:18:22 ERROR Upload failed error="upload failed" count=223792026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown584620270/002/e2380--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23812026/10/07 06:18:22 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown584620270/002/f23822026/10/07 06:18:22 ERROR Drain finished with paths left in queue remaining=102383--- PASS: TestDrainIsolatesPoisonPath (0.02s)2384--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2385--- PASS: TestWorkerPrunesClosureDeps (0.03s)2386--- PASS: TestWorkerUploadsAndRemoves (0.03s)2387--- PASS: TestWorkerSkipsGCdPaths (0.03s)2388--- PASS: TestQueueRemoveLargeClosure (0.08s)2389--- PASS: TestQueueConcurrentWriters (0.15s)23902026/10/07 06:18:22 ERROR Upload failed error="context deadline exceeded" count=223912026/10/07 06:18:22 ERROR Drain finished with paths left in queue remaining=42392--- PASS: TestDrainTimeout (0.21s)23932026/10/07 06:18:23 INFO Uploading batch count=123942026/10/07 06:18:23 INFO Uploading batch count=123952026/10/07 06:18:23 INFO Uploading batch count=123962026/10/07 06:18:23 ERROR Upload failed error="upload failed" count=123972026/10/07 06:18:23 INFO Uploading batch count=123982026/10/07 06:18:23 ERROR Upload failed error="upload failed" count=123992026/10/07 06:18:23 INFO Uploading batch count=124002026/10/07 06:18:23 ERROR Upload failed error="upload failed" count=124012026/10/07 06:18:23 INFO Uploading batch count=124022026/10/07 06:18:23 ERROR Upload failed error="upload failed" count=124032026/10/07 06:18:23 ERROR Drain finished with paths left in queue remaining=12404--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2405PASS2406Running signing tests...2407=== RUN TestExternalSigner2408=== PAUSE TestExternalSigner2409=== RUN TestExternalSignerWrongPublicKey2410=== PAUSE TestExternalSignerWrongPublicKey2411=== RUN TestExternalSignerErrors2412=== PAUSE TestExternalSignerErrors2413=== RUN TestExternalSignerRestartsAfterCrash2414=== PAUSE TestExternalSignerRestartsAfterCrash2415=== RUN TestExternalSignerProgramErrorKeepsProcess2416=== PAUSE TestExternalSignerProgramErrorKeepsProcess2417=== RUN TestExternalSignerClose2418=== PAUSE TestExternalSignerClose2419=== RUN TestExternalSignerRejectsInvalidPublicKey2420=== PAUSE TestExternalSignerRejectsInvalidPublicKey2421=== RUN TestExternalSignerCancellation2422=== PAUSE TestExternalSignerCancellation2423=== RUN TestGenerateFingerprint2424=== PAUSE TestGenerateFingerprint2425=== RUN TestParseSigningKey2426=== PAUSE TestParseSigningKey2427=== RUN TestSign2428=== PAUSE TestSign2429=== RUN TestSignBatch2430=== PAUSE TestSignBatch2431=== RUN TestNilKeyPublicKey2432=== PAUSE TestNilKeyPublicKey2433=== RUN TestSignErrors2434=== PAUSE TestSignErrors2435=== CONT TestExternalSigner2436=== CONT TestExternalSignerProgramErrorKeepsProcess2437=== CONT TestExternalSignerCancellation2438=== CONT TestExternalSignerRejectsInvalidPublicKey2439=== RUN TestExternalSignerRejectsInvalidPublicKey/#002440=== CONT TestExternalSignerClose2441=== CONT TestSignBatch2442=== CONT TestSignErrors2443=== CONT TestNilKeyPublicKey2444--- PASS: TestNilKeyPublicKey (0.00s)2445=== CONT TestExternalSignerErrors2446=== RUN TestExternalSignerErrors/exit_at_startup2447=== PAUSE TestExternalSignerErrors/exit_at_startup2448=== RUN TestExternalSignerErrors/wrong_shape2449=== PAUSE TestExternalSignerErrors/wrong_shape2450=== RUN TestExternalSignerErrors/program_error2451=== CONT TestExternalSignerRestartsAfterCrash2452=== CONT TestParseSigningKey2453=== RUN TestParseSigningKey/valid_32-byte_key2454=== PAUSE TestParseSigningKey/valid_32-byte_key2455=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2456=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2457=== CONT TestSign2458=== CONT TestGenerateFingerprint2459=== RUN TestGenerateFingerprint/basic_with_references2460=== CONT TestExternalSignerWrongPublicKey2461=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002462=== PAUSE TestExternalSignerErrors/program_error2463=== PAUSE TestGenerateFingerprint/basic_with_references2464=== RUN TestExternalSignerErrors/wrong_id2465=== PAUSE TestExternalSignerErrors/wrong_id2466=== RUN TestExternalSignerErrors/null_signatures2467=== PAUSE TestExternalSignerErrors/null_signatures2468=== RUN TestExternalSignerErrors/wrong_signature_name2469=== PAUSE TestExternalSignerErrors/wrong_signature_name2470=== RUN TestExternalSignerErrors/exit_on_request2471=== PAUSE TestExternalSignerErrors/exit_on_request2472=== RUN TestExternalSignerErrors/invalid_JSON2473=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2474=== PAUSE TestExternalSignerErrors/invalid_JSON2475=== RUN TestExternalSignerErrors/null2476=== PAUSE TestExternalSignerErrors/null2477=== RUN TestExternalSignerErrors/missing_signatures2478=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2479=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2480=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2481=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2482=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2483=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2484=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2485=== CONT TestExternalSignerRejectsInvalidPublicKey/#002486=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2487=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2488=== RUN TestGenerateFingerprint/no_references2489=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2490=== RUN TestParseSigningKey/no_colon2491=== PAUSE TestParseSigningKey/no_colon2492=== RUN TestParseSigningKey/empty_name2493=== PAUSE TestParseSigningKey/empty_name2494=== RUN TestParseSigningKey/invalid_base642495=== PAUSE TestExternalSignerErrors/missing_signatures2496=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2497--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2498 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2499 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2500 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2501 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2502 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2503=== PAUSE TestGenerateFingerprint/no_references2504=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2505=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2506=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2507=== PAUSE TestParseSigningKey/invalid_base642508=== RUN TestParseSigningKey/wrong_length2509=== PAUSE TestParseSigningKey/wrong_length2510=== CONT TestParseSigningKey/valid_32-byte_key2511=== CONT TestParseSigningKey/wrong_length2512=== RUN TestExternalSignerErrors/wrong_signatures_shape2513=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2514=== RUN TestExternalSignerErrors/missing_signature_name2515=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2516=== CONT TestParseSigningKey/empty_name2517=== CONT TestParseSigningKey/no_colon2518=== CONT TestParseSigningKey/invalid_base642519=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2520=== PAUSE TestExternalSignerErrors/missing_signature_name2521=== RUN TestExternalSignerErrors/invalid_signature_base642522=== PAUSE TestExternalSignerErrors/invalid_signature_base642523=== RUN TestExternalSignerErrors/too_few_signatures2524=== RUN TestGenerateFingerprint/invalid_nar_hash_length2525=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2526=== RUN TestGenerateFingerprint/invalid_store_path_prefix2527=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2528=== RUN TestGenerateFingerprint/invalid_reference_prefix2529=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2530=== CONT TestGenerateFingerprint/basic_with_references2531--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2532=== CONT TestGenerateFingerprint/invalid_nar_hash_length2533=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2534=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2535=== CONT TestGenerateFingerprint/no_references2536=== CONT TestGenerateFingerprint/invalid_reference_prefix2537=== CONT TestGenerateFingerprint/invalid_store_path_prefix2538--- PASS: TestGenerateFingerprint (0.00s)2539 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2540 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2541 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2542 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2543 --- PASS: TestGenerateFingerprint/no_references (0.00s)2544 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2545 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2546=== PAUSE TestExternalSignerErrors/too_few_signatures2547=== RUN TestExternalSignerErrors/unrequested_key2548=== PAUSE TestExternalSignerErrors/unrequested_key2549=== RUN TestExternalSignerErrors/wrong_signature_length2550=== RUN TestSignErrors/nil_key2551=== PAUSE TestSignErrors/nil_key2552=== PAUSE TestExternalSignerErrors/wrong_signature_length2553=== CONT TestExternalSignerErrors/exit_at_startup2554=== CONT TestExternalSignerErrors/missing_signatures2555=== CONT TestExternalSignerErrors/wrong_signatures_shape2556=== CONT TestExternalSignerErrors/program_error2557--- PASS: TestSign (0.00s)2558=== CONT TestExternalSignerErrors/too_few_signatures2559=== CONT TestExternalSignerErrors/wrong_shape2560=== CONT TestExternalSignerErrors/wrong_signature_name2561=== RUN TestSignErrors/nil_narinfo2562--- PASS: TestParseSigningKey (0.00s)2563 --- PASS: TestParseSigningKey/wrong_length (0.00s)2564 --- PASS: TestParseSigningKey/empty_name (0.00s)2565 --- PASS: TestParseSigningKey/no_colon (0.00s)2566 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2567 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2568 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2569=== PAUSE TestSignErrors/nil_narinfo2570=== CONT TestExternalSignerErrors/missing_signature_name2571--- PASS: TestSignBatch (0.00s)2572=== RUN TestSignErrors/invalid_narinfo2573=== PAUSE TestSignErrors/invalid_narinfo2574=== CONT TestExternalSignerErrors/invalid_signature_base642575--- PASS: TestExternalSignerClose (0.00s)2576=== CONT TestExternalSignerErrors/invalid_JSON2577=== CONT TestExternalSignerErrors/exit_on_request2578=== CONT TestExternalSignerErrors/wrong_id2579=== CONT TestExternalSignerErrors/null_signatures2580=== CONT TestExternalSignerErrors/unrequested_key2581=== CONT TestExternalSignerErrors/wrong_signature_length2582=== CONT TestExternalSignerErrors/null2583=== RUN TestSignErrors/canceled2584=== PAUSE TestSignErrors/canceled2585=== CONT TestSignErrors/nil_key2586=== CONT TestSignErrors/nil_narinfo2587=== CONT TestSignErrors/canceled2588=== CONT TestSignErrors/invalid_narinfo2589--- PASS: TestSignErrors (0.00s)2590 --- PASS: TestSignErrors/nil_key (0.00s)2591 --- PASS: TestSignErrors/nil_narinfo (0.00s)2592 --- PASS: TestSignErrors/canceled (0.00s)2593 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2594--- PASS: TestExternalSignerWrongPublicKey (0.00s)2595--- PASS: TestExternalSigner (0.01s)2596--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2597--- PASS: TestExternalSignerErrors (0.00s)2598 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2599 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2600 --- PASS: TestExternalSignerErrors/program_error (0.00s)2601 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2602 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2603 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2604 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2605 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2606 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2607 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2608 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2609 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2610 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2611 --- PASS: TestExternalSignerErrors/null (0.01s)2612 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2613 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2614--- PASS: TestExternalSignerCancellation (0.02s)2615PASS2616Running OpenBao signer tests...2617=== RUN TestSign2618=== PAUSE TestSign2619=== RUN TestSignErrors2620=== PAUSE TestSignErrors2621=== RUN TestServe2622=== PAUSE TestServe2623=== RUN TestServeRejectsGarbage2624=== PAUSE TestServeRejectsGarbage2625=== CONT TestSign2626=== CONT TestServeRejectsGarbage2627=== CONT TestServe2628=== CONT TestSignErrors2629--- PASS: TestServeRejectsGarbage (0.00s)2630=== RUN TestSignErrors/invalid_json2631=== PAUSE TestSignErrors/invalid_json2632=== RUN TestSignErrors/no_prefix2633=== PAUSE TestSignErrors/no_prefix2634=== RUN TestSignErrors/invalid_base642635=== PAUSE TestSignErrors/invalid_base642636=== RUN TestSignErrors/http_error2637=== PAUSE TestSignErrors/http_error2638=== CONT TestSignErrors/invalid_json2639=== CONT TestSignErrors/invalid_base642640=== CONT TestSignErrors/no_prefix2641=== CONT TestSignErrors/http_error2642--- PASS: TestServe (0.00s)2643--- PASS: TestSignErrors (0.00s)2644 --- PASS: TestSignErrors/http_error (0.00s)2645 --- PASS: TestSignErrors/invalid_json (0.00s)2646 --- PASS: TestSignErrors/no_prefix (0.00s)2647 --- PASS: TestSignErrors/invalid_base64 (0.00s)2648--- PASS: TestSign (0.00s)2649PASS