niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #389
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestSetClientTLSErrors101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102=== CONT TestStreamPushIsolatesFailures103=== CONT TestEncodeNixBase32104=== RUN TestEncodeNixBase32/test_string_hash105=== CONT TestStreamPushBatchesUnderLoad106=== PAUSE TestEncodeNixBase32/test_string_hash107=== RUN TestEncodeNixBase32/empty_input108=== PAUSE TestEncodeNixBase32/empty_input109=== CONT TestStreamPushReportsEveryPath110=== CONT TestFileTokenEmpty111=== CONT TestResolveStorePath112=== CONT TestShellSplitErrors113--- PASS: TestShellSplitErrors (0.00s)114=== CONT TestFileTokenReadsAndCaches115=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1162026/10/06 21:45:19 ERROR Upload failed error="bad path" count=31172026/10/06 21:45:19 WARN Rate limiter enabled after throttle name=server-test rate=5118=== CONT TestRateLimiterFeedback119=== RUN TestRateLimiterFeedback/429_enables_limiter120=== CONT TestPathInfoCACompatibility121=== CONT TestParsePathInfoJSONMultiplePaths122=== CONT TestParsePathInfoJSON123=== CONT TestPathInfoHashCompatibility124=== CONT TestGetStorePathHash125=== CONT TestConvertHashToNix32126=== CONT TestShellSplit127=== CONT TestScriptTokenCachesUntilRefresh128=== CONT TestEncodeNixBase32WithRealHash129=== CONT TestScriptTokenEmptyCommand130=== CONT TestFileTokenMissing131=== CONT TestScriptTokenNoExpiryRerunsEveryCall132=== CONT TestScriptTokenScriptFails133--- PASS: TestFileTokenReadsAndCaches (0.00s)134=== CONT TestScriptTokenBadJSON135=== CONT TestScriptTokenEmptyToken136--- PASS: TestResolveStorePath (0.00s)137=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)138--- PASS: TestFileTokenEmpty (0.00s)139--- PASS: TestShellSplit (0.00s)140--- PASS: TestScriptTokenEmptyCommand (0.00s)141--- PASS: TestEncodeNixBase32WithRealHash (0.00s)142=== RUN TestPathInfoCACompatibility/null_ca_field143=== RUN TestParsePathInfoJSON/Nix_format144=== PAUSE TestParsePathInfoJSON/Nix_format145=== CONT TestStaticToken146--- PASS: TestStaticToken (0.00s)147=== CONT TestDumpPathSingleFile148=== PAUSE TestPathInfoCACompatibility/null_ca_field149=== RUN TestGetStorePathHash/valid_store_path150=== RUN TestConvertHashToNix32/SRI_format_to_Nix32151=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32152=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths153=== CONT TestUploadMultipart_PartsInParallel154=== CONT TestDumpPathMatchesNix1552026/10/06 21:45:19 WARN Rate limiter enabled after throttle name=server-test rate=5156=== CONT TestDumpPathWriterError157=== PAUSE TestRateLimiterFeedback/429_enables_limiter158=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)159=== RUN TestParsePathInfoJSON/Lix_format160--- PASS: TestStreamPushIsolatesFailures (0.01s)161=== CONT TestUploadMultipart_SupersededByPeer162=== RUN TestPathInfoCACompatibility/old_string_format_-_text1632026/10/06 21:45:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44733164=== PAUSE TestGetStorePathHash/valid_store_path165=== CONT TestPartSizeForNAR166=== RUN TestPartSizeForNAR/zero_stays_at_minimum167=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text168=== RUN TestGetStorePathHash/basename_without_hyphen_should_error169=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive170=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum171=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths172=== CONT TestClientSignaturesByStorePath173=== CONT TestSetClientTLS174=== CONT TestSetClientTLSDoesNotMutateDefaultTransport175=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun1762026/10/06 21:45:19 WARN Rate limiter backed off name=server-test rate=5177=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon178=== RUN TestRateLimiterFeedback/503_enables_limiter1792026/10/06 21:45:19 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44733180--- PASS: TestStreamPushReportsEveryPath (0.01s)181=== RUN TestUploadMultipart_SupersededByPeer/exists182=== PAUSE TestParsePathInfoJSON/Lix_format183=== RUN TestConvertHashToNix32/already_Nix32_format184=== RUN TestPartSizeForNAR/small_stays_at_minimum185=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths186=== RUN TestSetClientTLSErrors/missing_cert_file187=== PAUSE TestUploadMultipart_SupersededByPeer/exists188=== PAUSE TestPartSizeForNAR/small_stays_at_minimum189=== RUN TestUploadMultipart_SupersededByPeer/missing190=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths191=== RUN TestParsePathInfoJSON/empty_input192=== PAUSE TestParsePathInfoJSON/empty_input193=== CONT TestFilterOversizedClosures194=== RUN TestParsePathInfoJSON/whitespace_only195=== PAUSE TestParsePathInfoJSON/whitespace_only196=== PAUSE TestUploadMultipart_SupersededByPeer/missing197=== PAUSE TestRateLimiterFeedback/503_enables_limiter198--- PASS: TestScriptTokenScriptFails (0.00s)199--- PASS: TestFileTokenMissing (0.00s)200--- PASS: TestScriptTokenBadJSON (0.01s)201--- PASS: TestClientSignaturesByStorePath (0.00s)202--- PASS: TestDoServerRequestAttachesToken (0.04s)203=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter204=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter205=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error206=== PAUSE TestConvertHashToNix32/already_Nix32_format207=== PAUSE TestSetClientTLSErrors/missing_cert_file208=== RUN TestSetClientTLSErrors/missing_key_file209=== PAUSE TestSetClientTLSErrors/missing_key_file210=== CONT TestRegisterUploadedObjectReusesConnections211=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive212=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon213=== RUN TestPathInfoCACompatibility/new_structured_format_-_text214=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI215=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI216=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512217=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512218=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum219=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum220=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts221=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts222=== CONT TestStreamPushGivesUpOnDeadServer223=== RUN TestPartSizeForNAR/1_TiB2242026/10/06 21:45:19 INFO Garbage collection started225=== PAUSE TestPartSizeForNAR/1_TiB226=== RUN TestPartSizeForNAR/5_TiB_S3_max_object227=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object228=== RUN TestPartSizeForNAR/capped_at_5_GiB229=== PAUSE TestPartSizeForNAR/capped_at_5_GiB230=== RUN TestParsePathInfoJSON/invalid_JSON2312026/10/06 21:45:19 ERROR Upload failed error="connection refused" count=20232=== PAUSE TestParsePathInfoJSON/invalid_JSON233=== RUN TestSetClientTLS/rejects_connection_without_client_cert2342026/10/06 21:45:19 ERROR Server seems unavailable, giving up on batch untried=17235=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert236=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA237=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA238=== RUN TestSetClientTLS/preserves_debug_logging_transport239=== CONT TestEncodeNixBase32/test_string_hash240=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths241=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths242=== CONT TestUploadMultipart_SupersededByPeer/missing243=== PAUSE TestSetClientTLS/preserves_debug_logging_transport244=== CONT TestUploadMultipart_SupersededByPeer/exists245=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)246=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI247=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon248=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512249=== CONT TestPartSizeForNAR/zero_stays_at_minimum250=== CONT TestPartSizeForNAR/5_TiB_S3_max_object251=== CONT TestParsePathInfoJSON/Nix_format252=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts253=== CONT TestPartSizeForNAR/1_TiB254=== CONT TestParsePathInfoJSON/whitespace_only255=== CONT TestParsePathInfoJSON/empty_input256=== CONT TestParsePathInfoJSON/Lix_format257=== CONT TestPartSizeForNAR/capped_at_5_GiB258=== CONT TestSetClientTLS/rejects_connection_without_client_cert259=== CONT TestParsePathInfoJSON/invalid_JSON260=== CONT TestPartSizeForNAR/small_stays_at_minimum261=== CONT TestSetClientTLS/preserves_debug_logging_transport262=== CONT TestStreamPushReportsSignatures263--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)264--- PASS: TestDumpPathSingleFile (0.04s)265--- PASS: TestScriptTokenEmptyToken (0.04s)266=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter267=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter268=== CONT TestRateLimiterFeedback/429_enables_limiter269=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter270=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error271=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error272=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error273=== RUN TestConvertHashToNix32/invalid_format2742026/10/06 21:45:19 WARN Rate limiter enabled after throttle name=server-test rate=5275=== PAUSE TestConvertHashToNix32/invalid_format2762026/10/06 21:45:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:43615277=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum2782026/10/06 21:45:19 ERROR Upload failed error=boom count=1279=== CONT TestRateLimiterFeedback/503_enables_limiter280=== CONT TestConvertHashToNix32/SRI_format_to_Nix32281=== CONT TestConvertHashToNix32/invalid_format282=== RUN TestSetClientTLSErrors/missing_ca_file283=== PAUSE TestSetClientTLSErrors/missing_ca_file2842026/10/06 21:45:19 WARN Rate limiter backed off name=server-test rate=5285=== RUN TestSetClientTLSErrors/invalid_ca_file286=== PAUSE TestSetClientTLSErrors/invalid_ca_file287=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text288=== RUN TestFilterOversizedClosures/no_limit_keeps_everything289=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica290=== CONT TestCaseHackSuffix291=== CONT TestEncodeNixBase32/empty_input292=== CONT TestStreamPushRequestLine293=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA294=== CONT TestSetClientTLSErrors/missing_ca_file295=== CONT TestSetClientTLSErrors/missing_key_file2962026/10/06 21:45:19 WARN Rate limiter enabled after throttle name=server-test rate=5297--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)2982026/10/06 21:45:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:35939299=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error300=== CONT TestGetStorePathHash/valid_store_path3012026/10/06 21:45:19 ERROR Upload failed error=boom count=1302--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)303 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)304 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)305--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)3062026/10/06 21:45:19 WARN Rate limiter backed off name=server-test rate=5307--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)308--- PASS: TestStreamPushReportsSignatures (0.00s)309=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3102026/10/06 21:45:19 INFO Garbage collection started311=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error312=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error313=== CONT TestSetClientTLSErrors/missing_cert_file314=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method315=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method316=== CONT TestPathInfoCACompatibility/null_ca_field317=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything318=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped319=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped320=== RUN TestFilterOversizedClosures/all_closures_skipped321=== PAUSE TestFilterOversizedClosures/all_closures_skipped322=== CONT TestFilterOversizedClosures/no_limit_keeps_everything323=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method324=== CONT TestPathInfoCACompatibility/new_structured_format_-_text325=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive326=== CONT TestSetClientTLSErrors/invalid_ca_file327=== CONT TestPathInfoCACompatibility/old_string_format_-_text328--- PASS: TestParsePathInfoJSON (0.04s)329 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)330 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)331 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)332 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)333 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)334=== CONT TestGetStorePathHash/basename_without_hyphen_should_error335=== CONT TestConvertHashToNix32/already_Nix32_format336=== CONT TestFilterOversizedClosures/all_closures_skipped3372026/10/06 21:45:19 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50338=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3392026/10/06 21:45:19 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=20003402026/10/06 21:45:19 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=0341--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)342 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)343 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)344--- PASS: TestPathInfoHashCompatibility (0.04s)345 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)346 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)347 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)348 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)349--- PASS: TestPartSizeForNAR (0.04s)350 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)351 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)352 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)353 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)354 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)355 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)356 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)357--- PASS: TestEncodeNixBase32 (0.00s)358 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)359 --- PASS: TestEncodeNixBase32/empty_input (0.00s)360--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)361--- PASS: TestRateLimiterFeedback (0.04s)362 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)363 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)364 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)365 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)366--- PASS: TestPathInfoCACompatibility (0.04s)367 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)368 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)369 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)370 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)371 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)372--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)373--- PASS: TestGetStorePathHash (0.04s)374 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)375 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)376 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)377 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)378--- PASS: TestConvertHashToNix32 (0.04s)379 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)380 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)381 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)382--- PASS: TestFilterOversizedClosures (0.00s)383 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)384 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)385 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)386--- PASS: TestSetClientTLSErrors (0.05s)387 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)388 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)390 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3912026/10/06 21:45:19 WARN Garbage collection finished on another replica. Its statistics are not available here392--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)3932026/10/06 21:45:19 http: TLS handshake error from 127.0.0.1:56764: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.00s)395 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)396 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)397 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)398--- PASS: TestStreamPushRequestLine (0.03s)399--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)400--- PASS: TestDumpPathWriterError (0.08s)401--- PASS: TestCaseHackSuffix (0.04s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.13s)404--- PASS: TestUploadMultipart_PartsInParallel (0.66s)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/postgres3307591782/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/postgres3307591782/data -l logfile start434435/build/postgres3307591782:5432 - no response4362026-10-06 21:45:21.344 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 21:45:21.344 UTC [128] LOG: listening on Unix socket "/build/postgres3307591782/.s.PGSQL.5432"4382026-10-06 21:45:21.349 UTC [135] LOG: database system was shut down at 2026-10-06 21:45:21 UTC4392026-10-06 21:45:21.355 UTC [128] LOG: database system is ready to accept connections440/build/postgres3307591782:5432 - accepting connections441{"timestamp":"2026-10-06T21:45:21.648215835Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"49d4da27-2a09-4946-b22f-c8678a515325","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(391)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/06 21:45:21 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 21:45:22 INFO lead: released remote=192.0.2.1:12344912026/10/06 21:45:22 INFO lead: acquired remote=192.0.2.1:12344922026/10/06 21:45:23 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.86s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/06 21:45:23 INFO lead: acquired remote=192.0.2.1:12345002026-10-06 21:45:25.123 UTC [574] FATAL: terminating connection due to administrator command5012026/10/06 21:45:25 INFO lead: acquired remote=192.0.2.1:12345022026/10/06 21:45:26 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/06 21:45:26 INFO lead: released remote=192.0.2.1:12345042026/10/06 21:45:26 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestService_NativeMTLS575=== PAUSE TestService_NativeMTLS576=== RUN TestServerTLSConfig577=== PAUSE TestServerTLSConfig578=== RUN TestMultipartCleanup579=== PAUSE TestMultipartCleanup580=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== RUN TestPendingCleanupUsesOneCutoff583=== PAUSE TestPendingCleanupUsesOneCutoff584=== RUN TestObjectStatsTrigger585=== PAUSE TestObjectStatsTrigger586=== RUN TestObjectStatsLargeCommit587=== PAUSE TestObjectStatsLargeCommit588=== RUN TestOrphanedObjectsGC589=== PAUSE TestOrphanedObjectsGC590=== RUN TestOrphanedObjectsGCStressTest591=== PAUSE TestOrphanedObjectsGCStressTest592=== RUN TestCreatePin_ReservedPins593=== PAUSE TestCreatePin_ReservedPins594=== RUN TestPresentReportsOnlyClosureRoots595=== PAUSE TestPresentReportsOnlyClosureRoots596=== RUN TestPresentRefreshesOnlyStaleClosures597=== PAUSE TestPresentRefreshesOnlyStaleClosures598=== RUN TestPresentNotReportedWhileGCDeletesClosure599=== PAUSE TestPresentNotReportedWhileGCDeletesClosure600=== RUN TestParseSingleRange601=== PAUSE TestParseSingleRange602=== RUN TestProxyHeadersOnlyTrustedOnSocket603=== PAUSE TestProxyHeadersOnlyTrustedOnSocket604=== RUN TestIsValidCachePath605=== PAUSE TestIsValidCachePath606=== RUN TestReadProxyNarinfo607=== PAUSE TestReadProxyNarinfo608=== RUN TestReadProxyNarinfoAlreadyDecompressed609=== PAUSE TestReadProxyNarinfoAlreadyDecompressed610=== RUN TestReadProxyContentNegotiation611=== PAUSE TestReadProxyContentNegotiation612=== RUN TestReadProxyNarStreaming613=== PAUSE TestReadProxyNarStreaming614=== RUN TestReadProxy404615=== PAUSE TestReadProxy404616=== RUN TestReadProxyInvalidPath617=== PAUSE TestReadProxyInvalidPath618=== RUN TestReadProxyHead619=== PAUSE TestReadProxyHead620=== RUN TestReadProxyOutlastsServerWriteTimeout621=== PAUSE TestReadProxyOutlastsServerWriteTimeout622=== RUN TestReadProxyConditionalGet623=== PAUSE TestReadProxyConditionalGet624=== RUN TestReadProxyRootRedirectsToIndexHTML625=== PAUSE TestReadProxyRootRedirectsToIndexHTML626=== RUN TestReadProxyDisabled627=== PAUSE TestReadProxyDisabled628=== RUN TestReadRedirectNar629=== PAUSE TestReadRedirectNar630=== RUN TestReadRedirectKeepsNarinfoProxied631=== PAUSE TestReadRedirectKeepsNarinfoProxied632=== RUN TestReadProxyRangeRequest633=== PAUSE TestReadProxyRangeRequest634=== RUN TestReadRedirectUsesPublicS3URL635=== PAUSE TestReadRedirectUsesPublicS3URL636=== RUN TestPush_OverlappingRootsStoreOneRowPerKey637=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey638=== RUN TestPush_CompleteCommitsEveryRoot639=== PAUSE TestPush_CompleteCommitsEveryRoot640=== RUN TestPush_RepeatedRootCommitsOnce641=== PAUSE TestPush_RepeatedRootCommitsOnce642=== RUN TestPush_CompleteWaitsForCleanupOfThePush643=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush644=== RUN TestPush_RootsAreLockedInByteOrder645=== PAUSE TestPush_RootsAreLockedInByteOrder646=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit647=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit648=== RUN TestPush_RejectsBadRequests649=== PAUSE TestPush_RejectsBadRequests650=== RUN TestPush_SignsNarinfosOfItsPendingObjects651=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects652=== RUN TestRedundantMultipartUpload653=== PAUSE TestRedundantMultipartUpload654=== RUN TestCompleteMultipartUpload_ErrorButObjectExists655=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists656=== RUN TestCompletedNarNotReofferedAcrossClosures657=== PAUSE TestCompletedNarNotReofferedAcrossClosures658=== RUN TestPresignedUploadRegisteredBeforeCommit659=== PAUSE TestPresignedUploadRegisteredBeforeCommit660=== RUN TestService_Rustfstest661=== PAUSE TestService_Rustfstest662=== RUN TestParseSize663=== PAUSE TestParseSize664=== RUN TestSkippedUploadsHandler665=== PAUSE TestSkippedUploadsHandler666=== RUN TestSystemdListenerNotActivated667--- PASS: TestSystemdListenerNotActivated (0.00s)668=== RUN TestWatchdogBeatsWhenHealthy669--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)670=== RUN TestWatchdogSkipsWhenUnhealthy6712026/10/06 21:45:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 21:45:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 21:45:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 21:45:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/06 21:45:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6762026/10/06 21:45:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/06 21:45:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/06 21:45:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6792026/10/06 21:45:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6802026/10/06 21:45:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"681--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)682=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle683=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle684=== RUN TestProxyWriteTimeout685=== PAUSE TestProxyWriteTimeout686=== RUN TestPendingClosureWriteTimeout687=== PAUSE TestPendingClosureWriteTimeout688=== RUN TestIsValidUploadKey689=== PAUSE TestIsValidUploadKey690=== RUN TestUploadHandlersRejectInvalidKeys691=== PAUSE TestUploadHandlersRejectInvalidKeys692=== RUN TestUploadHandlersRejectOversizedBody693=== PAUSE TestUploadHandlersRejectOversizedBody694=== RUN TestService_cleanupPendingClosuresHandler695=== PAUSE TestService_cleanupPendingClosuresHandler696=== RUN TestService_createPendingClosureHandler697=== PAUSE TestService_createPendingClosureHandler698=== RUN TestService_verifyS3Integrity699=== PAUSE TestService_verifyS3Integrity700=== RUN TestCompleteMultipartUnregistered701=== PAUSE TestCompleteMultipartUnregistered702=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT703=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT704=== CONT TestService_AuthMiddleware705=== CONT TestParseSize706--- PASS: TestParseSize (0.00s)707=== CONT TestCacheConfigHandlerMaxNarSize708=== CONT TestObjectStatsTrigger709=== CONT TestCompleteMultipartUnregistered710=== CONT TestService_verifyS3Integrity711=== CONT TestService_createPendingClosureHandler712=== CONT TestService_cleanupPendingClosuresHandler713=== CONT TestUploadHandlersRejectOversizedBody714=== CONT TestUploadHandlersRejectInvalidKeys715=== CONT TestIsValidUploadKey716=== CONT TestPendingClosureWriteTimeout717=== CONT TestProxyWriteTimeout718=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle719=== CONT TestSkippedUploadsHandler720=== CONT TestGCSweepDeliversEachKeyOnce721=== CONT TestPendingCleanupUsesOneCutoff722=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded723=== CONT TestMultipartCleanup7242026/10/06 21:45:26 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000725=== CONT TestServerTLSConfig726=== RUN TestServerTLSConfig/no_client_CA727=== PAUSE TestServerTLSConfig/no_client_CA728=== RUN TestServerTLSConfig/missing_CA_file729=== CONT TestService_NativeMTLS730=== CONT TestMetricsInventory731=== CONT TestNARDeduplicationMetadataUploadBug732=== CONT TestCreatePendingClosureRejectsOversizedNAR733=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT7342026/10/06 21:45:26 INFO Received uploads request method=POST path=/api/pending_closures735--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)736--- PASS: TestSkippedUploadsHandler (0.01s)737=== CONT TestGenerateLandingPage738=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info739=== RUN TestIsValidUploadKey/narinfo740=== RUN TestPendingClosureWriteTimeout/empty741=== RUN TestProxyWriteTimeout/narinfo742=== CONT TestService_readinessHandler743=== PAUSE TestServerTLSConfig/missing_CA_file744=== RUN TestServerTLSConfig/not_a_PEM_file745--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)746--- PASS: TestGenerateLandingPage (0.00s)747=== CONT TestGracefulShutdownDrainsInflight748=== CONT TestService_healthCheckHandler749=== PAUSE TestIsValidUploadKey/narinfo750=== RUN TestIsValidUploadKey/nar_zst751=== PAUSE TestProxyWriteTimeout/narinfo7522026/10/06 21:45:26 INFO Starting HTTP server address=127.0.0.1:37449753=== RUN TestProxyWriteTimeout/1_GiB_nar754=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info755=== PAUSE TestPendingClosureWriteTimeout/empty7562026/10/06 21:45:26 INFO Shutdown signal received, draining in-flight requests timeout=10s757=== PAUSE TestServerTLSConfig/not_a_PEM_file758=== PAUSE TestIsValidUploadKey/nar_zst759=== RUN TestIsValidUploadKey/nar_xz760=== PAUSE TestIsValidUploadKey/nar_xz761=== RUN TestIsValidUploadKey/nar_plain762=== PAUSE TestProxyWriteTimeout/1_GiB_nar763=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal764=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal765=== PAUSE TestIsValidUploadKey/nar_plain766=== CONT TestGCTaskStore_Fail767--- PASS: TestGCTaskStore_Fail (0.00s)768=== RUN TestPendingClosureWriteTimeout/400_objects769=== PAUSE TestPendingClosureWriteTimeout/400_objects770=== RUN TestPendingClosureWriteTimeout/670k_objects771=== PAUSE TestPendingClosureWriteTimeout/670k_objects772=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline773=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline774=== RUN TestProxyWriteTimeout/10_GiB_nar775=== PAUSE TestProxyWriteTimeout/10_GiB_nar776=== RUN TestProxyWriteTimeout/unknown_size777=== PAUSE TestProxyWriteTimeout/unknown_size778=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key779=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key780=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key781=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key782=== RUN TestIsValidUploadKey/listing783=== CONT TestGCTaskStore_PhaseUpdates784--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)785=== CONT TestGCTaskStore_CompletedAllowsNewTask786--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)787=== CONT TestGCTaskStore_GetReturnsLatest788--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)789=== CONT TestGCTaskStore_GetEmpty790--- PASS: TestGCTaskStore_GetEmpty (0.00s)791=== CONT TestGCEndsOnShutdown792=== RUN TestGCEndsOnShutdown/before_the_run793=== PAUSE TestGCEndsOnShutdown/before_the_run794=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete795=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete796=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark797=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark798=== PAUSE TestIsValidUploadKey/listing799=== RUN TestIsValidUploadKey/build_log800=== CONT TestGCTaskStore_ConflictDifferentParams801--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)802=== CONT TestGCTaskStore_DeduplicateSameParams803--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)804=== CONT TestGCTaskStore_StartNew805--- PASS: TestGCTaskStore_StartNew (0.00s)806=== CONT TestGetExistingObjectsLocksRows807=== CONT TestCommitRacingPendingCleanupKeepsObjects808=== PAUSE TestIsValidUploadKey/build_log809=== RUN TestIsValidUploadKey/build_log_home-manager_file810=== PAUSE TestIsValidUploadKey/build_log_home-manager_file811=== RUN TestIsValidUploadKey/build_log_plus_in_name812=== PAUSE TestIsValidUploadKey/build_log_plus_in_name813=== RUN TestIsValidUploadKey/build_log_question_mark814=== CONT TestPushWaitsForSweepHoldingRow815=== CONT TestSweepRechecksPendingAfterLocking816=== PAUSE TestIsValidUploadKey/build_log_question_mark817=== RUN TestIsValidUploadKey/build_log_equals818=== PAUSE TestIsValidUploadKey/build_log_equals819=== RUN TestIsValidUploadKey/realisation820=== PAUSE TestIsValidUploadKey/realisation821=== RUN TestIsValidUploadKey/realisation_plus_in_output822=== PAUSE TestIsValidUploadKey/realisation_plus_in_output823=== RUN TestIsValidUploadKey/nix-cache-info824=== PAUSE TestIsValidUploadKey/nix-cache-info825=== RUN TestIsValidUploadKey/index.html826=== PAUSE TestIsValidUploadKey/index.html827=== RUN TestIsValidUploadKey/narinfo_key,_nar_type828=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type829=== RUN TestIsValidUploadKey/nar_key,_narinfo_type830=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type831=== RUN TestIsValidUploadKey/listing_key,_narinfo_type832=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type833=== RUN TestIsValidUploadKey/traversal834=== PAUSE TestIsValidUploadKey/traversal835=== RUN TestIsValidUploadKey/traversal_nar836=== PAUSE TestIsValidUploadKey/traversal_nar837=== RUN TestIsValidUploadKey/absolute838=== PAUSE TestIsValidUploadKey/absolute839=== RUN TestIsValidUploadKey/empty_key840=== PAUSE TestIsValidUploadKey/empty_key841=== RUN TestIsValidUploadKey/unknown_type842=== PAUSE TestIsValidUploadKey/unknown_type843=== CONT TestRegisterCompletedObjectNeedsPendingRow844--- PASS: TestGracefulShutdownDrainsInflight (0.14s)845=== CONT TestSweepSkipsRowsLockedByPush846=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts847=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts848=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure849=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure850=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart851=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart852=== CONT TestFailedS3DeleteKeepsTombstone853--- PASS: TestObjectStatsTrigger (0.54s)854=== CONT TestForceGCDuringPushOffersSweptObject855=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows856=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows857=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check858=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check859=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection8602026/10/06 21:45:27 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"861--- PASS: TestService_AuthMiddleware (0.55s)862=== CONT TestClientPushesUseOnePush8632026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures8642026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures8652026/10/06 21:45:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8662026/10/06 21:45:27 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst867--- PASS: TestCompleteMultipartUnregistered (0.62s)868=== CONT TestTombstonedObjectOfferedWithoutWaiting8692026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures8702026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures8712026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures8722026/10/06 21:45:27 INFO Received cleanup request method=DELETE path=/api/pending_closures8732026/10/06 21:45:27 INFO Aborted multipart uploads count=0 kept=08742026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures8752026/10/06 21:45:27 INFO Received cleanup request method=DELETE path=/api/pending_closures8762026/10/06 21:45:27 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket5/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8772026/10/06 21:45:27 INFO Aborted multipart uploads count=0 kept=18782026/10/06 21:45:27 INFO Received cleanup request method=DELETE path=/api/pending_closures8792026/10/06 21:45:27 INFO Received cleanup request method=DELETE path=/api/pending_closures8802026/10/06 21:45:27 INFO Aborted multipart uploads count=1 kept=08812026/10/06 21:45:27 INFO Aborted multipart uploads count=1 kept=08822026/10/06 21:45:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8832026-10-06 21:45:27.460 UTC [649] ERROR: Closure does not exist: id=18842026-10-06 21:45:27.460 UTC [649] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8852026-10-06 21:45:27.460 UTC [649] STATEMENT: -- name: CommitPendingClosure :exec886 SELECT commit_pending_closure($1::bigint)887 888--- PASS: TestService_cleanupPendingClosuresHandler (0.70s)889=== CONT TestGCSweepSkipsPendingObjects890--- PASS: TestMultipartCleanup (0.70s)891=== CONT TestDeduplicatedObjectsRecordedAsPending8922026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures8932026/10/06 21:45:27 INFO Aborted multipart uploads count=0 kept=08942026/10/06 21:45:27 WARN Force mode enabled - objects will be deleted immediately without grace period895--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.74s)896=== CONT TestPushDedupSurvivesConcurrentGC8972026/10/06 21:45:27 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=08982026/10/06 21:45:27 INFO Vacuumed table table=pending_closures8992026/10/06 21:45:27 INFO Vacuumed table table=pending_objects9002026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures9012026/10/06 21:45:27 INFO Vacuumed table table=multipart_uploads9022026/10/06 21:45:27 INFO Vacuumed table table=closures9032026/10/06 21:45:27 INFO Vacuumed table table=objects904--- PASS: TestGCSweepDeliversEachKeyOnce (0.76s)905=== CONT TestGCMetrics9062026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures9072026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures908--- PASS: TestService_healthCheckHandler (0.72s)909=== CONT TestGCBugBareHashReferences9102026/10/06 21:45:27 INFO Received cleanup request method=DELETE path=/api/pending_closures9112026/10/06 21:45:27 WARN readiness check failed error="closed pool"912--- PASS: TestService_readinessHandler (0.85s)913=== CONT TestGCAdvisoryLockBlocksConcurrentRun9142026/10/06 21:45:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete915=== NAME TestNARDeduplicationMetadataUploadBug916 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug740345676/001/store/vgmcid5xypqcjhxv9xg6hiby49q8hmim-file1.txt9172026/10/06 21:45:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9182026/10/06 21:45:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"919--- PASS: TestService_NativeMTLS (0.89s)920=== CONT TestLeadEndsOnShutdown9212026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures922--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.92s)923=== CONT TestLeadIncumbentAnnouncesAtOnce924--- PASS: TestMetricsInventory (0.96s)925=== CONT TestLeadElectsOneAndHandsOver9262026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures9272026/10/06 21:45:27 INFO Received push request method=POST path=/api/pushes9282026/10/06 21:45:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9292026/10/06 21:45:27 INFO Uploading vgmcid5xypqcjhxv9xg6hiby49q8hmim-file1.txt (160B)9302026/10/06 21:45:27 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9312026/10/06 21:45:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9322026/10/06 21:45:27 WARN Failed to register uploaded object key=vgmcid5xypqcjhxv9xg6hiby49q8hmim.ls error="server returned 404: 404 page not found\n"9332026/10/06 21:45:27 INFO Signed narinfos id=1 count=19342026/10/06 21:45:27 INFO Uploading 1 narinfos9352026/10/06 21:45:27 INFO Received complete push request method=POST path=/api/pushes/1/complete9362026/10/06 21:45:27 WARN Failed to register uploaded object key=vgmcid5xypqcjhxv9xg6hiby49q8hmim.narinfo error="server returned 404: 404 page not found\n"9372026/10/06 21:45:27 INFO Completed push id=19382026/10/06 21:45:27 INFO Upload complete. (74ms)939=== NAME TestNARDeduplicationMetadataUploadBug940 metadata_upload_test.go:54: Retrieved narinfo from S3:941 StorePath: /build/TestNARDeduplicationMetadataUploadBug740345676/001/store/vgmcid5xypqcjhxv9xg6hiby49q8hmim-file1.txt942 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst943 Compression: zstd944 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf945 NarSize: 160946 References: 947 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf948 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)949 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):950 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}951--- PASS: TestGetExistingObjectsLocksRows (0.94s)952=== CONT TestConnectWaitsForAPeerMigration953--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.95s)954=== CONT TestResolveDBConnectionString955=== RUN TestResolveDBConnectionString/flag_wins956=== PAUSE TestResolveDBConnectionString/flag_wins957=== RUN TestResolveDBConnectionString/file_when_flag_empty958=== PAUSE TestResolveDBConnectionString/file_when_flag_empty959=== RUN TestResolveDBConnectionString/missing_file_is_an_error960=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error961=== RUN TestResolveDBConnectionString/PGHOST_allows_empty962=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty963=== RUN TestResolveDBConnectionString/nothing_configured964=== PAUSE TestResolveDBConnectionString/nothing_configured965=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock966=== NAME TestNARDeduplicationMetadataUploadBug967 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug740345676/001/store/8gf3d8l8vk605fj6ckhdbbzwrg2svbj3-file2.txt9682026/10/06 21:45:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9692026/10/06 21:45:27 INFO Aborted multipart uploads count=0 kept=09702026/10/06 21:45:27 WARN Force mode enabled - objects will be deleted immediately without grace period9712026/10/06 21:45:27 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjBhYWI1ZTEtNDdlMy00YjhmLWE4NjYtYjk5YzQ0MDllMmM5Ljk3NTcwMGQ1LTBiNGUtNGE4YS1hM2RhLTg1OWNlNTA2YmE2ZHgxNzkxMzIzMTI3MzY0NTA5NTgy parts=109722026/10/06 21:45:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9732026/10/06 21:45:27 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=09742026/10/06 21:45:27 INFO Completed upload id=19752026/10/06 21:45:27 INFO Vacuumed table table=pending_closures9762026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures9772026/10/06 21:45:27 INFO Vacuumed table table=pending_objects9782026/10/06 21:45:27 INFO Vacuumed table table=multipart_uploads9792026/10/06 21:45:27 INFO Vacuumed table table=closures9802026/10/06 21:45:27 INFO Vacuumed table table=objects9812026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures982--- PASS: TestSweepRechecksPendingAfterLocking (1.02s)983=== CONT TestDeleteClosuresRacingPins9842026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures9852026/10/06 21:45:27 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9862026/10/06 21:45:27 WARN Found objects in DB but missing from S3, will re-upload count=1987--- PASS: TestService_verifyS3Integrity (1.12s)988=== CONT TestClientFallsBackToClosures9892026/10/06 21:45:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9902026/10/06 21:45:27 INFO Aborted multipart uploads count=0 kept=09912026/10/06 21:45:27 WARN Force mode enabled - objects will be deleted immediately without grace period9922026/10/06 21:45:27 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=09932026/10/06 21:45:27 INFO Vacuumed table table=pending_closures9942026/10/06 21:45:27 INFO Vacuumed table table=pending_objects9952026/10/06 21:45:27 INFO Vacuumed table table=multipart_uploads9962026/10/06 21:45:27 INFO Vacuumed table table=closures9972026/10/06 21:45:27 INFO Vacuumed table table=objects9982026/10/06 21:45:27 INFO Aborted multipart uploads count=0 kept=09992026/10/06 21:45:27 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjBhYWI1ZTEtNDdlMy00YjhmLWE4NjYtYjk5YzQ0MDllMmM5LmVlOTFlZTc5LTYwNmUtNGE0Ny04MGE3LTc5OThlOWYyZjRjMXgxNzkxMzIzMTI3NDA5MzU0MjUw parts=1010002026/10/06 21:45:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10012026/10/06 21:45:27 WARN Force mode enabled - objects will be deleted immediately without grace period10022026/10/06 21:45:27 INFO Completed upload id=110032026/10/06 21:45:27 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010042026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures10052026/10/06 21:45:27 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=010062026/10/06 21:45:27 INFO Vacuumed table table=pending_closures10072026/10/06 21:45:27 INFO Received push request method=POST path=/api/pushes10082026/10/06 21:45:27 INFO Vacuumed table table=pending_objects10092026/10/06 21:45:27 INFO Vacuumed table table=multipart_uploads10102026/10/06 21:45:27 INFO Vacuumed table table=closures10112026/10/06 21:45:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures10122026/10/06 21:45:27 INFO Vacuumed table table=objects10132026/10/06 21:45:27 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1014--- PASS: TestSweepSkipsRowsLockedByPush (0.99s)1015=== CONT TestCacheStatsHandler10162026/10/06 21:45:27 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10172026/10/06 21:45:27 INFO Signed narinfos id=2 count=110182026/10/06 21:45:27 WARN Failed to register uploaded object key=8gf3d8l8vk605fj6ckhdbbzwrg2svbj3.ls error="server returned 404: 404 page not found\n"10192026/10/06 21:45:27 INFO Aborted multipart uploads count=0 kept=010202026/10/06 21:45:27 INFO Uploading 1 narinfos10212026/10/06 21:45:27 INFO Received complete push request method=POST path=/api/pushes/2/complete10222026/10/06 21:45:27 WARN Failed to register uploaded object key=8gf3d8l8vk605fj6ckhdbbzwrg2svbj3.narinfo error="server returned 404: 404 page not found\n"10232026/10/06 21:45:27 INFO Completed push id=210242026/10/06 21:45:27 INFO Upload complete. (56ms)1025=== NAME TestNARDeduplicationMetadataUploadBug1026 metadata_upload_test.go:76: Retrieved narinfo from S3:1027 StorePath: /build/TestNARDeduplicationMetadataUploadBug740345676/001/store/8gf3d8l8vk605fj6ckhdbbzwrg2svbj3-file2.txt1028 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1029 Compression: zstd1030 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1031 NarSize: 1601032 References: 1033 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf10342026/10/06 21:45:27 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=01035 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1036 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1037 {"version":1,"root":{"type":"regular","size":44}}10382026/10/06 21:45:27 INFO Vacuumed table table=pending_closures1039--- PASS: TestNARDeduplicationMetadataUploadBug (1.16s)1040=== CONT TestPinProtectsFromGC10412026/10/06 21:45:27 INFO Aborted multipart uploads count=0 kept=010422026/10/06 21:45:27 INFO Vacuumed table table=pending_objects10432026/10/06 21:45:27 WARN Force mode enabled - objects will be deleted immediately without grace period10442026/10/06 21:45:27 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=010452026/10/06 21:45:27 INFO Vacuumed table table=multipart_uploads10462026/10/06 21:45:27 INFO Vacuumed table table=pending_closures10472026/10/06 21:45:27 INFO Vacuumed table table=closures10482026/10/06 21:45:27 INFO Vacuumed table table=pending_objects10492026/10/06 21:45:27 INFO Vacuumed table table=objects10502026/10/06 21:45:27 INFO Vacuumed table table=multipart_uploads10512026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures10522026/10/06 21:45:27 INFO Vacuumed table table=closures10532026/10/06 21:45:27 INFO Vacuumed table table=objects10542026/10/06 21:45:27 INFO Aborted multipart uploads count=0 kept=010552026/10/06 21:45:27 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001056--- PASS: TestService_createPendingClosureHandler (1.20s)1057=== CONT TestClientSharedPathCommittedMidPush1058--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.11s)1059=== CONT TestClientWithDependencies10602026/10/06 21:45:27 WARN Force mode enabled - objects will be deleted immediately without grace period10612026/10/06 21:45:27 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10622026/10/06 21:45:27 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1063--- PASS: TestFailedS3DeleteKeepsTombstone (1.04s)1064=== CONT TestClientMultipleUploads10652026/10/06 21:45:27 INFO Received uploads request method=POST path=/api/pending_closures1066--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.61s)1067=== CONT TestClientIntegration10682026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures10692026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures10702026/10/06 21:45:28 INFO Aborted multipart uploads count=0 kept=010712026/10/06 21:45:28 WARN Force mode enabled - objects will be deleted immediately without grace period10722026/10/06 21:45:28 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=01073--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.59s)1074=== CONT TestClientErrorHandling1075=== RUN TestClientErrorHandling/InvalidStorePath1076=== PAUSE TestClientErrorHandling/InvalidStorePath1077=== RUN TestClientErrorHandling/InvalidAuthToken1078=== PAUSE TestClientErrorHandling/InvalidAuthToken1079=== RUN TestClientErrorHandling/ServerNotAvailable1080=== PAUSE TestClientErrorHandling/ServerNotAvailable1081=== CONT TestClientCADerivations10822026/10/06 21:45:28 INFO Vacuumed table table=pending_closures10832026/10/06 21:45:28 INFO Vacuumed table table=pending_objects10842026/10/06 21:45:28 INFO Vacuumed table table=multipart_uploads10852026/10/06 21:45:28 INFO Vacuumed table table=closures10862026/10/06 21:45:28 INFO Vacuumed table table=objects1087--- PASS: TestGCSweepSkipsPendingObjects (0.62s)1088=== CONT TestReadProxyRootRedirectsToIndexHTML10892026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures10902026/10/06 21:45:28 INFO Aborted multipart uploads count=0 kept=010912026/10/06 21:45:28 WARN Force mode enabled - objects will be deleted immediately without grace period10922026/10/06 21:45:28 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=010932026/10/06 21:45:28 INFO Vacuumed table table=pending_closures10942026/10/06 21:45:28 INFO Vacuumed table table=pending_objects10952026/10/06 21:45:28 INFO Vacuumed table table=multipart_uploads10962026/10/06 21:45:28 INFO Vacuumed table table=closures10972026/10/06 21:45:28 INFO Vacuumed table table=objects1098--- PASS: TestGCMetrics (0.63s)1099=== CONT TestService_Rustfstest11002026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes11012026/10/06 21:45:28 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11022026/10/06 21:45:28 INFO Uploading n1dmz8qvrpxh0jq8ym22jr0ni8i2b11c-a (216B)11032026/10/06 21:45:28 INFO Uploading scfvqvgz3wmy04kx31bipjfvmynldvcv-shared-dep (136B)1104--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.86s)1105=== CONT TestPresignedUploadRegisteredBeforeCommit11062026/10/06 21:45:28 WARN Failed to register uploaded object key=8943wrh6g8ssgvhi6i886y3hf0c7sq8b.ls error="server returned 404: 404 page not found\n"11072026/10/06 21:45:28 WARN Failed to register uploaded object key=n1dmz8qvrpxh0jq8ym22jr0ni8i2b11c.ls error="server returned 404: 404 page not found\n"11082026/10/06 21:45:28 INFO Aborted multipart uploads count=0 kept=011092026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11102026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/1myyrc35630cm45yap3xc81zg1mbvf6nf95ra8b98c0ady8wyf9x.nar.zst error="server returned 404: 404 page not found\n"11112026/10/06 21:45:28 WARN Failed to register uploaded object key=scfvqvgz3wmy04kx31bipjfvmynldvcv.ls error="server returned 404: 404 page not found\n"11122026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11132026/10/06 21:45:28 INFO Signed narinfos id=1 count=311142026/10/06 21:45:28 INFO Uploading 3 narinfos11152026/10/06 21:45:28 WARN Failed to register uploaded object key=scfvqvgz3wmy04kx31bipjfvmynldvcv.narinfo error="server returned 404: 404 page not found\n"11162026/10/06 21:45:28 WARN Failed to register uploaded object key=8943wrh6g8ssgvhi6i886y3hf0c7sq8b.narinfo error="server returned 404: 404 page not found\n"11172026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/1/complete11182026/10/06 21:45:28 WARN Failed to register uploaded object key=n1dmz8qvrpxh0jq8ym22jr0ni8i2b11c.narinfo error="server returned 404: 404 page not found\n"11192026/10/06 21:45:28 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=011202026/10/06 21:45:28 INFO Vacuumed table table=pending_closures11212026/10/06 21:45:28 INFO Completed push id=111222026/10/06 21:45:28 INFO Upload complete. (73ms)1123=== NAME TestClientPushesUseOnePush1124 client_pushes_test.go:97: Retrieved narinfo from S3:1125 StorePath: /build/TestClientPushesUseOnePush1818937595/001/store/scfvqvgz3wmy04kx31bipjfvmynldvcv-shared-dep1126 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1127 Compression: zstd1128 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821129 NarSize: 1361130 References: 1131 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11322026/10/06 21:45:28 INFO Vacuumed table table=pending_objects11332026/10/06 21:45:28 INFO Vacuumed table table=multipart_uploads1134 client_pushes_test.go:97: Retrieved narinfo from S3:1135 StorePath: /build/TestClientPushesUseOnePush1818937595/001/store/n1dmz8qvrpxh0jq8ym22jr0ni8i2b11c-a1136 URL: nar/1myyrc35630cm45yap3xc81zg1mbvf6nf95ra8b98c0ady8wyf9x.nar.zst1137 Compression: zstd1138 NarHash: sha256:1myyrc35630cm45yap3xc81zg1mbvf6nf95ra8b98c0ady8wyf9x1139 NarSize: 2161140 References: /build/TestClientPushesUseOnePush1818937595/001/store/scfvqvgz3wmy04kx31bipjfvmynldvcv-shared-dep1141 CA: text:sha256:1jbz48cr9m7nylr7fx92fxv1m9kf1fj826wfk4z2bmq5xa6c4gw111422026/10/06 21:45:28 INFO Vacuumed table table=closures11432026/10/06 21:45:28 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"1144--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.56s)1145=== CONT TestCompletedNarNotReofferedAcrossClosures1146=== NAME TestClientPushesUseOnePush1147 client_pushes_test.go:97: Retrieved narinfo from S3:1148 StorePath: /build/TestClientPushesUseOnePush1818937595/001/store/8943wrh6g8ssgvhi6i886y3hf0c7sq8b-b1149 URL: nar/1myyrc35630cm45yap3xc81zg1mbvf6nf95ra8b98c0ady8wyf9x.nar.zst1150 Compression: zstd1151 NarHash: sha256:1myyrc35630cm45yap3xc81zg1mbvf6nf95ra8b98c0ady8wyf9x1152 NarSize: 2161153 References: /build/TestClientPushesUseOnePush1818937595/001/store/scfvqvgz3wmy04kx31bipjfvmynldvcv-shared-dep1154 CA: text:sha256:1jbz48cr9m7nylr7fx92fxv1m9kf1fj826wfk4z2bmq5xa6c4gw111552026/10/06 21:45:28 INFO Vacuumed table table=objects11562026/10/06 21:45:28 INFO Aborted multipart uploads count=0 kept=011572026/10/06 21:45:28 WARN Force mode enabled - objects will be deleted immediately without grace period11582026/10/06 21:45:28 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=01159--- PASS: TestClientPushesUseOnePush (0.89s)1160=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11612026/10/06 21:45:28 INFO Vacuumed table table=pending_closures11622026/10/06 21:45:28 INFO lead: acquired remote=192.0.2.1:123411632026/10/06 21:45:28 INFO Vacuumed table table=pending_objects11642026/10/06 21:45:28 INFO Vacuumed table table=multipart_uploads11652026/10/06 21:45:28 INFO Vacuumed table table=closures11662026/10/06 21:45:28 INFO Vacuumed table table=objects1167--- PASS: TestPushDedupSurvivesConcurrentGC (0.71s)1168=== CONT TestRedundantMultipartUpload11692026/10/06 21:45:28 INFO lead: acquired remote=192.0.2.1:123411702026/10/06 21:45:28 INFO lead: released remote=192.0.2.1:12341171--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.53s)1172=== CONT TestPush_SignsNarinfosOfItsPendingObjects11732026/10/06 21:45:28 INFO lead: acquired remote=192.0.2.1:12341174--- PASS: TestPushWaitsForSweepHoldingRow (1.40s)1175=== CONT TestPush_RejectsBadRequests1176--- PASS: TestCacheStatsHandler (0.46s)1177=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11782026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures1179--- PASS: TestGCBugBareHashReferences (0.82s)1180=== CONT TestPush_RootsAreLockedInByteOrder1181=== NAME TestPinProtectsFromGC1182 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4008821840/001/store/3sb0q85rfxx5h5z4m56s4bn3yc427an4-pinned-file.txt1183 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4008821840/001/store/s3qirm3i542hpd4wydbhg80casjn56pl-unpinned-file.txt1184--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.69s)1185=== CONT TestPush_CompleteWaitsForCleanupOfThePush1186=== NAME TestClientWithDependencies1187 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3956917382/001/store/x821z8jwxfdyji6ja9i88ds1a2yv2ya7-test-script11882026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures1189=== NAME TestClientMultipleUploads1190 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads500719887/001/store/7n56xvag521nz32ilxf9l5rb21cfpw0h-test-file-0.txt11912026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures11922026/10/06 21:45:28 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11932026/10/06 21:45:28 INFO Uploading zf8zih4nkwpriid88xmfxg2irn1q225m-a (216B)11942026/10/06 21:45:28 INFO Uploading 4nc0cy7lcz8sppsnpakgd29ls47y9ijy-shared-dep (136B)11952026/10/06 21:45:28 WARN Failed to register uploaded object key=4vx42qx6j5p0mwb5ynn37pdsb5j1bpx0.ls error="server returned 404: 404 page not found\n"11962026/10/06 21:45:28 WARN Failed to register uploaded object key=zf8zih4nkwpriid88xmfxg2irn1q225m.ls error="server returned 404: 404 page not found\n"11972026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11982026/10/06 21:45:28 WARN Failed to register uploaded object key=4nc0cy7lcz8sppsnpakgd29ls47y9ijy.ls error="server returned 404: 404 page not found\n"11992026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/1hfva1f1mhjqqyi02kvi17b8kd29krjkb1gvi2lllsvhgbxw3kqa.nar.zst error="server returned 404: 404 page not found\n"12002026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12012026/10/06 21:45:28 INFO Signed narinfos id=1 count=212022026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12032026/10/06 21:45:28 INFO Signed narinfos id=2 count=212042026/10/06 21:45:28 INFO Uploading 4 narinfos1205=== NAME TestClientWithDependencies1206 client_integration_test.go:615: Found 1 dependencies (including self)12072026/10/06 21:45:28 WARN Failed to register uploaded object key=4vx42qx6j5p0mwb5ynn37pdsb5j1bpx0.narinfo error="server returned 404: 404 page not found\n"12082026/10/06 21:45:28 WARN Failed to register uploaded object key=4nc0cy7lcz8sppsnpakgd29ls47y9ijy.narinfo error="server returned 404: 404 page not found\n"12092026/10/06 21:45:28 WARN Failed to register uploaded object key=zf8zih4nkwpriid88xmfxg2irn1q225m.narinfo error="server returned 404: 404 page not found\n"12102026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes12112026/10/06 21:45:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12122026/10/06 21:45:28 WARN Failed to register uploaded object key=4nc0cy7lcz8sppsnpakgd29ls47y9ijy.narinfo error="server returned 404: 404 page not found\n"1213=== NAME TestClientIntegration1214 client_integration_test.go:286: Created store path: /build/TestClientIntegration2786707503/002/store/q4719pb05j2awsl1bqq5hr0cfsb4gdz5-test-file.txt12152026/10/06 21:45:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12162026/10/06 21:45:28 INFO Uploading 3sb0q85rfxx5h5z4m56s4bn3yc427an4-pinned-file.txt (128B)12172026/10/06 21:45:28 INFO Completed upload id=112182026/10/06 21:45:28 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12192026/10/06 21:45:28 INFO Completed upload id=212202026/10/06 21:45:28 INFO Upload complete. (79ms)1221=== NAME TestClientMultipleUploads1222 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads500719887/001/store/blwnymg9c4jhfvkm4kgj5x95l5l2fm4x-test-file-1.txt1223=== NAME TestClientFallsBackToClosures1224 client_pushes_test.go:112: Retrieved narinfo from S3:1225 StorePath: /build/TestClientFallsBackToClosures416347326/001/store/4nc0cy7lcz8sppsnpakgd29ls47y9ijy-shared-dep1226 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1227 Compression: zstd1228 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821229 NarSize: 1361230 References: 1231 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12322026/10/06 21:45:28 WARN Failed to register uploaded object key=3sb0q85rfxx5h5z4m56s4bn3yc427an4.ls error="server returned 404: 404 page not found\n"12332026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1234 client_pushes_test.go:112: Retrieved narinfo from S3:1235 StorePath: /build/TestClientFallsBackToClosures416347326/001/store/zf8zih4nkwpriid88xmfxg2irn1q225m-a1236 URL: nar/1hfva1f1mhjqqyi02kvi17b8kd29krjkb1gvi2lllsvhgbxw3kqa.nar.zst1237 Compression: zstd1238 NarHash: sha256:1hfva1f1mhjqqyi02kvi17b8kd29krjkb1gvi2lllsvhgbxw3kqa12392026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1240 NarSize: 21612412026/10/06 21:45:28 INFO Signed narinfos id=1 count=11242 References: /build/TestClientFallsBackToClosures416347326/001/store/4nc0cy7lcz8sppsnpakgd29ls47y9ijy-shared-dep1243 CA: text:sha256:16cra9w5gpj6r02lg7j71b1024qwcddpjkqymng316scz5n39dma12442026/10/06 21:45:28 INFO Uploading 1 narinfos1245 client_pushes_test.go:112: Retrieved narinfo from S3:1246 StorePath: /build/TestClientFallsBackToClosures416347326/001/store/4vx42qx6j5p0mwb5ynn37pdsb5j1bpx0-b1247 URL: nar/1hfva1f1mhjqqyi02kvi17b8kd29krjkb1gvi2lllsvhgbxw3kqa.nar.zst1248 Compression: zstd1249 NarHash: sha256:1hfva1f1mhjqqyi02kvi17b8kd29krjkb1gvi2lllsvhgbxw3kqa1250 NarSize: 2161251 References: /build/TestClientFallsBackToClosures416347326/001/store/4nc0cy7lcz8sppsnpakgd29ls47y9ijy-shared-dep1252 CA: text:sha256:16cra9w5gpj6r02lg7j71b1024qwcddpjkqymng316scz5n39dma12532026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/1/complete12542026/10/06 21:45:28 WARN Failed to register uploaded object key=3sb0q85rfxx5h5z4m56s4bn3yc427an4.narinfo error="server returned 404: 404 page not found\n"1255--- PASS: TestClientFallsBackToClosures (0.72s)1256=== CONT TestPush_RepeatedRootCommitsOnce12572026/10/06 21:45:28 INFO Completed push id=112582026/10/06 21:45:28 INFO Upload complete. (82ms)1259--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.53s)1260=== CONT TestPush_CompleteCommitsEveryRoot1261=== NAME TestClientMultipleUploads1262 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads500719887/001/store/4191jql9006g2mxkykv2k7g0jyfq683b-test-file-2.txt12632026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes1264--- PASS: TestService_Rustfstest (0.48s)1265=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12662026/10/06 21:45:28 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12672026/10/06 21:45:28 INFO Uploading gs2cb1jnhrwi4c55a88rp5lhpc0qlwl4-top (224B)12682026/10/06 21:45:28 INFO Uploading fvzm15v98g74idkc6ckjw1avh296khz1-shared-dep (136B)12692026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes12702026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/13maz5y625l3x2j5jsih7f03ldv0r9hbpqiyv7mycbwwjjbhkh01.nar.zst error="server returned 404: 404 page not found\n"12712026/10/06 21:45:28 WARN Failed to register uploaded object key=fvzm15v98g74idkc6ckjw1avh296khz1.ls error="server returned 404: 404 page not found\n"12722026/10/06 21:45:28 WARN Failed to register uploaded object key=gs2cb1jnhrwi4c55a88rp5lhpc0qlwl4.ls error="server returned 404: 404 page not found\n"12732026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12742026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12752026/10/06 21:45:28 INFO Signed narinfos id=1 count=212762026/10/06 21:45:28 INFO Uploading 2 narinfos12772026/10/06 21:45:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12782026/10/06 21:45:28 INFO Uploading q4719pb05j2awsl1bqq5hr0cfsb4gdz5-test-file.txt (152B)12792026/10/06 21:45:28 WARN Failed to register uploaded object key=fvzm15v98g74idkc6ckjw1avh296khz1.narinfo error="server returned 404: 404 page not found\n"12802026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/1/complete12812026/10/06 21:45:28 WARN Failed to register uploaded object key=gs2cb1jnhrwi4c55a88rp5lhpc0qlwl4.narinfo error="server returned 404: 404 page not found\n"12822026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12832026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12842026/10/06 21:45:28 INFO Signed narinfos id=1 count=112852026/10/06 21:45:28 WARN Failed to register uploaded object key=q4719pb05j2awsl1bqq5hr0cfsb4gdz5.ls error="server returned 404: 404 page not found\n"12862026/10/06 21:45:28 INFO Uploading 1 narinfos12872026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/1/complete12882026/10/06 21:45:28 WARN Failed to register uploaded object key=q4719pb05j2awsl1bqq5hr0cfsb4gdz5.narinfo error="server returned 404: 404 page not found\n"12892026/10/06 21:45:28 INFO Completed push id=112902026/10/06 21:45:28 INFO Upload complete. (69ms)12912026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes1292=== NAME TestClientSharedPathCommittedMidPush12932026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures1294 client_integration_test.go:680: Retrieved narinfo from S3:1295 StorePath: /build/TestClientSharedPathCommittedMidPush4003473700/001/store/fvzm15v98g74idkc6ckjw1avh296khz1-shared-dep1296 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1297 Compression: zstd1298 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821299 NarSize: 1361300 References: 1301 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1302 client_integration_test.go:680: Retrieved narinfo from S3:1303 StorePath: /build/TestClientSharedPathCommittedMidPush4003473700/001/store/gs2cb1jnhrwi4c55a88rp5lhpc0qlwl4-top1304 URL: nar/13maz5y625l3x2j5jsih7f03ldv0r9hbpqiyv7mycbwwjjbhkh01.nar.zst1305 Compression: zstd1306 NarHash: sha256:13maz5y625l3x2j5jsih7f03ldv0r9hbpqiyv7mycbwwjjbhkh011307 NarSize: 2241308 References: /build/TestClientSharedPathCommittedMidPush4003473700/001/store/fvzm15v98g74idkc6ckjw1avh296khz1-shared-dep1309 CA: text:sha256:1j1vbvms2gnzf4w028f9y1nrbxgvjx5r42q90492d1kxr2i7kzr613102026/10/06 21:45:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13112026/10/06 21:45:28 INFO Uploading x821z8jwxfdyji6ja9i88ds1a2yv2ya7-test-script (136B)13122026/10/06 21:45:28 INFO Completed push id=113132026/10/06 21:45:28 INFO Upload complete. (63ms)13142026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13152026/10/06 21:45:28 WARN Failed to register uploaded object key=x821z8jwxfdyji6ja9i88ds1a2yv2ya7.ls error="server returned 404: 404 page not found\n"13162026/10/06 21:45:28 WARN Failed to register uploaded object key=log/s6cnamilqnsasbaxsh51i8zww727awam-test-script.drv error="server returned 404: 404 page not found\n"13172026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13182026/10/06 21:45:28 INFO Signed narinfos id=1 count=113192026/10/06 21:45:28 INFO Uploading 1 narinfos1320--- PASS: TestClientSharedPathCommittedMidPush (0.70s)1321=== CONT TestReadRedirectUsesPublicS3URL13222026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes13232026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/1/complete13242026/10/06 21:45:28 WARN Failed to register uploaded object key=x821z8jwxfdyji6ja9i88ds1a2yv2ya7.narinfo error="server returned 404: 404 page not found\n"13252026/10/06 21:45:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13262026/10/06 21:45:28 INFO Uploading s3qirm3i542hpd4wydbhg80casjn56pl-unpinned-file.txt (128B)13272026/10/06 21:45:28 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13282026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures13292026/10/06 21:45:28 WARN Failed to register uploaded object key=s3qirm3i542hpd4wydbhg80casjn56pl.ls error="server returned 404: 404 page not found\n"1330=== NAME TestClientCADerivations13312026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign1332 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3123508487/001/store/4glzx7v8jwfkgvq5v6ca8q9fslaczdpx-ca-test13332026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13342026/10/06 21:45:28 INFO Signed narinfos id=2 count=113352026/10/06 21:45:28 INFO Uploading 1 narinfos1336--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.51s)1337=== CONT TestReadProxyRangeRequest13382026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/2/complete13392026/10/06 21:45:28 INFO Completed push id=113402026/10/06 21:45:28 WARN Failed to register uploaded object key=s3qirm3i542hpd4wydbhg80casjn56pl.narinfo error="server returned 404: 404 page not found\n"13412026/10/06 21:45:28 INFO Upload complete. (72ms)13422026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures1343=== NAME TestClientWithDependencies1344 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3956917382/001/store) requires matching store prefix13452026/10/06 21:45:28 INFO Completed push id=213462026/10/06 21:45:28 INFO Upload complete. (49ms)1347--- PASS: TestClientWithDependencies (0.72s)1348=== CONT TestReadRedirectKeepsNarinfoProxied13492026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures13502026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes13512026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures1352=== NAME TestClientCADerivations1353 client_ca_test.go:139: Found 1 dependencies (including self)13542026/10/06 21:45:28 INFO All 1 paths already cached1355=== NAME TestClientIntegration1356 client_integration_test.go:312: Retrieved narinfo from S3:1357 StorePath: /build/TestClientIntegration2786707503/002/store/q4719pb05j2awsl1bqq5hr0cfsb4gdz5-test-file.txt1358 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1359 Compression: zstd1360 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11361 NarSize: 1521362 References: 1363 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11364 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1365 client_integration_test.go:313: Decompressed .ls content (64 bytes):1366 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1367 client_integration_test.go:316: Testing garbage collection...13682026/10/06 21:45:28 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13692026/10/06 21:45:28 INFO Uploading 7n56xvag521nz32ilxf9l5rb21cfpw0h-test-file-0.txt (160B)13702026/10/06 21:45:28 INFO Uploading 4191jql9006g2mxkykv2k7g0jyfq683b-test-file-2.txt (160B)13712026/10/06 21:45:28 INFO Uploading blwnymg9c4jhfvkm4kgj5x95l5l2fm4x-test-file-1.txt (160B)13722026/10/06 21:45:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures13732026/10/06 21:45:28 WARN Failed to register uploaded object key=4191jql9006g2mxkykv2k7g0jyfq683b.ls error="server returned 404: 404 page not found\n"13742026/10/06 21:45:28 INFO Garbage collection started13752026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13762026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13772026/10/06 21:45:28 WARN Failed to register uploaded object key=7n56xvag521nz32ilxf9l5rb21cfpw0h.ls error="server returned 404: 404 page not found\n"13782026/10/06 21:45:28 WARN Failed to register uploaded object key=blwnymg9c4jhfvkm4kgj5x95l5l2fm4x.ls error="server returned 404: 404 page not found\n"13792026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13802026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13812026/10/06 21:45:28 INFO Signed narinfos id=1 count=313822026/10/06 21:45:28 INFO Uploading 3 narinfos13832026/10/06 21:45:28 WARN Failed to register uploaded object key=4191jql9006g2mxkykv2k7g0jyfq683b.narinfo error="server returned 404: 404 page not found\n"13842026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/1/complete13852026/10/06 21:45:28 WARN Failed to register uploaded object key=7n56xvag521nz32ilxf9l5rb21cfpw0h.narinfo error="server returned 404: 404 page not found\n"13862026/10/06 21:45:28 WARN Failed to register uploaded object key=blwnymg9c4jhfvkm4kgj5x95l5l2fm4x.narinfo error="server returned 404: 404 page not found\n"13872026/10/06 21:45:28 INFO Aborted multipart uploads count=0 kept=013882026/10/06 21:45:28 INFO Completed push id=113892026/10/06 21:45:28 INFO Upload complete. (85ms)1390=== NAME TestClientMultipleUploads1391 client_integration_test.go:369: Uploaded 3 paths in 125.547499ms13922026/10/06 21:45:28 WARN Force mode enabled - objects will be deleted immediately without grace period13932026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes13942026/10/06 21:45:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures13952026/10/06 21:45:28 INFO Garbage collection started1396--- PASS: TestClientMultipleUploads (0.78s)1397=== CONT TestReadRedirectNar13982026/10/06 21:45:28 INFO Aborted multipart uploads count=0 kept=013992026/10/06 21:45:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14002026/10/06 21:45:28 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=014012026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14022026/10/06 21:45:28 INFO Signed narinfos id=1 count=114032026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14042026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14052026/10/06 21:45:28 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"14062026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14072026/10/06 21:45:28 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"14082026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14092026/10/06 21:45:28 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=114102026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14112026/10/06 21:45:28 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo14122026/10/06 21:45:28 WARN Force mode enabled - objects will be deleted immediately without grace period1413--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.54s)14142026/10/06 21:45:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjBhYWI1ZTEtNDdlMy00YjhmLWE4NjYtYjk5YzQ0MDllMmM5LmRiNDcwZjAwLTdmMjMtNDRhMy05NDRjLWIzN2UwM2Y4MmU1N3gxNzkxMzIzMTI4NzIyNzg1NjAy1415=== CONT TestReadProxyDisabled14162026/10/06 21:45:28 INFO Vacuumed table table=pending_closures1417=== RUN TestPush_RejectsBadRequests/no_objects1418=== PAUSE TestPush_RejectsBadRequests/no_objects1419=== RUN TestPush_RejectsBadRequests/bad_root1420=== PAUSE TestPush_RejectsBadRequests/bad_root1421=== RUN TestPush_RejectsBadRequests/root_not_in_objects1422=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1423=== RUN TestPush_RejectsBadRequests/no_roots1424=== PAUSE TestPush_RejectsBadRequests/no_roots1425=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14262026/10/06 21:45:28 INFO Vacuumed table table=pending_objects14272026/10/06 21:45:28 INFO Vacuumed table table=multipart_uploads14282026/10/06 21:45:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjBhYWI1ZTEtNDdlMy00YjhmLWE4NjYtYjk5YzQ0MDllMmM5LmRiNDcwZjAwLTdmMjMtNDRhMy05NDRjLWIzN2UwM2Y4MmU1N3gxNzkxMzIzMTI4NzIyNzg1NjAy parts=114292026/10/06 21:45:28 INFO Vacuumed table table=closures1430--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.58s)1431=== CONT TestService_ReadAuthMiddleware14322026/10/06 21:45:28 INFO Vacuumed table table=objects14332026/10/06 21:45:28 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=014342026/10/06 21:45:28 INFO Vacuumed table table=pending_closures14352026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes14362026/10/06 21:45:28 INFO Vacuumed table table=pending_objects14372026/10/06 21:45:28 INFO Vacuumed table table=multipart_uploads14382026/10/06 21:45:28 INFO Vacuumed table table=closures14392026/10/06 21:45:28 INFO Vacuumed table table=objects14402026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes14412026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes14422026/10/06 21:45:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14432026/10/06 21:45:28 INFO Uploading 4glzx7v8jwfkgvq5v6ca8q9fslaczdpx-ca-test (144B)14442026/10/06 21:45:28 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14452026-10-06 21:45:28.832 UTC [1682] ERROR: could not obtain lock on row in relation "closures"14462026-10-06 21:45:28.832 UTC [1682] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14472026/10/06 21:45:28 WARN Failed to register uploaded object key=4glzx7v8jwfkgvq5v6ca8q9fslaczdpx.ls error="server returned 404: 404 page not found\n"14482026-10-06 21:45:28.833 UTC [1682] ERROR: could not obtain lock on row in relation "closures"14492026-10-06 21:45:28.833 UTC [1682] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14502026/10/06 21:45:28 WARN Failed to register uploaded object key=log/k88h5jnpk0maygar1n1ib1ggvgazv5kq-ca-test.drv error="server returned 404: 404 page not found\n"14512026/10/06 21:45:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14522026-10-06 21:45:28.833 UTC [1682] ERROR: could not obtain lock on row in relation "closures"14532026-10-06 21:45:28.833 UTC [1682] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14542026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/1/complete14552026-10-06 21:45:28.833 UTC [1682] ERROR: could not obtain lock on row in relation "closures"14562026-10-06 21:45:28.833 UTC [1682] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14572026/10/06 21:45:28 INFO Signed narinfos id=1 count=114582026-10-06 21:45:28.834 UTC [1682] ERROR: could not obtain lock on row in relation "closures"14592026-10-06 21:45:28.834 UTC [1682] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14602026/10/06 21:45:28 INFO Uploading 1 narinfos14612026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/1/complete14622026/10/06 21:45:28 WARN Failed to register uploaded object key=4glzx7v8jwfkgvq5v6ca8q9fslaczdpx.narinfo error="server returned 404: 404 page not found\n"14632026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes1464--- PASS: TestPush_RootsAreLockedInByteOrder (0.45s)1465=== CONT TestService_ReadScope_PublicByDefault14662026/10/06 21:45:28 INFO Completed push id=114672026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes14682026/10/06 21:45:28 INFO Completed push id=114692026/10/06 21:45:28 INFO Upload complete. (99ms)1470=== NAME TestClientCADerivations1471 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3123508487/001/store/4glzx7v8jwfkgvq5v6ca8q9fslaczdpx-ca-test1472 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1473 Compression: zstd1474 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1475 NarSize: 1441476 References: 1477 Deriver: /build/TestClientCADerivations3123508487/001/store/k88h5jnpk0maygar1n1ib1ggvgazv5kq-ca-test.drv1478 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1479 client_ca_test.go:185: Checking for realisation files in S3...1480 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1481 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14822026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes14832026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/1/complete14842026/10/06 21:45:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14852026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes14862026/10/06 21:45:28 INFO Completed push id=11487--- PASS: TestPush_RepeatedRootCommitsOnce (0.30s)1488=== CONT TestCacheConfigHandler1489=== RUN TestCacheConfigHandler/full_config,_no_issuer1490=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1491=== RUN TestCacheConfigHandler/no_cache_url_configured1492=== PAUSE TestCacheConfigHandler/no_cache_url_configured1493=== RUN TestCacheConfigHandler/no_signing_keys1494=== PAUSE TestCacheConfigHandler/no_signing_keys1495=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1496=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1497=== CONT TestService_RequireScope_OIDC14982026/10/06 21:45:28 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjBhYWI1ZTEtNDdlMy00YjhmLWE4NjYtYjk5YzQ0MDllMmM5LjRmNTY1M2JhLWU5MjEtNGYyMC05NjJkLTZmNTU2NGVmMGMxM3gxNzkxMzIzMTI4Mzg4NDUyNTIz parts=1214992026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/1/complete15002026/10/06 21:45:28 INFO Received uploads request method=POST path=/api/pending_closures1501--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.71s)1502=== CONT TestIsValidCachePath1503=== RUN TestIsValidCachePath/narinfo1504=== PAUSE TestIsValidCachePath/narinfo1505=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1506=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1507=== RUN TestIsValidCachePath/nar_zst1508=== PAUSE TestIsValidCachePath/nar_zst1509=== RUN TestIsValidCachePath/nar_xz1510=== PAUSE TestIsValidCachePath/nar_xz1511=== RUN TestIsValidCachePath/nar_bz21512=== PAUSE TestIsValidCachePath/nar_bz21513=== RUN TestIsValidCachePath/nar_uncompressed1514=== PAUSE TestIsValidCachePath/nar_uncompressed1515=== RUN TestIsValidCachePath/ls1516=== PAUSE TestIsValidCachePath/ls1517=== RUN TestIsValidCachePath/log1518=== PAUSE TestIsValidCachePath/log1519=== RUN TestIsValidCachePath/realisation1520=== PAUSE TestIsValidCachePath/realisation1521=== RUN TestIsValidCachePath/nix-cache-info1522=== PAUSE TestIsValidCachePath/nix-cache-info1523=== RUN TestIsValidCachePath/index.html1524=== PAUSE TestIsValidCachePath/index.html1525=== RUN TestIsValidCachePath/traversal_parent1526=== PAUSE TestIsValidCachePath/traversal_parent15272026/10/06 21:45:28 INFO Received push request method=POST path=/api/pushes1528=== RUN TestIsValidCachePath/traversal_in_middle1529=== PAUSE TestIsValidCachePath/traversal_in_middle1530=== RUN TestIsValidCachePath/invalid_char_e1531=== PAUSE TestIsValidCachePath/invalid_char_e1532=== RUN TestIsValidCachePath/invalid_char_u1533=== PAUSE TestIsValidCachePath/invalid_char_u1534=== RUN TestIsValidCachePath/random_path1535=== PAUSE TestIsValidCachePath/random_path1536=== RUN TestIsValidCachePath/empty1537=== PAUSE TestIsValidCachePath/empty1538=== RUN TestIsValidCachePath/leading_slash1539=== PAUSE TestIsValidCachePath/leading_slash1540=== RUN TestIsValidCachePath/wrong_extension1541=== PAUSE TestIsValidCachePath/wrong_extension1542=== RUN TestIsValidCachePath/short_hash1543=== PAUSE TestIsValidCachePath/short_hash1544=== CONT TestReadProxyConditionalGet15452026/10/06 21:45:28 INFO Completed push id=11546--- PASS: TestPush_CompleteCommitsEveryRoot (0.30s)1547=== CONT TestReadProxyOutlastsServerWriteTimeout15482026/10/06 21:45:28 INFO Aborted multipart uploads count=0 kept=015492026/10/06 21:45:28 WARN Force mode enabled - objects will be deleted immediately without grace period1550--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.30s)1551=== CONT TestReadProxyHead15522026/10/06 21:45:28 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=015532026/10/06 21:45:28 INFO Vacuumed table table=pending_closures1554--- PASS: TestReadRedirectUsesPublicS3URL (0.27s)1555=== CONT TestReadProxyInvalidPath15562026/10/06 21:45:28 INFO Vacuumed table table=pending_objects15572026/10/06 21:45:28 INFO Vacuumed table table=multipart_uploads15582026/10/06 21:45:28 INFO Vacuumed table table=closures15592026/10/06 21:45:28 INFO Vacuumed table table=objects15602026/10/06 21:45:28 INFO Received complete push request method=POST path=/api/pushes/2/complete15612026/10/06 21:45:28 INFO Completed push id=21562--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.58s)1563=== CONT TestReadProxy4041564--- PASS: TestReadProxyRangeRequest (0.28s)1565=== CONT TestReadProxyNarStreaming1566=== NAME TestClientCADerivations1567 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1568 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1569 error: binary cache 's3://bucket48?endpoint=http://localhost:42733®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3123508487/001/store'1570 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11571--- PASS: TestClientCADerivations (0.93s)1572=== CONT TestReadProxyContentNegotiation1573--- PASS: TestReadRedirectKeepsNarinfoProxied (0.30s)1574=== CONT TestReadProxyNarinfoAlreadyDecompressed1575--- PASS: TestReadRedirectNar (0.25s)1576=== CONT TestReadProxyNarinfo1577--- PASS: TestReadProxyDisabled (0.25s)1578=== CONT TestPresentReportsOnlyClosureRoots15792026/10/06 21:45:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39625/oidc1580--- PASS: TestService_ReadAuthMiddleware (0.27s)1581=== CONT TestProxyHeadersOnlyTrustedOnSocket15822026/10/06 21:45:29 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15832026/10/06 21:45:29 WARN mTLS auth: bound subjects configured but subject DN unavailable15842026/10/06 21:45:29 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1585--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.30s)1586=== CONT TestParseSingleRange1587=== RUN TestParseSingleRange/none1588=== PAUSE TestParseSingleRange/none1589=== RUN TestParseSingleRange/unknown_unit1590=== PAUSE TestParseSingleRange/unknown_unit1591=== RUN TestParseSingleRange/multi-range_ignored1592=== PAUSE TestParseSingleRange/multi-range_ignored1593=== RUN TestParseSingleRange/malformed_no_dash1594=== PAUSE TestParseSingleRange/malformed_no_dash1595=== RUN TestParseSingleRange/malformed_both_empty1596=== PAUSE TestParseSingleRange/malformed_both_empty1597=== RUN TestParseSingleRange/malformed_end_before_start1598=== PAUSE TestParseSingleRange/malformed_end_before_start1599=== RUN TestParseSingleRange/closed1600=== PAUSE TestParseSingleRange/closed1601=== RUN TestParseSingleRange/open-ended1602=== PAUSE TestParseSingleRange/open-ended1603=== RUN TestParseSingleRange/end_clamped_to_size1604=== PAUSE TestParseSingleRange/end_clamped_to_size1605=== RUN TestParseSingleRange/suffix1606=== PAUSE TestParseSingleRange/suffix1607=== RUN TestParseSingleRange/suffix_exceeds_size1608=== PAUSE TestParseSingleRange/suffix_exceeds_size1609=== RUN TestParseSingleRange/single_byte1610=== PAUSE TestParseSingleRange/single_byte1611=== RUN TestParseSingleRange/start_past_EOF1612=== PAUSE TestParseSingleRange/start_past_EOF1613=== RUN TestParseSingleRange/start_far_past_EOF1614=== PAUSE TestParseSingleRange/start_far_past_EOF1615=== CONT TestPresentNotReportedWhileGCDeletesClosure1616=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1617=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1618=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1619=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1620=== CONT TestPresentRefreshesOnlyStaleClosures1621--- PASS: TestService_ReadScope_PublicByDefault (0.27s)1622=== CONT TestOrphanedObjectsGCStressTest16232026-10-06 21:45:29.169 UTC [1706] ERROR: Push does not exist: id=116242026-10-06 21:45:29.169 UTC [1706] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE16252026-10-06 21:45:29.169 UTC [1706] STATEMENT: SELECT commit_push($1)1626--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.68s)1627=== CONT TestCreatePin_ReservedPins16282026/10/06 21:45:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1629--- PASS: TestReadProxyConditionalGet (0.27s)1630=== CONT TestService_AuthMiddleware_OIDC1631--- PASS: TestReadProxyHead (0.28s)1632=== CONT TestService_AuthMiddleware_MTLSProxyHeader16332026/10/06 21:45:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42979/oidc16342026/10/06 21:45:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjBhYWI1ZTEtNDdlMy00YjhmLWE4NjYtYjk5YzQ0MDllMmM5Ljg4MmMyOTYxLTRkMmMtNDI3MC1hMmEyLTYzNTdiNGQzZmQ5ZXgxNzkxMzIzMTI4Njg2MzU4NDk4 parts=1216352026/10/06 21:45:29 INFO Received uploads request method=POST path=/api/pending_closures16362026/10/06 21:45:29 INFO Received uploads request method=POST path=/api/pending_closures1637--- PASS: TestReadProxyInvalidPath (0.29s)1638=== CONT TestOrphanedObjectsGC16392026/10/06 21:45:29 INFO lead: released remote=192.0.2.1:12341640--- PASS: TestLeadEndsOnShutdown (1.59s)1641=== CONT TestObjectStatsLargeCommit1642--- PASS: TestReadProxyNarStreaming (0.31s)1643=== CONT TestServerTLSConfig/no_client_CA1644=== CONT TestServerTLSConfig/missing_CA_file1645=== CONT TestServerTLSConfig/not_a_PEM_file1646=== CONT TestPendingClosureWriteTimeout/empty1647=== CONT TestPendingClosureWriteTimeout/670k_objects1648=== CONT TestPendingClosureWriteTimeout/400_objects1649=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1650--- PASS: TestServerTLSConfig (0.09s)1651 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1652 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1653 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)16542026/10/06 21:45:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42337/oidc1655--- PASS: TestReadProxy404 (0.35s)1656=== CONT TestProxyWriteTimeout/narinfo1657=== CONT TestProxyWriteTimeout/unknown_size1658=== CONT TestProxyWriteTimeout/10_GiB_nar1659=== CONT TestProxyWriteTimeout/1_GiB_nar1660--- PASS: TestProxyWriteTimeout (0.09s)1661 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1662 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1663 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1664 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1665=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16662026/10/06 21:45:29 INFO Received uploads request method=POST path=/1667=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16682026/10/06 21:45:29 INFO Received request for more parts method=POST path=/1669=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16702026/10/06 21:45:29 INFO Received complete multipart upload request method=POST path=/1671=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16722026/10/06 21:45:29 INFO Received uploads request method=POST path=/1673--- PASS: TestUploadHandlersRejectInvalidKeys (0.09s)1674 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1675 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1676 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1677 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1678=== CONT TestGCEndsOnShutdown/before_the_run1679--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.33s)1680=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1681--- PASS: TestDeleteClosuresRacingPins (1.50s)1682=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1683--- PASS: TestReadProxyContentNegotiation (0.41s)1684=== CONT TestIsValidUploadKey/narinfo1685=== CONT TestIsValidUploadKey/absolute1686=== CONT TestIsValidUploadKey/traversal_nar1687=== CONT TestIsValidUploadKey/traversal1688=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1689=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1690=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1691=== CONT TestIsValidUploadKey/index.html1692=== CONT TestIsValidUploadKey/nix-cache-info1693=== CONT TestIsValidUploadKey/realisation_plus_in_output1694=== CONT TestIsValidUploadKey/realisation1695=== CONT TestIsValidUploadKey/build_log_equals1696=== CONT TestIsValidUploadKey/build_log_question_mark1697=== CONT TestIsValidUploadKey/build_log_plus_in_name1698=== CONT TestIsValidUploadKey/build_log_home-manager_file1699=== CONT TestIsValidUploadKey/build_log1700=== CONT TestIsValidUploadKey/listing1701=== CONT TestIsValidUploadKey/empty_key1702=== CONT TestIsValidUploadKey/nar_zst1703=== CONT TestIsValidUploadKey/nar_plain1704=== CONT TestIsValidUploadKey/nar_xz1705=== CONT TestIsValidUploadKey/unknown_type1706--- PASS: TestIsValidUploadKey (0.09s)1707 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1708 --- PASS: TestIsValidUploadKey/absolute (0.00s)1709 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1710 --- PASS: TestIsValidUploadKey/traversal (0.00s)1711 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1712 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1713 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1714 --- PASS: TestIsValidUploadKey/index.html (0.00s)1715 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1716 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1717 --- PASS: TestIsValidUploadKey/realisation (0.00s)1718 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1719 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1720 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1721 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1722 --- PASS: TestIsValidUploadKey/build_log (0.00s)1723 --- PASS: TestIsValidUploadKey/listing (0.00s)1724 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1725 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1726 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1727 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1728 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1729=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17302026/10/06 21:45:29 INFO Received request for more parts method=POST path=/1731--- PASS: TestPresentReportsOnlyClosureRoots (0.39s)1732=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17332026/10/06 21:45:29 INFO Received complete multipart upload request method=POST path=/1734=== RUN TestService_RequireScope_OIDC/builder_may_write1735=== PAUSE TestService_RequireScope_OIDC/builder_may_write1736=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1737=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1738=== RUN TestService_RequireScope_OIDC/ops_may_admin1739=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1740=== RUN TestService_RequireScope_OIDC/ops_may_not_write1741=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1742=== RUN TestService_RequireScope_OIDC/reader_may_not_write1743=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1744=== RUN TestService_RequireScope_OIDC/static_token_may_admin1745=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1746=== RUN TestService_RequireScope_OIDC/static_token_may_write1747=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1748=== RUN TestService_RequireScope_OIDC/reader_may_read1749=== PAUSE TestService_RequireScope_OIDC/reader_may_read1750=== RUN TestService_RequireScope_OIDC/writer_implies_read1751=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1752=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1753=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1754=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1755=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1756=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1757=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1758=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1759=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1760=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1761=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1762=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17632026/10/06 21:45:29 INFO Received uploads request method=POST path=/17642026/10/06 21:45:29 INFO Starting HTTP server address=127.0.0.1:3932117652026/10/06 21:45:29 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2722197310/001/proxy.sock17662026/10/06 21:45:29 WARN mTLS auth: subject not in bound subjects subject="CN=someone"17672026/10/06 21:45:29 INFO Shutdown signal received, draining in-flight requests timeout=10s1768--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.42s)1769=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1770=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1771=== CONT TestResolveDBConnectionString/flag_wins1772=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1773=== CONT TestResolveDBConnectionString/nothing_configured1774=== CONT TestResolveDBConnectionString/missing_file_is_an_error1775=== CONT TestResolveDBConnectionString/file_when_flag_empty1776=== CONT TestClientErrorHandling/InvalidStorePath1777--- PASS: TestResolveDBConnectionString (0.00s)1778 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1779 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1780 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1781 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1782 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17832026/10/06 21:45:29 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1784--- PASS: TestReadProxyNarinfo (0.49s)1785=== CONT TestClientErrorHandling/ServerNotAvailable1786--- PASS: TestPresentRefreshesOnlyStaleClosures (0.42s)1787=== CONT TestClientErrorHandling/InvalidAuthToken17882026/10/06 21:45:29 INFO lead: released remote=192.0.2.1:12341789--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.33s)1790=== CONT TestPush_RejectsBadRequests/no_objects17912026/10/06 21:45:29 INFO Received push request method=POST path=/api/pushes1792=== CONT TestPush_RejectsBadRequests/root_not_in_objects17932026/10/06 21:45:29 INFO Received push request method=POST path=/api/pushes1794=== CONT TestPush_RejectsBadRequests/no_roots17952026/10/06 21:45:29 INFO Received push request method=POST path=/api/pushes1796=== CONT TestPush_RejectsBadRequests/bad_root17972026/10/06 21:45:29 INFO Received push request method=POST path=/api/pushes1798=== CONT TestCacheConfigHandler/full_config,_no_issuer1799--- PASS: TestPush_RejectsBadRequests (0.52s)1800 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1801 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1802 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1803 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1804=== CONT TestCacheConfigHandler/no_signing_keys1805=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1806=== CONT TestCacheConfigHandler/no_cache_url_configured1807=== CONT TestIsValidCachePath/narinfo1808=== CONT TestIsValidCachePath/index.html1809=== CONT TestIsValidCachePath/short_hash1810=== CONT TestIsValidCachePath/wrong_extension1811=== CONT TestIsValidCachePath/invalid_char_e1812=== CONT TestIsValidCachePath/traversal_in_middle1813=== CONT TestIsValidCachePath/traversal_parent1814=== CONT TestIsValidCachePath/invalid_char_u1815--- PASS: TestCacheConfigHandler (0.00s)1816 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1817 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1818 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1819 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1820=== CONT TestIsValidCachePath/nar_uncompressed1821=== CONT TestIsValidCachePath/leading_slash1822=== CONT TestIsValidCachePath/nix-cache-info1823=== CONT TestIsValidCachePath/empty1824=== CONT TestIsValidCachePath/realisation1825=== CONT TestIsValidCachePath/random_path1826=== CONT TestIsValidCachePath/log1827=== CONT TestIsValidCachePath/nar_xz1828=== CONT TestIsValidCachePath/nar_bz21829=== CONT TestIsValidCachePath/nar_zst1830=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1831=== CONT TestIsValidCachePath/ls1832--- PASS: TestIsValidCachePath (0.00s)1833 --- PASS: TestIsValidCachePath/narinfo (0.00s)1834 --- PASS: TestIsValidCachePath/index.html (0.00s)1835 --- PASS: TestIsValidCachePath/short_hash (0.00s)1836 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1837 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1838 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1839 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1840 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1841 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1842 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1843 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1844 --- PASS: TestIsValidCachePath/empty (0.00s)1845 --- PASS: TestIsValidCachePath/realisation (0.00s)1846 --- PASS: TestIsValidCachePath/random_path (0.00s)1847 --- PASS: TestIsValidCachePath/log (0.00s)1848 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1849 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1850 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1851 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1852 --- PASS: TestIsValidCachePath/ls (0.00s)1853=== CONT TestParseSingleRange/none1854=== CONT TestParseSingleRange/open-ended1855=== CONT TestParseSingleRange/start_far_past_EOF1856=== CONT TestParseSingleRange/start_past_EOF1857=== CONT TestParseSingleRange/single_byte1858=== CONT TestParseSingleRange/suffix_exceeds_size1859=== CONT TestParseSingleRange/suffix1860=== CONT TestParseSingleRange/end_clamped_to_size1861=== CONT TestParseSingleRange/malformed_both_empty1862=== CONT TestParseSingleRange/malformed_end_before_start1863=== CONT TestParseSingleRange/multi-range_ignored1864=== CONT TestParseSingleRange/malformed_no_dash1865=== CONT TestParseSingleRange/unknown_unit1866=== CONT TestParseSingleRange/closed1867--- PASS: TestParseSingleRange (0.00s)1868 --- PASS: TestParseSingleRange/none (0.00s)1869 --- PASS: TestParseSingleRange/open-ended (0.00s)1870 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1871 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1872 --- PASS: TestParseSingleRange/single_byte (0.00s)1873 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1874 --- PASS: TestParseSingleRange/suffix (0.00s)1875 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1876 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1877 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1878 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1879 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1880 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1881 --- PASS: TestParseSingleRange/closed (0.00s)1882=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18832026/10/06 21:45:29 INFO lead: acquired remote=192.0.2.1:123418842026/10/06 21:45:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18852026/10/06 21:45:29 WARN Refused reserved pin name=worker-x86_64-linux18862026/10/06 21:45:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18872026/10/06 21:45:29 INFO Received create pin request method=POST path=/api/pins/my-app18882026/10/06 21:45:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1889--- PASS: TestCreatePin_ReservedPins (0.41s)1890=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18912026/10/06 21:45:29 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/present18922026/10/06 21:45:29 INFO Received uploads request method=POST path=/api/pending_closures18932026/10/06 21:45:29 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.183863ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1894=== CONT TestService_RequireScope_OIDC/builder_may_write1895=== CONT TestService_RequireScope_OIDC/reader_may_read1896=== CONT TestService_RequireScope_OIDC/static_token_may_write1897=== CONT TestService_RequireScope_OIDC/static_token_may_admin1898=== CONT TestService_RequireScope_OIDC/reader_may_not_write1899=== CONT TestService_RequireScope_OIDC/ops_may_not_write1900=== CONT TestService_RequireScope_OIDC/ops_may_admin1901=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1902=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19032026/10/06 21:45:29 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]1904=== CONT TestService_RequireScope_OIDC/writer_implies_read1905=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1906=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1907=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1908=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1909--- PASS: TestService_RequireScope_OIDC (0.56s)1910 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1911 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1912 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1913 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1914 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1915 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1916 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1917 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1918 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1919 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1920 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1921 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1922 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1923 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)19242026/10/06 21:45:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1925=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1926=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1927=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1928=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1929=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1930=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1931=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1932=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1933=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1934=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19352026/10/06 21:45:29 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]1936=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1937=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19382026/10/06 21:45:29 WARN Authentication failed token_preview=eyJhbGciOi...z69R4i-sjg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1939--- PASS: TestService_AuthMiddleware_OIDC (0.64s)1940 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1941 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1942 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1943 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19442026/10/06 21:45:29 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjBhYWI1ZTEtNDdlMy00YjhmLWE4NjYtYjk5YzQ0MDllMmM5LmIzY2E4MGFlLTlmNTgtNGI2My04NTBhLWIzNjdjZjgyNDAzYXgxNzkxMzIzMTI5MjI3NTk1OTY3 error="Get \"http://127.0.0.1:1/bucket53/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"19452026/10/06 21:45:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjBhYWI1ZTEtNDdlMy00YjhmLWE4NjYtYjk5YzQ0MDllMmM5LmQ0M2RiYWVlLThhMzgtNGJjYS1iYWI4LWU4MmU3YTAxM2EzNHgxNzkxMzIzMTI5MjIwMzU0NTgz parts=1219462026/10/06 21:45:29 INFO Received cleanup request method=DELETE path=/api/pending_closures19472026/10/06 21:45:29 INFO Aborted multipart uploads count=1 kept=01948--- PASS: TestRedundantMultipartUpload (1.64s)19492026/10/06 21:45:29 INFO Aborted multipart uploads count=0 kept=019502026/10/06 21:45:29 WARN Force mode enabled - objects will be deleted immediately without grace period19512026/10/06 21:45:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=380.095266ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19522026/10/06 21:45:29 INFO Aborted multipart uploads count=0 kept=019532026/10/06 21:45:29 WARN Force mode enabled - objects will be deleted immediately without grace period19542026/10/06 21:45:29 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:42733/bucket93/?delete=\": context canceled"1955--- PASS: TestGCEndsOnShutdown (0.00s)1956 --- PASS: TestGCEndsOnShutdown/before_the_run (0.40s)1957 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.56s)1958 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.52s)19592026/10/06 21:45:29 INFO Received uploads request method=POST path=/api/pending_closures19602026/10/06 21:45:29 INFO Aborted multipart uploads count=0 kept=019612026/10/06 21:45:29 WARN Force mode enabled - objects will be deleted immediately without grace period19622026/10/06 21:45:29 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=019632026/10/06 21:45:29 INFO Vacuumed table table=pending_closures19642026/10/06 21:45:29 INFO Vacuumed table table=pending_objects19652026/10/06 21:45:29 INFO Vacuumed table table=multipart_uploads19662026/10/06 21:45:29 INFO Vacuumed table table=closures19672026/10/06 21:45:29 INFO Vacuumed table table=objects19682026/10/06 21:45:29 INFO Received uploads request method=POST path=/api/pending_closures1969=== NAME TestOrphanedObjectsGC1970 orphaned_objects_gc_test.go:287: GC Test Summary:1971 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1972 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1973 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1974 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1975 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1976--- PASS: TestOrphanedObjectsGC (0.69s)19772026/10/06 21:45:29 INFO Aborted multipart uploads count=0 kept=019782026/10/06 21:45:29 WARN Force mode enabled - objects will be deleted immediately without grace period19792026/10/06 21:45:29 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=019802026/10/06 21:45:29 INFO Vacuumed table table=pending_closures19812026/10/06 21:45:29 INFO Vacuumed table table=pending_objects19822026/10/06 21:45:29 INFO Vacuumed table table=multipart_uploads19832026/10/06 21:45:29 INFO Vacuumed table table=closures19842026/10/06 21:45:29 INFO Vacuumed table table=objects1985--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1986 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.48s)1987 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.51s)19882026/10/06 21:45:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19892026/10/06 21:45:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1990--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)1991 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1992 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.08s)1993 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.69s)19942026/10/06 21:45:30 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=837.68032ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1995--- PASS: TestObjectStatsLargeCommit (1.10s)1996--- PASS: TestPendingClosureWriteTimeout (0.09s)1997 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1998 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1999 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2000 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.21s)2001--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2002 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.95s)2003 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.94s)20042026/10/06 21:45:30 INFO lead: released remote=192.0.2.1:12342005--- PASS: TestLeadElectsOneAndHandsOver (2.92s)20062026/10/06 21:45:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020072026/10/06 21:45:30 INFO Received create pin request method=POST path=/api/pins/myapp20082026/10/06 21:45:30 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4008821840/001/store/3sb0q85rfxx5h5z4m56s4bn3yc427an4-pinned-file.txt narinfo_key=3sb0q85rfxx5h5z4m56s4bn3yc427an4.narinfo20092026/10/06 21:45:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures20102026/10/06 21:45:30 INFO Garbage collection started20112026/10/06 21:45:30 INFO Aborted multipart uploads count=0 kept=020122026/10/06 21:45:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020132026/10/06 21:45:30 WARN Force mode enabled - objects will be deleted immediately without grace period2014=== NAME TestClientIntegration2015 client_integration_test.go:323: Objects in database after GC:2016 client_integration_test.go:323: Successfully deleted all objects with GC --force20172026/10/06 21:45:30 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=020182026/10/06 21:45:30 INFO Vacuumed table table=pending_closures20192026/10/06 21:45:30 INFO Vacuumed table table=pending_objects20202026/10/06 21:45:30 INFO Vacuumed table table=multipart_uploads2021--- PASS: TestClientIntegration (2.77s)20222026/10/06 21:45:30 INFO Vacuumed table table=closures20232026/10/06 21:45:30 INFO Vacuumed table table=objects2024=== NAME TestOrphanedObjectsGCStressTest2025 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2026 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20272026/10/06 21:45:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.657851845s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2028 orphaned_objects_gc_test.go:503: Stress test completed successfully:2029 orphaned_objects_gc_test.go:504: - Active objects preserved: 202030 orphaned_objects_gc_test.go:505: - Objects deleted: 2102031 orphaned_objects_gc_test.go:506: - Total GC'd: 2102032--- PASS: TestOrphanedObjectsGCStressTest (2.11s)20332026/10/06 21:45:31 WARN Rate limiter enabled after throttle name=s3-test rate=520342026/10/06 21:45:31 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2035=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2036 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102037 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002038--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.55s)2039=== NAME TestPinProtectsFromGC2040 client_integration_test.go:840: Pin successfully protected closure from garbage collection2041--- PASS: TestPinProtectsFromGC (4.81s)20422026/10/06 21:45:32 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-config20432026/10/06 21:45:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.932636ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2044--- PASS: TestConnectWaitsForAPeerMigration (5.17s)20452026/10/06 21:45:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=415.438735ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2046--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.44s)20472026/10/06 21:45:33 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=728.910624ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20482026/10/06 21:45:33 INFO Aborted multipart uploads count=1 kept=020492026/10/06 21:45:33 INFO Received cleanup request method=DELETE path=/api/pending_closures20502026/10/06 21:45:33 INFO Aborted multipart uploads count=1 kept=02051--- PASS: TestPendingCleanupUsesOneCutoff (6.83s)20522026/10/06 21:45:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.651112746s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20532026/10/06 21:45:35 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"20542026/10/06 21:45:35 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-config20552026/10/06 21:45:36 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.415443ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20562026/10/06 21:45:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=395.434487ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20572026/10/06 21:45:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=803.793183ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20582026/10/06 21:45:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.716847733s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20592026/10/06 21:45:39 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_closures20602026/10/06 21:45:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.946683ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20612026/10/06 21:45:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=366.624863ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20622026/10/06 21:45:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=757.085306ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20632026/10/06 21:45:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.675382725s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2064--- PASS: TestClientErrorHandling (0.00s)2065 --- PASS: TestClientErrorHandling/InvalidStorePath (0.51s)2066 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.59s)2067 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.73s)2068PASS2069{"timestamp":"2026-10-06T21:45:42.222639553Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:42784","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(392)"}20702026-10-06 21:45:42.588 UTC [128] LOG: received smart shutdown request20712026-10-06 21:45:42.592 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 120722026-10-06 21:45:42.603 UTC [133] LOG: shutting down20732026-10-06 21:45:42.604 UTC [133] LOG: checkpoint starting: shutdown immediate20742026-10-06 21:45:44.233 UTC [133] LOG: checkpoint complete: wrote 11333 buffers (69.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.288 s, sync=1.262 s, total=1.630 s; sync files=33710, longest=0.008 s, average=0.001 s; distance=527021 kB, estimate=527021 kB; lsn=0/21A11488, redo lsn=0/21A1148820752026-10-06 21:45:44.320 UTC [128] LOG: database system is shut down2076Running OIDC tests...2077=== RUN TestAudienceForIssuer2078=== PAUSE TestAudienceForIssuer2079=== RUN TestGlobMatch2080=== PAUSE TestGlobMatch2081=== RUN TestValidateToken_ValidToken2082=== PAUSE TestValidateToken_ValidToken2083=== RUN TestValidateToken_WrongAudience2084=== PAUSE TestValidateToken_WrongAudience2085=== RUN TestValidateToken_Expired2086=== PAUSE TestValidateToken_Expired2087=== RUN TestValidateToken_BoundClaimsMismatch2088=== PAUSE TestValidateToken_BoundClaimsMismatch2089=== RUN TestValidateToken_BoundSubjectMismatch2090=== PAUSE TestValidateToken_BoundSubjectMismatch2091=== RUN TestValidateToken_MultipleProviders2092=== PAUSE TestValidateToken_MultipleProviders2093=== RUN TestValidateToken_NoMatchingProvider2094=== PAUSE TestValidateToken_NoMatchingProvider2095=== RUN TestValidateToken_KubernetesServiceAccount2096=== PAUSE TestValidateToken_KubernetesServiceAccount2097=== RUN TestNewValidator_KubernetesRequiresCA2098=== PAUSE TestNewValidator_KubernetesRequiresCA2099=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2100=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2101=== RUN TestPins_ReservedForMatchingRule2102=== PAUSE TestPins_ReservedForMatchingRule2103=== RUN TestPins_TopLevelShorthand2104=== PAUSE TestPins_TopLevelShorthand2105=== RUN TestPins_ConfigValidation2106=== PAUSE TestPins_ConfigValidation2107=== RUN TestScopes_LegacyProviderDefaultsToWrite2108=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2109=== RUN TestScopes_Rules2110=== PAUSE TestScopes_Rules2111=== RUN TestScopes_ConfigValidation2112=== PAUSE TestScopes_ConfigValidation2113=== CONT TestAudienceForIssuer2114=== CONT TestPins_ConfigValidation2115--- PASS: TestAudienceForIssuer (0.00s)2116=== CONT TestValidateToken_NoMatchingProvider2117=== CONT TestValidateToken_MultipleProviders2118=== CONT TestValidateToken_KubernetesServiceAccount2119=== CONT TestValidateToken_BoundSubjectMismatch2120--- PASS: TestPins_ConfigValidation (0.00s)2121=== CONT TestValidateToken_BoundClaimsMismatch2122=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2123=== CONT TestValidateToken_Expired2124=== CONT TestValidateToken_WrongAudience2125=== CONT TestValidateToken_ValidToken2126=== CONT TestNewValidator_KubernetesRequiresCA2127=== CONT TestGlobMatch2128=== RUN TestGlobMatch/foo_foo2129=== PAUSE TestGlobMatch/foo_foo2130=== RUN TestGlobMatch/foo_bar2131=== PAUSE TestGlobMatch/foo_bar2132=== RUN TestGlobMatch/*_2133=== CONT TestScopes_Rules2134=== CONT TestPins_TopLevelShorthand2135=== CONT TestScopes_ConfigValidation2136=== CONT TestScopes_LegacyProviderDefaultsToWrite2137=== CONT TestPins_ReservedForMatchingRule2138=== PAUSE TestGlobMatch/*_2139=== RUN TestGlobMatch/*_anything2140=== PAUSE TestGlobMatch/*_anything2141=== RUN TestGlobMatch/foo*_foo2142=== PAUSE TestGlobMatch/foo*_foo2143=== RUN TestGlobMatch/foo*_foobar2144=== PAUSE TestGlobMatch/foo*_foobar2145=== RUN TestGlobMatch/foo*_bar2146=== PAUSE TestGlobMatch/foo*_bar2147=== RUN TestGlobMatch/*bar_bar2148=== PAUSE TestGlobMatch/*bar_bar2149=== RUN TestGlobMatch/*bar_foobar2150=== PAUSE TestGlobMatch/*bar_foobar2151=== RUN TestGlobMatch/*bar_foo2152=== PAUSE TestGlobMatch/*bar_foo2153=== RUN TestGlobMatch/foo*bar_foobar2154=== PAUSE TestGlobMatch/foo*bar_foobar2155=== RUN TestGlobMatch/foo*bar_foo123bar2156=== PAUSE TestGlobMatch/foo*bar_foo123bar2157=== RUN TestGlobMatch/foo*bar_foobarbaz2158=== PAUSE TestGlobMatch/foo*bar_foobarbaz2159=== RUN TestGlobMatch/*/*_foo/bar2160=== PAUSE TestGlobMatch/*/*_foo/bar2161=== RUN TestGlobMatch/*/*_foo2162=== PAUSE TestGlobMatch/*/*_foo2163=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2164=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2165=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02166=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02167=== RUN TestGlobMatch/refs/*/main_refs/heads/main2168=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2169=== RUN TestGlobMatch/fo?_foo2170=== PAUSE TestGlobMatch/fo?_foo2171=== RUN TestGlobMatch/fo?_fo2172=== PAUSE TestGlobMatch/fo?_fo2173=== RUN TestGlobMatch/fo?_fooo2174=== PAUSE TestGlobMatch/fo?_fooo2175=== RUN TestGlobMatch/?oo_foo2176=== PAUSE TestGlobMatch/?oo_foo2177=== RUN TestGlobMatch/?oo_boo2178=== PAUSE TestGlobMatch/?oo_boo2179=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2180=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2181=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2182=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2183=== CONT TestGlobMatch/foo_foo2184=== CONT TestGlobMatch/foo*bar_foobarbaz2185=== CONT TestGlobMatch/foo*bar_foo123bar2186=== CONT TestGlobMatch/foo*bar_foobar2187=== CONT TestGlobMatch/*bar_foo2188=== CONT TestGlobMatch/*bar_foobar2189=== CONT TestGlobMatch/*bar_bar2190=== CONT TestGlobMatch/foo*_bar2191=== CONT TestGlobMatch/foo*_foobar2192=== CONT TestGlobMatch/foo*_foo2193=== CONT TestGlobMatch/*_anything2194=== CONT TestGlobMatch/*/*_foo/bar2195=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02196=== CONT TestGlobMatch/fo?_foo2197=== CONT TestGlobMatch/refs/*/main_refs/heads/main2198=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2199=== CONT TestGlobMatch/*_2200=== CONT TestGlobMatch/foo_bar2201=== CONT TestGlobMatch/fo?_fo2202=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2203=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2204=== CONT TestGlobMatch/?oo_boo2205=== CONT TestGlobMatch/?oo_foo2206=== CONT TestGlobMatch/fo?_fooo2207=== CONT TestGlobMatch/*/*_foo2208--- PASS: TestGlobMatch (0.00s)2209 --- PASS: TestGlobMatch/foo_foo (0.00s)2210 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2211 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2212 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2213 --- PASS: TestGlobMatch/*bar_foo (0.00s)2214 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2215 --- PASS: TestGlobMatch/*bar_bar (0.00s)2216 --- PASS: TestGlobMatch/foo*_bar (0.00s)2217 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2218 --- PASS: TestGlobMatch/foo*_foo (0.00s)2219 --- PASS: TestGlobMatch/*_anything (0.00s)2220 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2221 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2222 --- PASS: TestGlobMatch/fo?_foo (0.00s)2223 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2224 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2225 --- PASS: TestGlobMatch/*_ (0.00s)2226 --- PASS: TestGlobMatch/foo_bar (0.00s)2227 --- PASS: TestGlobMatch/fo?_fo (0.00s)2228 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2229 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2230 --- PASS: TestGlobMatch/?oo_boo (0.00s)2231 --- PASS: TestGlobMatch/?oo_foo (0.00s)2232 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2233 --- PASS: TestGlobMatch/*/*_foo (0.00s)2234--- PASS: TestScopes_ConfigValidation (0.00s)22352026/10/06 21:45:46 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232236--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)22372026/10/06 21:45:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33989/oidc22382026/10/06 21:45:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45391/oidc22392026/10/06 21:45:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42355/oidc2240--- PASS: TestValidateToken_WrongAudience (0.04s)2241--- PASS: TestPins_TopLevelShorthand (0.03s)2242--- PASS: TestValidateToken_BoundSubjectMismatch (0.04s)22432026/10/06 21:45:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35407/oidc22442026/10/06 21:45:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35209/oidc2245--- PASS: TestValidateToken_Expired (0.05s)22462026/10/06 21:45:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34187/oidc2247--- PASS: TestScopes_Rules (0.04s)2248--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)22492026/10/06 21:45:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46185/oidc2250--- PASS: TestPins_ReservedForMatchingRule (0.06s)22512026/10/06 21:45:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40413/oidc2252--- PASS: TestValidateToken_ValidToken (0.08s)22532026/10/06 21:45:46 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44045/oidc22542026/10/06 21:45:46 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45495/oidc2255--- PASS: TestValidateToken_MultipleProviders (0.10s)22562026/10/06 21:45:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44557/oidc2257--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)22582026/10/06 21:45:46 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:362692259--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)22602026/10/06 21:45:46 http: TLS handshake error from 127.0.0.1:41902: remote error: tls: bad certificate2261--- PASS: TestNewValidator_KubernetesRequiresCA (0.15s)22622026/10/06 21:45:47 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45919/oidc2263--- PASS: TestValidateToken_NoMatchingProvider (0.22s)2264PASS2265Running hook tests...2266=== RUN TestSendPathsEmpty2267=== PAUSE TestSendPathsEmpty2268=== RUN TestQueueEnqueueAndFetch2269=== PAUSE TestQueueEnqueueAndFetch2270=== RUN TestQueueDeduplication2271=== PAUSE TestQueueDeduplication2272=== RUN TestQueueRemove2273=== PAUSE TestQueueRemove2274=== RUN TestQueueFetchBatchLimit2275=== PAUSE TestQueueFetchBatchLimit2276=== RUN TestQueueRetryMovesToBack2277=== PAUSE TestQueueRetryMovesToBack2278=== RUN TestQueueFetchRemoveLifecycle2279=== PAUSE TestQueueFetchRemoveLifecycle2280=== RUN TestQueueConcurrentWriters2281=== PAUSE TestQueueConcurrentWriters2282=== RUN TestQueueRemoveLargeClosure2283=== PAUSE TestQueueRemoveLargeClosure2284=== RUN TestServerClientIntegration2285=== PAUSE TestServerClientIntegration2286=== RUN TestServerQueueError2287=== PAUSE TestServerQueueError2288=== RUN TestGetListenerSocketActivation2289 server_test.go:210: === RUN TestGetListenerSocketActivation2290 --- PASS: TestGetListenerSocketActivation (0.00s)2291 PASS2292 2293--- PASS: TestGetListenerSocketActivation (0.01s)2294=== RUN TestDrainIsolatesPoisonPath2295=== PAUSE TestDrainIsolatesPoisonPath2296=== RUN TestRunNotBlockedByPoisonHead2297=== PAUSE TestRunNotBlockedByPoisonHead2298=== RUN TestDrainGivesUpWhenServerDown2299=== PAUSE TestDrainGivesUpWhenServerDown2300=== RUN TestFailedPathPrunedByLaterClosure2301=== PAUSE TestFailedPathPrunedByLaterClosure2302=== RUN TestWorkerUploadsAndRemoves2303=== PAUSE TestWorkerUploadsAndRemoves2304=== RUN TestWorkerSkipsGCdPaths2305=== PAUSE TestWorkerSkipsGCdPaths2306=== RUN TestWorkerPrunesClosureDeps2307=== PAUSE TestWorkerPrunesClosureDeps2308=== RUN TestDrainTimeout2309=== PAUSE TestDrainTimeout2310=== CONT TestSendPathsEmpty2311=== CONT TestServerQueueError2312--- PASS: TestSendPathsEmpty (0.00s)2313=== CONT TestQueueFetchBatchLimit2314=== CONT TestQueueRemove2315=== CONT TestQueueDeduplication2316=== CONT TestQueueEnqueueAndFetch23172026/10/06 21:45:47 ERROR Failed to queue paths error="permission denied" count=12318=== CONT TestQueueRetryMovesToBack2319=== CONT TestWorkerUploadsAndRemoves2320=== CONT TestServerClientIntegration2321=== CONT TestDrainTimeout2322=== CONT TestWorkerPrunesClosureDeps2323=== CONT TestQueueRemoveLargeClosure2324=== CONT TestQueueConcurrentWriters2325=== CONT TestWorkerSkipsGCdPaths2326=== CONT TestQueueFetchRemoveLifecycle2327=== CONT TestRunNotBlockedByPoisonHead2328=== CONT TestFailedPathPrunedByLaterClosure2329=== CONT TestDrainIsolatesPoisonPath2330=== CONT TestDrainGivesUpWhenServerDown2331--- PASS: TestServerQueueError (0.00s)2332--- PASS: TestServerClientIntegration (0.00s)23332026/10/06 21:45:47 INFO Upload queue status pending=323342026/10/06 21:45:47 INFO Upload queue status pending=223352026/10/06 21:45:47 INFO Uploading batch count=223362026/10/06 21:45:47 ERROR Upload failed error="upload failed" count=223372026/10/06 21:45:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown404814664/002/a23382026/10/06 21:45:47 INFO Uploading batch count=223392026/10/06 21:45:47 INFO Uploading batch count=12340--- PASS: TestQueueFetchBatchLimit (0.02s)23412026/10/06 21:45:47 ERROR Upload failed error="upload failed" count=123422026/10/06 21:45:47 INFO Upload queue status pending=223432026/10/06 21:45:47 INFO Upload queue status pending=22344--- PASS: TestQueueRemove (0.02s)23452026/10/06 21:45:47 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3440813144/002/nonexistent23462026/10/06 21:45:47 INFO Uploading batch count=123472026/10/06 21:45:47 ERROR Upload failed error="upload failed" count=123482026/10/06 21:45:47 INFO Uploading batch count=223492026/10/06 21:45:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown404814664/002/b2350--- PASS: TestQueueDeduplication (0.02s)23512026/10/06 21:45:47 INFO Uploading batch count=423522026/10/06 21:45:47 ERROR Upload failed error="upload failed" count=42353--- PASS: TestQueueEnqueueAndFetch (0.02s)23542026/10/06 21:45:47 INFO Uploading batch count=12355--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23562026/10/06 21:45:47 INFO Uploading batch count=123572026/10/06 21:45:47 INFO Uploading batch count=223582026/10/06 21:45:47 ERROR Upload failed error="upload failed" count=223592026/10/06 21:45:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown404814664/002/c23602026/10/06 21:45:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3290569242/002/bbb23612026/10/06 21:45:47 INFO Uploading batch count=12362--- PASS: TestQueueRetryMovesToBack (0.02s)23632026/10/06 21:45:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown404814664/002/d23642026/10/06 21:45:47 INFO Uploading batch count=123652026/10/06 21:45:47 INFO Uploading batch count=223662026/10/06 21:45:47 ERROR Upload failed error="upload failed" count=223672026/10/06 21:45:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown404814664/002/e23682026/10/06 21:45:47 INFO Uploading batch count=123692026/10/06 21:45:47 ERROR Upload failed error="upload failed" count=123702026/10/06 21:45:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown404814664/002/f23712026/10/06 21:45:47 INFO Uploading batch count=123722026/10/06 21:45:47 ERROR Upload failed error="upload failed" count=123732026/10/06 21:45:47 ERROR Drain finished with paths left in queue remaining=1023742026/10/06 21:45:47 INFO Uploading batch count=123752026/10/06 21:45:47 ERROR Upload failed error="upload failed" count=12376--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23772026/10/06 21:45:47 ERROR Drain finished with paths left in queue remaining=12378--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2379--- PASS: TestDrainIsolatesPoisonPath (0.02s)2380--- PASS: TestWorkerPrunesClosureDeps (0.04s)2381--- PASS: TestWorkerUploadsAndRemoves (0.04s)2382--- PASS: TestWorkerSkipsGCdPaths (0.04s)2383--- PASS: TestQueueRemoveLargeClosure (0.06s)23842026/10/06 21:45:47 ERROR Upload failed error="context deadline exceeded" count=223852026/10/06 21:45:47 ERROR Drain finished with paths left in queue remaining=42386--- PASS: TestDrainTimeout (0.22s)2387--- PASS: TestQueueConcurrentWriters (0.28s)23882026/10/06 21:45:48 INFO Uploading batch count=123892026/10/06 21:45:48 INFO Uploading batch count=123902026/10/06 21:45:48 INFO Uploading batch count=123912026/10/06 21:45:48 ERROR Upload failed error="upload failed" count=123922026/10/06 21:45:48 INFO Uploading batch count=123932026/10/06 21:45:48 ERROR Upload failed error="upload failed" count=123942026/10/06 21:45:48 INFO Uploading batch count=123952026/10/06 21:45:48 ERROR Upload failed error="upload failed" count=123962026/10/06 21:45:48 INFO Uploading batch count=123972026/10/06 21:45:48 ERROR Upload failed error="upload failed" count=123982026/10/06 21:45:48 ERROR Drain finished with paths left in queue remaining=12399--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2400PASS2401Running signing tests...2402=== RUN TestExternalSigner2403=== PAUSE TestExternalSigner2404=== RUN TestExternalSignerWrongPublicKey2405=== PAUSE TestExternalSignerWrongPublicKey2406=== RUN TestExternalSignerErrors2407=== PAUSE TestExternalSignerErrors2408=== RUN TestExternalSignerRestartsAfterCrash2409=== PAUSE TestExternalSignerRestartsAfterCrash2410=== RUN TestExternalSignerProgramErrorKeepsProcess2411=== PAUSE TestExternalSignerProgramErrorKeepsProcess2412=== RUN TestExternalSignerClose2413=== PAUSE TestExternalSignerClose2414=== RUN TestExternalSignerRejectsInvalidPublicKey2415=== PAUSE TestExternalSignerRejectsInvalidPublicKey2416=== RUN TestExternalSignerCancellation2417=== PAUSE TestExternalSignerCancellation2418=== RUN TestGenerateFingerprint2419=== PAUSE TestGenerateFingerprint2420=== RUN TestParseSigningKey2421=== PAUSE TestParseSigningKey2422=== RUN TestSign2423=== PAUSE TestSign2424=== RUN TestSignBatch2425=== PAUSE TestSignBatch2426=== RUN TestNilKeyPublicKey2427=== PAUSE TestNilKeyPublicKey2428=== RUN TestSignErrors2429=== PAUSE TestSignErrors2430=== CONT TestExternalSigner2431=== CONT TestExternalSignerCancellation2432=== CONT TestExternalSignerProgramErrorKeepsProcess2433=== CONT TestExternalSignerErrors2434=== CONT TestExternalSignerRestartsAfterCrash2435=== CONT TestSign2436=== CONT TestNilKeyPublicKey2437--- PASS: TestNilKeyPublicKey (0.00s)2438=== CONT TestSignErrors2439=== CONT TestSignBatch2440=== CONT TestParseSigningKey2441=== RUN TestParseSigningKey/valid_32-byte_key2442=== CONT TestGenerateFingerprint2443=== CONT TestExternalSignerClose2444=== CONT TestExternalSignerRejectsInvalidPublicKey2445=== CONT TestExternalSignerWrongPublicKey2446=== RUN TestExternalSignerErrors/exit_on_request2447=== PAUSE TestParseSigningKey/valid_32-byte_key2448=== PAUSE TestExternalSignerErrors/exit_on_request2449=== RUN TestGenerateFingerprint/basic_with_references2450=== PAUSE TestGenerateFingerprint/basic_with_references2451=== RUN TestExternalSignerErrors/missing_signatures2452=== PAUSE TestExternalSignerErrors/missing_signatures2453--- PASS: TestSign (0.00s)2454=== RUN TestExternalSignerErrors/too_few_signatures2455=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2456=== RUN TestExternalSignerRejectsInvalidPublicKey/#002457=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002458=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2459=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2460=== PAUSE TestExternalSignerErrors/too_few_signatures2461=== RUN TestSignErrors/nil_key2462=== PAUSE TestSignErrors/nil_key2463=== RUN TestSignErrors/nil_narinfo2464=== PAUSE TestSignErrors/nil_narinfo2465=== RUN TestSignErrors/invalid_narinfo2466=== PAUSE TestSignErrors/invalid_narinfo2467=== RUN TestGenerateFingerprint/no_references2468=== PAUSE TestGenerateFingerprint/no_references2469=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2470=== RUN TestParseSigningKey/no_colon2471=== PAUSE TestParseSigningKey/no_colon2472=== RUN TestParseSigningKey/empty_name2473=== PAUSE TestParseSigningKey/empty_name2474=== RUN TestParseSigningKey/invalid_base642475--- PASS: TestSignBatch (0.00s)2476=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2477=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2478=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2479=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2480=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2481=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2482=== CONT TestExternalSignerRejectsInvalidPublicKey/#002483=== RUN TestExternalSignerErrors/wrong_signature_name2484=== PAUSE TestExternalSignerErrors/wrong_signature_name2485=== RUN TestExternalSignerErrors/wrong_signature_length2486=== PAUSE TestExternalSignerErrors/wrong_signature_length2487=== RUN TestExternalSignerErrors/exit_at_startup2488=== PAUSE TestExternalSignerErrors/exit_at_startup2489=== RUN TestExternalSignerErrors/invalid_JSON2490=== PAUSE TestExternalSignerErrors/invalid_JSON2491=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2492=== RUN TestSignErrors/canceled2493=== PAUSE TestSignErrors/canceled2494=== CONT TestSignErrors/nil_key2495=== CONT TestSignErrors/canceled2496=== CONT TestSignErrors/invalid_narinfo2497=== PAUSE TestParseSigningKey/invalid_base642498=== RUN TestParseSigningKey/wrong_length2499=== PAUSE TestParseSigningKey/wrong_length2500=== CONT TestParseSigningKey/valid_32-byte_key2501=== CONT TestParseSigningKey/invalid_base642502=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2503=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2504=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2505--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2506--- PASS: TestExternalSignerClose (0.00s)2507=== RUN TestExternalSignerErrors/program_error2508=== PAUSE TestExternalSignerErrors/program_error2509=== CONT TestSignErrors/nil_narinfo2510=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2511=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2512=== CONT TestParseSigningKey/empty_name2513=== CONT TestParseSigningKey/wrong_length2514=== CONT TestParseSigningKey/no_colon2515=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2516--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2517 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2518 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2519 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2520 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2521 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2522--- PASS: TestExternalSignerWrongPublicKey (0.00s)2523=== RUN TestExternalSignerErrors/null2524=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2525=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2526--- PASS: TestSignErrors (0.00s)2527 --- PASS: TestSignErrors/nil_key (0.00s)2528 --- PASS: TestSignErrors/canceled (0.00s)2529 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2530 --- PASS: TestSignErrors/nil_narinfo (0.00s)2531=== PAUSE TestExternalSignerErrors/null2532=== RUN TestExternalSignerErrors/wrong_id2533=== PAUSE TestExternalSignerErrors/wrong_id2534=== RUN TestExternalSignerErrors/null_signatures2535=== PAUSE TestExternalSignerErrors/null_signatures2536=== RUN TestExternalSignerErrors/wrong_signatures_shape2537=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2538=== RUN TestExternalSignerErrors/missing_signature_name2539=== PAUSE TestExternalSignerErrors/missing_signature_name2540=== RUN TestExternalSignerErrors/wrong_shape2541=== PAUSE TestExternalSignerErrors/wrong_shape2542=== RUN TestGenerateFingerprint/invalid_nar_hash_length2543=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2544--- PASS: TestParseSigningKey (0.00s)2545 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2546 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2547 --- PASS: TestParseSigningKey/empty_name (0.00s)2548 --- PASS: TestParseSigningKey/wrong_length (0.00s)2549 --- PASS: TestParseSigningKey/no_colon (0.00s)2550 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2551=== RUN TestExternalSignerErrors/unrequested_key2552=== RUN TestGenerateFingerprint/invalid_store_path_prefix2553=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2554=== RUN TestGenerateFingerprint/invalid_reference_prefix2555=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2556=== CONT TestGenerateFingerprint/basic_with_references2557=== CONT TestGenerateFingerprint/no_references2558=== PAUSE TestExternalSignerErrors/unrequested_key2559=== RUN TestExternalSignerErrors/invalid_signature_base642560=== PAUSE TestExternalSignerErrors/invalid_signature_base642561=== CONT TestExternalSignerErrors/exit_on_request2562=== CONT TestExternalSignerErrors/wrong_signatures_shape2563=== CONT TestGenerateFingerprint/invalid_nar_hash_length2564=== CONT TestExternalSignerErrors/missing_signature_name2565=== CONT TestExternalSignerErrors/wrong_id2566=== CONT TestGenerateFingerprint/invalid_reference_prefix2567=== CONT TestGenerateFingerprint/invalid_store_path_prefix2568=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2569=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2570=== CONT TestExternalSignerErrors/invalid_signature_base642571--- PASS: TestGenerateFingerprint (0.00s)2572 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2573 --- PASS: TestGenerateFingerprint/no_references (0.00s)2574 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2575 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2576 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2577 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2578 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2579=== CONT TestExternalSignerErrors/unrequested_key2580=== CONT TestExternalSignerErrors/wrong_shape2581=== CONT TestExternalSignerErrors/program_error2582=== CONT TestExternalSignerErrors/exit_at_startup2583=== CONT TestExternalSignerErrors/null2584=== CONT TestExternalSignerErrors/invalid_JSON2585=== CONT TestExternalSignerErrors/null_signatures2586=== CONT TestExternalSignerErrors/wrong_signature_name2587=== CONT TestExternalSignerErrors/too_few_signatures2588=== CONT TestExternalSignerErrors/missing_signatures2589=== CONT TestExternalSignerErrors/wrong_signature_length2590--- PASS: TestExternalSigner (0.01s)2591--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2592--- PASS: TestExternalSignerErrors (0.01s)2593 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2594 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2595 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2596 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2597 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2598 --- PASS: TestExternalSignerErrors/program_error (0.01s)2599 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2600 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2601 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2602 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2603 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2604 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2605 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2606 --- PASS: TestExternalSignerErrors/null (0.01s)2607 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2608 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2609--- PASS: TestExternalSignerCancellation (0.02s)2610PASS2611Running OpenBao signer tests...2612=== RUN TestSign2613=== PAUSE TestSign2614=== RUN TestSignErrors2615=== PAUSE TestSignErrors2616=== RUN TestServe2617=== PAUSE TestServe2618=== RUN TestServeRejectsGarbage2619=== PAUSE TestServeRejectsGarbage2620=== CONT TestSign2621=== CONT TestServe2622=== CONT TestSignErrors2623=== CONT TestServeRejectsGarbage2624=== RUN TestSignErrors/invalid_json2625=== PAUSE TestSignErrors/invalid_json2626--- PASS: TestServe (0.00s)2627--- PASS: TestServeRejectsGarbage (0.00s)2628=== RUN TestSignErrors/no_prefix2629=== PAUSE TestSignErrors/no_prefix2630=== RUN TestSignErrors/invalid_base642631=== PAUSE TestSignErrors/invalid_base642632=== RUN TestSignErrors/http_error2633=== PAUSE TestSignErrors/http_error2634=== CONT TestSignErrors/invalid_json2635=== CONT TestSignErrors/http_error2636=== CONT TestSignErrors/invalid_base642637=== CONT TestSignErrors/no_prefix2638--- PASS: TestSign (0.00s)2639--- PASS: TestSignErrors (0.00s)2640 --- PASS: TestSignErrors/http_error (0.00s)2641 --- PASS: TestSignErrors/invalid_json (0.00s)2642 --- PASS: TestSignErrors/invalid_base64 (0.00s)2643 --- PASS: TestSignErrors/no_prefix (0.00s)2644PASS