niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #382
· 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.05s)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 TestSetClientTLS101=== CONT TestStreamPushIsolatesFailures102=== CONT TestStreamPushReportsSignatures103=== CONT TestScriptTokenEmptyCommand104--- PASS: TestScriptTokenEmptyCommand (0.00s)105=== CONT TestEncodeNixBase32106=== RUN TestEncodeNixBase32/test_string_hash107=== PAUSE TestEncodeNixBase32/test_string_hash108=== RUN TestEncodeNixBase32/empty_input109=== PAUSE TestEncodeNixBase32/empty_input110=== CONT TestScriptTokenScriptFails1112026/10/06 21:13:18 ERROR Upload failed error="bad path" count=3112=== CONT TestScriptTokenBadJSON113=== CONT TestScriptTokenEmptyToken114=== CONT TestScriptTokenCachesUntilRefresh115=== CONT TestScriptTokenNoExpiryRerunsEveryCall116=== CONT TestFileTokenEmpty117=== CONT TestFileTokenMissing118=== CONT TestFileTokenReadsAndCaches119=== CONT TestStaticToken1202026/10/06 21:13:18 ERROR Upload failed error=boom count=1121=== CONT TestDoWithRetry_BodyReplayedViaGetBody122=== CONT TestUploadMultipart_SupersededByPeer123=== CONT TestSetClientTLSErrors124=== CONT TestResolveStorePath125=== CONT TestSetClientTLSDoesNotMutateDefaultTransport126=== CONT TestParsePathInfoJSONMultiplePaths127=== CONT TestParsePathInfoJSON128=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths129=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths130=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths131=== RUN TestParsePathInfoJSON/Nix_format132=== CONT TestConvertHashToNix32133=== CONT TestStreamPushRequestLine134=== CONT TestStreamPushBatchesUnderLoad135=== CONT TestStreamPushReportsEveryPath136=== CONT TestPartSizeForNAR137=== CONT TestShellSplitErrors138=== CONT TestEncodeNixBase32WithRealHash139=== CONT TestShellSplit140--- PASS: TestStreamPushIsolatesFailures (0.00s)141--- PASS: TestStaticToken (0.00s)142=== CONT TestDumpPathWriterError143=== RUN TestUploadMultipart_SupersededByPeer/exists144=== CONT TestClientSignaturesByStorePath145=== PAUSE TestParsePathInfoJSON/Nix_format146--- PASS: TestStreamPushReportsSignatures (0.01s)147--- PASS: TestFileTokenMissing (0.00s)148--- PASS: TestScriptTokenScriptFails (0.01s)149--- PASS: TestFileTokenEmpty (0.00s)150=== RUN TestParsePathInfoJSON/Lix_format151=== PAUSE TestParsePathInfoJSON/Lix_format152=== RUN TestConvertHashToNix32/SRI_format_to_Nix32153=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths154=== RUN TestParsePathInfoJSON/empty_input155=== CONT TestPathInfoHashCompatibility156=== PAUSE TestParsePathInfoJSON/empty_input1572026/10/06 21:13:18 ERROR Upload failed error=boom count=1158=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32159=== RUN TestConvertHashToNix32/already_Nix32_format160=== PAUSE TestConvertHashToNix32/already_Nix32_format161=== RUN TestConvertHashToNix32/invalid_format162=== RUN TestPartSizeForNAR/zero_stays_at_minimum163=== CONT TestDumpPathSingleFile164=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum165=== CONT TestStreamPushGivesUpOnDeadServer166=== CONT TestRateLimiterFeedback167=== CONT TestCaseHackSuffix168=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess169=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica170=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)171=== CONT TestGetStorePathHash172=== RUN TestRateLimiterFeedback/429_enables_limiter1732026/10/06 21:13:18 WARN Rate limiter enabled after throttle name=server-test rate=5174=== RUN TestParsePathInfoJSON/whitespace_only175=== PAUSE TestParsePathInfoJSON/whitespace_only176=== CONT TestPathInfoCACompatibility177=== PAUSE TestConvertHashToNix32/invalid_format178=== PAUSE TestUploadMultipart_SupersededByPeer/exists179--- PASS: TestShellSplitErrors (0.00s)180=== RUN TestPartSizeForNAR/small_stays_at_minimum181=== RUN TestSetClientTLSErrors/missing_cert_file182=== CONT TestUploadMultipart_PartsInParallel183=== RUN TestGetStorePathHash/valid_store_path184=== PAUSE TestSetClientTLSErrors/missing_cert_file1852026/10/06 21:13:18 WARN Rate limiter enabled after throttle name=server-test rate=5186=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun1872026/10/06 21:13:18 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:378071882026/10/06 21:13:18 ERROR Upload failed error="connection refused" count=20189--- PASS: TestEncodeNixBase32WithRealHash (0.00s)190--- PASS: TestShellSplit (0.00s)191=== CONT TestFilterOversizedClosures192=== RUN TestFilterOversizedClosures/no_limit_keeps_everything193=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything1942026/10/06 21:13:18 ERROR Server seems unavailable, giving up on batch untried=17195=== RUN TestParsePathInfoJSON/invalid_JSON1962026/10/06 21:13:18 WARN Rate limiter backed off name=server-test rate=5197=== PAUSE TestParsePathInfoJSON/invalid_JSON198--- PASS: TestStreamPushReportsEveryPath (0.00s)1992026/10/06 21:13:18 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37807200--- PASS: TestClientSignaturesByStorePath (0.00s)201--- PASS: TestFileTokenReadsAndCaches (0.00s)202--- PASS: TestScriptTokenEmptyToken (0.01s)203--- PASS: TestScriptTokenBadJSON (0.01s)204--- PASS: TestResolveStorePath (0.00s)205=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths206=== RUN TestUploadMultipart_SupersededByPeer/missing207=== PAUSE TestUploadMultipart_SupersededByPeer/missing208=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths209=== CONT TestEncodeNixBase32/test_string_hash2102026/10/06 21:13:18 INFO Garbage collection started211=== CONT TestConvertHashToNix32/already_Nix32_format212=== RUN TestPathInfoCACompatibility/null_ca_field213=== RUN TestSetClientTLSErrors/missing_key_file214=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)215=== PAUSE TestRateLimiterFeedback/429_enables_limiter216=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped217=== CONT TestRegisterUploadedObjectReusesConnections218=== CONT TestDumpPathMatchesNix219=== RUN TestSetClientTLS/rejects_connection_without_client_cert2202026/10/06 21:13:18 INFO Garbage collection started221=== CONT TestEncodeNixBase32/empty_input222=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert223=== CONT TestParsePathInfoJSON/invalid_JSON224=== CONT TestParsePathInfoJSON/empty_input225=== CONT TestParsePathInfoJSON/Lix_format226--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)227=== CONT TestUploadMultipart_SupersededByPeer/exists228--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)229--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)230--- PASS: TestDoServerRequestAttachesToken (0.06s)231--- PASS: TestStreamPushGivesUpOnDeadServer (0.07s)232--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)233 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)234 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)235--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.07s)236=== CONT TestConvertHashToNix32/SRI_format_to_Nix32237=== CONT TestUploadMultipart_SupersededByPeer/missing238=== CONT TestConvertHashToNix32/invalid_format239=== CONT TestParsePathInfoJSON/Nix_format240=== PAUSE TestPathInfoCACompatibility/null_ca_field241=== RUN TestPathInfoCACompatibility/old_string_format_-_text242=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text243=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive244=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive245=== RUN TestPathInfoCACompatibility/new_structured_format_-_text246=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text247=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method248=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method249=== CONT TestPathInfoCACompatibility/null_ca_field250=== CONT TestPathInfoCACompatibility/new_structured_format_-_text251=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2522026/10/06 21:13:18 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=0253=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive254=== CONT TestParsePathInfoJSON/whitespace_only255=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped256=== RUN TestFilterOversizedClosures/all_closures_skipped257=== PAUSE TestFilterOversizedClosures/all_closures_skipped258=== CONT TestFilterOversizedClosures/no_limit_keeps_everything259=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon260=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon261=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI262=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI263=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512264=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512265=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)266=== CONT TestFilterOversizedClosures/all_closures_skipped2672026/10/06 21:13:18 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=50268=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2692026/10/06 21:13:18 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=2000270=== RUN TestRateLimiterFeedback/503_enables_limiter271=== PAUSE TestRateLimiterFeedback/503_enables_limiter272=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter273=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter274=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter275=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter276=== CONT TestRateLimiterFeedback/429_enables_limiter277=== PAUSE TestPartSizeForNAR/small_stays_at_minimum278=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum279=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum280=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts281=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts282=== RUN TestPartSizeForNAR/1_TiB283=== PAUSE TestPartSizeForNAR/1_TiB284=== RUN TestPartSizeForNAR/5_TiB_S3_max_object285=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object286=== RUN TestPartSizeForNAR/capped_at_5_GiB287=== PAUSE TestPartSizeForNAR/capped_at_5_GiB288=== CONT TestPartSizeForNAR/zero_stays_at_minimum289=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122902026/10/06 21:13:18 WARN Rate limiter enabled after throttle name=server-test rate=5291=== CONT TestPartSizeForNAR/5_TiB_S3_max_object292=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI293=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA2942026/10/06 21:13:18 WARN Garbage collection finished on another replica. Its statistics are not available here295=== PAUSE TestGetStorePathHash/valid_store_path2962026/10/06 21:13:18 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:42185297--- PASS: TestEncodeNixBase32 (0.00s)298 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)299 --- PASS: TestEncodeNixBase32/empty_input (0.00s)300=== CONT TestPathInfoCACompatibility/old_string_format_-_text301=== PAUSE TestSetClientTLSErrors/missing_key_file302=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3032026/10/06 21:13:18 WARN Rate limiter backed off name=server-test rate=5304=== RUN TestSetClientTLSErrors/missing_ca_file305=== PAUSE TestSetClientTLSErrors/missing_ca_file306=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter307=== CONT TestRateLimiterFeedback/503_enables_limiter308=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon309=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts310=== CONT TestPartSizeForNAR/capped_at_5_GiB311=== CONT TestPartSizeForNAR/1_TiB312=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum313=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA314=== RUN TestSetClientTLS/preserves_debug_logging_transport315=== PAUSE TestSetClientTLS/preserves_debug_logging_transport316=== CONT TestSetClientTLS/rejects_connection_without_client_cert317=== CONT TestSetClientTLS/preserves_debug_logging_transport318=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3192026/10/06 21:13:18 WARN Rate limiter enabled after throttle name=server-test rate=53202026/10/06 21:13:18 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:329513212026/10/06 21:13:18 WARN Rate limiter backed off name=server-test rate=5322=== CONT TestPartSizeForNAR/small_stays_at_minimum323=== RUN TestGetStorePathHash/basename_without_hyphen_should_error324--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.07s)325=== RUN TestSetClientTLSErrors/invalid_ca_file326=== PAUSE TestSetClientTLSErrors/invalid_ca_file327=== CONT TestSetClientTLSErrors/missing_cert_file328=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error329=== CONT TestSetClientTLSErrors/invalid_ca_file330--- PASS: TestConvertHashToNix32 (0.00s)331 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)332 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)333 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)334--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.07s)335=== CONT TestSetClientTLSErrors/missing_ca_file336=== CONT TestSetClientTLSErrors/missing_key_file337=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error338=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error339--- PASS: TestFilterOversizedClosures (0.07s)340 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)341 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)342 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)343=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error344--- PASS: TestPathInfoHashCompatibility (0.07s)345 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)346 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)347 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)348 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)349--- PASS: TestParsePathInfoJSON (0.07s)350 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)351 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)352 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)353 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)354 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)355=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error356=== CONT TestGetStorePathHash/valid_store_path357=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error358=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error359--- PASS: TestUploadMultipart_SupersededByPeer (0.07s)360 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)361 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)362--- PASS: TestPathInfoCACompatibility (0.07s)363 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)364 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)365 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)366 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)367 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)368=== CONT TestGetStorePathHash/basename_without_hyphen_should_error369--- PASS: TestRateLimiterFeedback (0.07s)370 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)371 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)373 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)374--- PASS: TestPartSizeForNAR (0.07s)375 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)376 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)377 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)378 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)379 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)380 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)381 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)382--- PASS: TestGetStorePathHash (0.07s)383 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)384 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)385 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)386 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)387--- PASS: TestSetClientTLSErrors (0.08s)388 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)389 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3922026/10/06 21:13:18 http: TLS handshake error from 127.0.0.1:34454: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.08s)394 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)395 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)397--- PASS: TestStreamPushRequestLine (0.08s)398--- PASS: TestCaseHackSuffix (0.09s)399--- PASS: TestDumpPathSingleFile (0.09s)400--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)401--- PASS: TestDumpPathWriterError (0.10s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.09s)404--- PASS: TestUploadMultipart_PartsInParallel (0.68s)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/postgres555232005/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/postgres555232005/data -l logfile start434435/build/postgres555232005:5432 - no response4362026-10-06 21:13:20.718 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 21:13:20.718 UTC [129] LOG: listening on Unix socket "/build/postgres555232005/.s.PGSQL.5432"4382026-10-06 21:13:20.722 UTC [136] LOG: database system was shut down at 2026-10-06 21:13:20 UTC4392026-10-06 21:13:20.726 UTC [129] LOG: database system is ready to accept connections440/build/postgres555232005:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== RUN TestResolveDBConnectionString480=== PAUSE TestResolveDBConnectionString481=== RUN TestConnectWaitsForAPeerMigration482=== PAUSE TestConnectWaitsForAPeerMigration483=== RUN TestLeadElectsOneAndHandsOver484=== PAUSE TestLeadElectsOneAndHandsOver485=== RUN TestLeadIncumbentWinsAfterRestart4862026/10/06 21:13:21 INFO lead: acquired remote=192.0.2.1:12344872026/10/06 21:13:21 INFO lead: released remote=192.0.2.1:12344882026/10/06 21:13:21 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 21:13:22 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.87s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/06 21:13:23 INFO lead: acquired remote=192.0.2.1:12344972026-10-06 21:13:24.512 UTC [576] FATAL: terminating connection due to administrator command4982026/10/06 21:13:24 INFO lead: acquired remote=192.0.2.1:12344992026/10/06 21:13:25 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/06 21:13:25 INFO lead: released remote=192.0.2.1:12345012026/10/06 21:13:25 INFO lead: released remote=192.0.2.1:1234502--- PASS: TestLeadEndsWhenItsConnectionHangs (2.92s)503=== RUN TestGCAdvisoryLockBlocksConcurrentRun504=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun505=== RUN TestGCBugBareHashReferences506=== PAUSE TestGCBugBareHashReferences507=== RUN TestGCMetrics508=== PAUSE TestGCMetrics509=== RUN TestPushDedupSurvivesConcurrentGC510=== PAUSE TestPushDedupSurvivesConcurrentGC511=== RUN TestDeduplicatedObjectsRecordedAsPending512=== PAUSE TestDeduplicatedObjectsRecordedAsPending513=== RUN TestGCSweepSkipsPendingObjects514=== PAUSE TestGCSweepSkipsPendingObjects515=== RUN TestTombstonedObjectOfferedWithoutWaiting516=== PAUSE TestTombstonedObjectOfferedWithoutWaiting517=== RUN TestGCSweepDeliversEachKeyOnce518=== PAUSE TestGCSweepDeliversEachKeyOnce519=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection520=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== RUN TestForceGCDuringPushOffersSweptObject522=== PAUSE TestForceGCDuringPushOffersSweptObject523=== RUN TestFailedS3DeleteKeepsTombstone524=== PAUSE TestFailedS3DeleteKeepsTombstone525=== RUN TestSweepSkipsRowsLockedByPush526=== PAUSE TestSweepSkipsRowsLockedByPush527=== RUN TestRegisterCompletedObjectNeedsPendingRow528=== PAUSE TestRegisterCompletedObjectNeedsPendingRow529=== RUN TestGetExistingObjectsLocksRows530=== PAUSE TestGetExistingObjectsLocksRows531=== RUN TestSweepRechecksPendingAfterLocking532=== PAUSE TestSweepRechecksPendingAfterLocking533=== RUN TestPushWaitsForSweepHoldingRow534=== PAUSE TestPushWaitsForSweepHoldingRow535=== RUN TestCommitRacingPendingCleanupKeepsObjects536=== PAUSE TestCommitRacingPendingCleanupKeepsObjects537=== RUN TestGCEndsOnShutdown538=== PAUSE TestGCEndsOnShutdown539=== RUN TestGCTaskStore_StartNew540=== PAUSE TestGCTaskStore_StartNew541=== RUN TestGCTaskStore_DeduplicateSameParams542=== PAUSE TestGCTaskStore_DeduplicateSameParams543=== RUN TestGCTaskStore_ConflictDifferentParams544=== PAUSE TestGCTaskStore_ConflictDifferentParams545=== RUN TestGCTaskStore_GetEmpty546=== PAUSE TestGCTaskStore_GetEmpty547=== RUN TestGCTaskStore_GetReturnsLatest548=== PAUSE TestGCTaskStore_GetReturnsLatest549=== RUN TestGCTaskStore_CompletedAllowsNewTask550=== PAUSE TestGCTaskStore_CompletedAllowsNewTask551=== RUN TestGCTaskStore_PhaseUpdates552=== PAUSE TestGCTaskStore_PhaseUpdates553=== RUN TestGCTaskStore_Fail554=== PAUSE TestGCTaskStore_Fail555=== RUN TestGracefulShutdownDrainsInflight556=== PAUSE TestGracefulShutdownDrainsInflight557=== RUN TestService_healthCheckHandler558=== PAUSE TestService_healthCheckHandler559=== RUN TestService_readinessHandler560=== PAUSE TestService_readinessHandler561=== RUN TestGenerateLandingPage562=== PAUSE TestGenerateLandingPage563=== RUN TestCacheConfigHandlerMaxNarSize564=== PAUSE TestCacheConfigHandlerMaxNarSize565=== RUN TestCreatePendingClosureRejectsOversizedNAR566=== PAUSE TestCreatePendingClosureRejectsOversizedNAR567=== RUN TestNARDeduplicationMetadataUploadBug568=== PAUSE TestNARDeduplicationMetadataUploadBug569=== RUN TestMetricsInventory570=== PAUSE TestMetricsInventory571=== RUN TestService_NativeMTLS572=== PAUSE TestService_NativeMTLS573=== RUN TestServerTLSConfig574=== PAUSE TestServerTLSConfig575=== RUN TestMultipartCleanup576=== PAUSE TestMultipartCleanup577=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded578=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== RUN TestPendingCleanupUsesOneCutoff580=== PAUSE TestPendingCleanupUsesOneCutoff581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentRefreshesOnlyStaleClosures592=== PAUSE TestPresentRefreshesOnlyStaleClosures593=== RUN TestPresentNotReportedWhileGCDeletesClosure594=== PAUSE TestPresentNotReportedWhileGCDeletesClosure595=== RUN TestParseSingleRange596=== PAUSE TestParseSingleRange597=== RUN TestProxyHeadersOnlyTrustedOnSocket598=== PAUSE TestProxyHeadersOnlyTrustedOnSocket599=== RUN TestIsValidCachePath600=== PAUSE TestIsValidCachePath601=== RUN TestReadProxyNarinfo602=== PAUSE TestReadProxyNarinfo603=== RUN TestReadProxyNarinfoAlreadyDecompressed604=== PAUSE TestReadProxyNarinfoAlreadyDecompressed605=== RUN TestReadProxyContentNegotiation606=== PAUSE TestReadProxyContentNegotiation607=== RUN TestReadProxyNarStreaming608=== PAUSE TestReadProxyNarStreaming609=== RUN TestReadProxy404610=== PAUSE TestReadProxy404611=== RUN TestReadProxyInvalidPath612=== PAUSE TestReadProxyInvalidPath613=== RUN TestReadProxyHead614=== PAUSE TestReadProxyHead615=== RUN TestReadProxyOutlastsServerWriteTimeout616=== PAUSE TestReadProxyOutlastsServerWriteTimeout617=== RUN TestReadProxyConditionalGet618=== PAUSE TestReadProxyConditionalGet619=== RUN TestReadProxyRootRedirectsToIndexHTML620=== PAUSE TestReadProxyRootRedirectsToIndexHTML621=== RUN TestReadProxyDisabled622=== PAUSE TestReadProxyDisabled623=== RUN TestReadRedirectNar624=== PAUSE TestReadRedirectNar625=== RUN TestReadRedirectKeepsNarinfoProxied626=== PAUSE TestReadRedirectKeepsNarinfoProxied627=== RUN TestReadProxyRangeRequest628=== PAUSE TestReadProxyRangeRequest629=== RUN TestReadRedirectUsesPublicS3URL630=== PAUSE TestReadRedirectUsesPublicS3URL631=== RUN TestPush_OverlappingRootsStoreOneRowPerKey632=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey633=== RUN TestPush_CompleteCommitsEveryRoot634=== PAUSE TestPush_CompleteCommitsEveryRoot635=== RUN TestPush_RepeatedRootCommitsOnce636=== PAUSE TestPush_RepeatedRootCommitsOnce637=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit638=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit639=== RUN TestPush_RejectsBadRequests640=== PAUSE TestPush_RejectsBadRequests641=== RUN TestPush_SignsNarinfosOfItsPendingObjects642=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects643=== RUN TestRedundantMultipartUpload644=== PAUSE TestRedundantMultipartUpload645=== RUN TestCompleteMultipartUpload_ErrorButObjectExists646=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists647=== RUN TestCompletedNarNotReofferedAcrossClosures648=== PAUSE TestCompletedNarNotReofferedAcrossClosures649=== RUN TestPresignedUploadRegisteredBeforeCommit650=== PAUSE TestPresignedUploadRegisteredBeforeCommit651=== RUN TestService_Rustfstest652=== PAUSE TestService_Rustfstest653=== RUN TestParseSize654=== PAUSE TestParseSize655=== RUN TestSkippedUploadsHandler656=== PAUSE TestSkippedUploadsHandler657=== RUN TestSystemdListenerNotActivated658--- PASS: TestSystemdListenerNotActivated (0.00s)659=== RUN TestWatchdogBeatsWhenHealthy660--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)661=== RUN TestWatchdogSkipsWhenUnhealthy6622026/10/06 21:13:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 21:13:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 21:13:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 21:13:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 21:13:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 21:13:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 21:13:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 21:13:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:13:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:13:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"672--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)673=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle674=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle675=== RUN TestProxyWriteTimeout676=== PAUSE TestProxyWriteTimeout677=== RUN TestPendingClosureWriteTimeout678=== PAUSE TestPendingClosureWriteTimeout679=== RUN TestIsValidUploadKey680=== PAUSE TestIsValidUploadKey681=== RUN TestUploadHandlersRejectInvalidKeys682=== PAUSE TestUploadHandlersRejectInvalidKeys683=== RUN TestUploadHandlersRejectOversizedBody684=== PAUSE TestUploadHandlersRejectOversizedBody685=== RUN TestService_cleanupPendingClosuresHandler686=== PAUSE TestService_cleanupPendingClosuresHandler687=== RUN TestService_createPendingClosureHandler688=== PAUSE TestService_createPendingClosureHandler689=== RUN TestService_verifyS3Integrity690=== PAUSE TestService_verifyS3Integrity691=== RUN TestCompleteMultipartUnregistered692=== PAUSE TestCompleteMultipartUnregistered693=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT694=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT695=== CONT TestService_AuthMiddleware696=== CONT TestProxyWriteTimeout697=== RUN TestProxyWriteTimeout/narinfo698=== PAUSE TestProxyWriteTimeout/narinfo699=== RUN TestProxyWriteTimeout/1_GiB_nar700=== PAUSE TestProxyWriteTimeout/1_GiB_nar701=== RUN TestProxyWriteTimeout/10_GiB_nar702=== PAUSE TestProxyWriteTimeout/10_GiB_nar703=== RUN TestProxyWriteTimeout/unknown_size704=== PAUSE TestProxyWriteTimeout/unknown_size705=== CONT TestProxyHeadersOnlyTrustedOnSocket706=== CONT TestServerTLSConfig707=== RUN TestServerTLSConfig/no_client_CA708=== CONT TestCompleteMultipartUnregistered709=== CONT TestService_verifyS3Integrity710=== CONT TestService_createPendingClosureHandler711=== CONT TestService_cleanupPendingClosuresHandler712=== CONT TestUploadHandlersRejectOversizedBody713=== CONT TestUploadHandlersRejectInvalidKeys714=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info715=== CONT TestIsValidUploadKey716=== CONT TestPendingClosureWriteTimeout717=== CONT TestRegisterCompletedObjectNeedsPendingRow718=== CONT TestParseSingleRange719=== CONT TestPresentNotReportedWhileGCDeletesClosure720=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale721=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale722=== CONT TestPresentRefreshesOnlyStaleClosures723=== CONT TestPresentReportsOnlyClosureRoots724=== CONT TestCreatePin_ReservedPins725=== CONT TestOrphanedObjectsGCStressTest726=== CONT TestOrphanedObjectsGC727=== CONT TestObjectStatsTrigger728=== CONT TestPendingCleanupUsesOneCutoff729=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded730=== CONT TestMultipartCleanup731=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT732=== PAUSE TestServerTLSConfig/no_client_CA733=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info734=== RUN TestIsValidUploadKey/narinfo735=== PAUSE TestIsValidUploadKey/narinfo736=== RUN TestIsValidUploadKey/nar_zst737=== PAUSE TestIsValidUploadKey/nar_zst738=== RUN TestIsValidUploadKey/nar_xz739=== RUN TestPendingClosureWriteTimeout/empty740=== RUN TestParseSingleRange/none741=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh742=== RUN TestServerTLSConfig/missing_CA_file743=== PAUSE TestServerTLSConfig/missing_CA_file744=== RUN TestServerTLSConfig/not_a_PEM_file745=== PAUSE TestServerTLSConfig/not_a_PEM_file746=== CONT TestService_NativeMTLS747=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal748=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal749=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key750=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key751=== PAUSE TestIsValidUploadKey/nar_xz752=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key753=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key754=== PAUSE TestPendingClosureWriteTimeout/empty755=== RUN TestPendingClosureWriteTimeout/400_objects756=== PAUSE TestPendingClosureWriteTimeout/400_objects757=== RUN TestPendingClosureWriteTimeout/670k_objects758=== PAUSE TestPendingClosureWriteTimeout/670k_objects759=== CONT TestMetricsInventory760=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh761=== CONT TestNARDeduplicationMetadataUploadBug762=== RUN TestIsValidUploadKey/nar_plain763=== PAUSE TestParseSingleRange/none764=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline765=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline766=== PAUSE TestIsValidUploadKey/nar_plain767=== RUN TestParseSingleRange/unknown_unit7682026/10/06 21:13:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45243/oidc769=== PAUSE TestParseSingleRange/unknown_unit770=== CONT TestCreatePendingClosureRejectsOversizedNAR771=== RUN TestIsValidUploadKey/listing772=== PAUSE TestIsValidUploadKey/listing7732026/10/06 21:13:26 INFO Received uploads request method=POST path=/api/pending_closures774=== RUN TestIsValidUploadKey/build_log775=== PAUSE TestIsValidUploadKey/build_log776=== RUN TestIsValidUploadKey/build_log_home-manager_file777=== RUN TestParseSingleRange/multi-range_ignored778=== PAUSE TestParseSingleRange/multi-range_ignored779--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)780=== CONT TestCacheConfigHandlerMaxNarSize781=== PAUSE TestIsValidUploadKey/build_log_home-manager_file782=== RUN TestParseSingleRange/malformed_no_dash783=== PAUSE TestParseSingleRange/malformed_no_dash784=== RUN TestIsValidUploadKey/build_log_plus_in_name785=== PAUSE TestIsValidUploadKey/build_log_plus_in_name786=== RUN TestIsValidUploadKey/build_log_question_mark787=== PAUSE TestIsValidUploadKey/build_log_question_mark788=== RUN TestIsValidUploadKey/build_log_equals789=== PAUSE TestIsValidUploadKey/build_log_equals790=== RUN TestIsValidUploadKey/realisation791=== PAUSE TestIsValidUploadKey/realisation792=== RUN TestIsValidUploadKey/realisation_plus_in_output793=== PAUSE TestIsValidUploadKey/realisation_plus_in_output794=== RUN TestIsValidUploadKey/nix-cache-info795=== PAUSE TestIsValidUploadKey/nix-cache-info796=== RUN TestIsValidUploadKey/index.html797=== PAUSE TestIsValidUploadKey/index.html798=== RUN TestIsValidUploadKey/narinfo_key,_nar_type799=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type800--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)801=== CONT TestGenerateLandingPage802=== RUN TestParseSingleRange/malformed_both_empty803=== PAUSE TestParseSingleRange/malformed_both_empty804=== RUN TestParseSingleRange/malformed_end_before_start805=== PAUSE TestParseSingleRange/malformed_end_before_start806=== RUN TestIsValidUploadKey/nar_key,_narinfo_type807=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type808=== RUN TestParseSingleRange/closed809=== RUN TestIsValidUploadKey/listing_key,_narinfo_type810=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type811=== RUN TestIsValidUploadKey/traversal812=== PAUSE TestIsValidUploadKey/traversal813=== RUN TestIsValidUploadKey/traversal_nar814=== PAUSE TestIsValidUploadKey/traversal_nar815=== PAUSE TestParseSingleRange/closed816=== RUN TestParseSingleRange/open-ended817=== PAUSE TestParseSingleRange/open-ended818=== RUN TestIsValidUploadKey/absolute819=== PAUSE TestIsValidUploadKey/absolute820=== RUN TestIsValidUploadKey/empty_key821=== PAUSE TestIsValidUploadKey/empty_key822=== RUN TestIsValidUploadKey/unknown_type823=== RUN TestParseSingleRange/end_clamped_to_size824=== PAUSE TestIsValidUploadKey/unknown_type825=== PAUSE TestParseSingleRange/end_clamped_to_size826=== RUN TestParseSingleRange/suffix827=== PAUSE TestParseSingleRange/suffix828=== RUN TestParseSingleRange/suffix_exceeds_size829=== PAUSE TestParseSingleRange/suffix_exceeds_size830=== RUN TestParseSingleRange/single_byte831=== PAUSE TestParseSingleRange/single_byte832=== RUN TestParseSingleRange/start_past_EOF833=== PAUSE TestParseSingleRange/start_past_EOF834=== RUN TestParseSingleRange/start_far_past_EOF835=== PAUSE TestParseSingleRange/start_far_past_EOF836=== CONT TestService_healthCheckHandler837=== CONT TestService_readinessHandler838--- PASS: TestGenerateLandingPage (0.00s)839=== CONT TestGracefulShutdownDrainsInflight8402026/10/06 21:13:26 INFO Starting HTTP server address=127.0.0.1:352338412026/10/06 21:13:26 INFO Shutdown signal received, draining in-flight requests timeout=10s842--- PASS: TestGracefulShutdownDrainsInflight (0.07s)843=== CONT TestGCTaskStore_Fail844--- PASS: TestGCTaskStore_Fail (0.00s)845=== CONT TestGCTaskStore_PhaseUpdates846--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)847=== CONT TestGCTaskStore_CompletedAllowsNewTask848--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)849=== CONT TestGCTaskStore_GetReturnsLatest850--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)851=== CONT TestGCTaskStore_GetEmpty852--- PASS: TestGCTaskStore_GetEmpty (0.00s)853=== CONT TestGCTaskStore_ConflictDifferentParams854--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)855=== CONT TestGCTaskStore_DeduplicateSameParams856--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)857=== CONT TestGCTaskStore_StartNew858--- PASS: TestGCTaskStore_StartNew (0.00s)859=== CONT TestGCEndsOnShutdown860=== RUN TestGCEndsOnShutdown/before_the_run861=== PAUSE TestGCEndsOnShutdown/before_the_run862=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete863=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete864=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark865=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark866=== CONT TestCommitRacingPendingCleanupKeepsObjects867=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure868=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure869=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart870=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart871=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts872=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts873=== CONT TestPushWaitsForSweepHoldingRow8742026/10/06 21:13:26 INFO Starting HTTP server address=127.0.0.1:457478752026/10/06 21:13:26 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2019207020/001/proxy.sock8762026/10/06 21:13:26 WARN mTLS auth: subject not in bound subjects subject="CN=someone"8772026/10/06 21:13:26 INFO Shutdown signal received, draining in-flight requests timeout=10s878--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.41s)879=== CONT TestSweepRechecksPendingAfterLocking8802026/10/06 21:13:26 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"881--- PASS: TestService_AuthMiddleware (0.44s)882=== CONT TestGetExistingObjectsLocksRows883--- PASS: TestPresentReportsOnlyClosureRoots (0.47s)884=== CONT TestReadRedirectUsesPublicS3URL8852026/10/06 21:13:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8862026/10/06 21:13:26 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst887--- PASS: TestCompleteMultipartUnregistered (0.49s)888=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8892026/10/06 21:13:26 INFO Received uploads request method=POST path=/api/pending_closures8902026/10/06 21:13:26 INFO Received uploads request method=POST path=/api/pending_closures8912026/10/06 21:13:26 INFO Received uploads request method=POST path=/api/pending_closures8922026/10/06 21:13:26 INFO Received uploads request method=POST path=/api/pending_closures893--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.55s)894=== CONT TestSkippedUploadsHandler8952026/10/06 21:13:26 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000896--- PASS: TestSkippedUploadsHandler (0.01s)897=== CONT TestParseSize898--- PASS: TestParseSize (0.00s)899=== CONT TestService_Rustfstest9002026/10/06 21:13:26 INFO Received cleanup request method=DELETE path=/api/pending_closures9012026/10/06 21:13:26 INFO Aborted multipart uploads count=0 kept=09022026/10/06 21:13:26 INFO Received uploads request method=POST path=/api/pending_closures9032026/10/06 21:13:26 INFO Received cleanup request method=DELETE path=/api/pending_closures9042026/10/06 21:13:26 INFO Aborted multipart uploads count=1 kept=09052026/10/06 21:13:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9062026-10-06 21:13:26.744 UTC [657] ERROR: Closure does not exist: id=19072026-10-06 21:13:26.744 UTC [657] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9082026-10-06 21:13:26.744 UTC [657] STATEMENT: -- name: CommitPendingClosure :exec909 SELECT commit_pending_closure($1::bigint)910 911--- PASS: TestService_cleanupPendingClosuresHandler (0.60s)912=== CONT TestPresignedUploadRegisteredBeforeCommit913--- PASS: TestPresentRefreshesOnlyStaleClosures (0.60s)914=== CONT TestCompletedNarNotReofferedAcrossClosures9152026/10/06 21:13:26 INFO Received uploads request method=POST path=/api/pending_closures9162026/10/06 21:13:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9172026/10/06 21:13:26 WARN Refused reserved pin name=worker-x86_64-linux9182026/10/06 21:13:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9192026/10/06 21:13:26 INFO Received create pin request method=POST path=/api/pins/my-app9202026/10/06 21:13:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux921--- PASS: TestCreatePin_ReservedPins (0.68s)922=== CONT TestCompleteMultipartUpload_ErrorButObjectExists923--- PASS: TestService_healthCheckHandler (0.63s)924=== CONT TestRedundantMultipartUpload9252026/10/06 21:13:26 INFO Received cleanup request method=DELETE path=/api/pending_closures9262026/10/06 21:13:26 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket12/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""9272026/10/06 21:13:26 INFO Aborted multipart uploads count=0 kept=19282026/10/06 21:13:26 INFO Received cleanup request method=DELETE path=/api/pending_closures9292026/10/06 21:13:26 INFO Aborted multipart uploads count=1 kept=0930--- PASS: TestMetricsInventory (0.68s)931=== CONT TestPush_SignsNarinfosOfItsPendingObjects932--- PASS: TestMultipartCleanup (0.76s)933=== CONT TestPush_RejectsBadRequests934=== NAME TestNARDeduplicationMetadataUploadBug935 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1952470057/001/store/chjs74m4df5gw9kbvv037chbhwawhzx8-file1.txt9362026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures9372026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures9382026/10/06 21:13:27 INFO Received cleanup request method=DELETE path=/api/pending_closures9392026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures940--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.10s)941=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit9422026/10/06 21:13:27 INFO Received push request method=POST path=/api/pushes9432026/10/06 21:13:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9442026/10/06 21:13:27 INFO Uploading chjs74m4df5gw9kbvv037chbhwawhzx8-file1.txt (160B)9452026/10/06 21:13:27 WARN readiness check failed error="closed pool"946--- PASS: TestService_readinessHandler (1.11s)947=== CONT TestPush_RepeatedRootCommitsOnce9482026/10/06 21:13:27 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9492026/10/06 21:13:27 WARN Failed to register uploaded object key=chjs74m4df5gw9kbvv037chbhwawhzx8.ls error="server returned 404: 404 page not found\n"9502026/10/06 21:13:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9512026/10/06 21:13:27 INFO Signed narinfos id=1 count=19522026/10/06 21:13:27 INFO Uploading 1 narinfos9532026/10/06 21:13:27 INFO Received complete push request method=POST path=/api/pushes/1/complete9542026/10/06 21:13:27 WARN Failed to register uploaded object key=chjs74m4df5gw9kbvv037chbhwawhzx8.narinfo error="server returned 404: 404 page not found\n"955=== NAME TestOrphanedObjectsGC956 orphaned_objects_gc_test.go:290: GC Test Summary:957 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A958 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B959 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)960 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)961 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects962--- PASS: TestOrphanedObjectsGC (1.13s)963=== CONT TestPush_CompleteCommitsEveryRoot9642026/10/06 21:13:27 INFO Upload complete. (82ms)965=== NAME TestNARDeduplicationMetadataUploadBug966 metadata_upload_test.go:54: Retrieved narinfo from S3:967 StorePath: /build/TestNARDeduplicationMetadataUploadBug1952470057/001/store/chjs74m4df5gw9kbvv037chbhwawhzx8-file1.txt968 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst969 Compression: zstd970 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf971 NarSize: 160972 References: 973 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf9742026/10/06 21:13:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9752026/10/06 21:13:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"976--- PASS: TestService_NativeMTLS (1.14s)977=== CONT TestPush_OverlappingRootsStoreOneRowPerKey978=== NAME TestNARDeduplicationMetadataUploadBug979 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)980 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):981 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9822026/10/06 21:13:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9832026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures9842026/10/06 21:13:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9852026/10/06 21:13:27 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YWFkNjM3YWUtODllMC00YWU1LWI3NzctNzFhODcyM2JmMmEyLmFlZTE3NmZiLTgxOWMtNDZhNi1iMTRlLWYzNjc2MmVjOTdhN3gxNzkxMzIxMjA2Njg3NjM0MDQ1 parts=109862026/10/06 21:13:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete987--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.18s)988=== CONT TestPushDedupSurvivesConcurrentGC9892026/10/06 21:13:27 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YWFkNjM3YWUtODllMC00YWU1LWI3NzctNzFhODcyM2JmMmEyLmQ0YjVjNmJhLTVmZmItNDhmMC04YWUzLWE1ZDUzOTgyYzllM3gxNzkxMzIxMjA2Njc0NzAyMDU3 parts=109902026/10/06 21:13:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9912026/10/06 21:13:27 INFO Completed upload id=19922026/10/06 21:13:27 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009932026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures9942026/10/06 21:13:27 INFO Completed upload id=1995=== NAME TestNARDeduplicationMetadataUploadBug996 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1952470057/001/store/0lvky5ai9479433rp0yvs317xv1f63hv-file2.txt9972026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures9982026/10/06 21:13:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures9992026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures10002026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures10012026/10/06 21:13:27 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10022026/10/06 21:13:27 WARN Found objects in DB but missing from S3, will re-upload count=11003--- PASS: TestService_verifyS3Integrity (1.27s)1004=== CONT TestSweepSkipsRowsLockedByPush10052026/10/06 21:13:27 INFO Aborted multipart uploads count=0 kept=010062026/10/06 21:13: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=010072026/10/06 21:13:27 INFO Vacuumed table table=pending_closures10082026/10/06 21:13:27 INFO Vacuumed table table=pending_objects10092026/10/06 21:13:27 INFO Vacuumed table table=multipart_uploads10102026/10/06 21:13:27 INFO Vacuumed table table=closures10112026/10/06 21:13:27 INFO Vacuumed table table=objects10122026/10/06 21:13:27 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001013--- PASS: TestService_createPendingClosureHandler (1.32s)1014=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10152026/10/06 21:13:27 INFO Aborted multipart uploads count=0 kept=010162026/10/06 21:13:27 WARN Force mode enabled - objects will be deleted immediately without grace period10172026/10/06 21:13:27 INFO Received push request method=POST path=/api/pushes10182026/10/06 21:13: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=010192026/10/06 21:13:27 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10202026/10/06 21:13:27 INFO Vacuumed table table=pending_closures10212026/10/06 21:13:27 INFO Vacuumed table table=pending_objects10222026/10/06 21:13:27 INFO Vacuumed table table=multipart_uploads10232026/10/06 21:13:27 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10242026/10/06 21:13:27 WARN Failed to register uploaded object key=0lvky5ai9479433rp0yvs317xv1f63hv.ls error="server returned 404: 404 page not found\n"10252026/10/06 21:13:27 INFO Signed narinfos id=2 count=110262026/10/06 21:13:27 INFO Uploading 1 narinfos10272026/10/06 21:13:27 INFO Vacuumed table table=closures10282026/10/06 21:13:27 INFO Vacuumed table table=objects10292026/10/06 21:13:27 INFO Received complete push request method=POST path=/api/pushes/2/complete10302026/10/06 21:13:27 WARN Failed to register uploaded object key=0lvky5ai9479433rp0yvs317xv1f63hv.narinfo error="server returned 404: 404 page not found\n"10312026/10/06 21:13:27 INFO Upload complete. (48ms)1032=== NAME TestNARDeduplicationMetadataUploadBug1033 metadata_upload_test.go:76: Retrieved narinfo from S3:1034 StorePath: /build/TestNARDeduplicationMetadataUploadBug1952470057/001/store/0lvky5ai9479433rp0yvs317xv1f63hv-file2.txt1035 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1036 Compression: zstd1037 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1038 NarSize: 1601039 References: 1040 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1041--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.19s)1042--- PASS: TestObjectStatsTrigger (1.28s)1043=== CONT TestFailedS3DeleteKeepsTombstone1044=== CONT TestForceGCDuringPushOffersSweptObject1045=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1046=== NAME TestNARDeduplicationMetadataUploadBug1047 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1048=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1049=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1050=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1051=== NAME TestNARDeduplicationMetadataUploadBug1052 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1053 {"version":1,"root":{"type":"regular","size":44}}1054=== CONT TestGCMetrics1055--- PASS: TestNARDeduplicationMetadataUploadBug (1.28s)1056=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1057--- PASS: TestGetExistingObjectsLocksRows (0.93s)1058=== CONT TestGCBugBareHashReferences10592026/10/06 21:13:27 INFO Aborted multipart uploads count=0 kept=010602026/10/06 21:13:27 WARN Force mode enabled - objects will be deleted immediately without grace period1061--- PASS: TestReadRedirectUsesPublicS3URL (0.93s)1062=== CONT TestGCSweepDeliversEachKeyOnce10632026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures10642026/10/06 21:13: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=010652026/10/06 21:13:27 INFO Vacuumed table table=pending_closures10662026/10/06 21:13:27 INFO Vacuumed table table=pending_objects10672026/10/06 21:13:27 INFO Vacuumed table table=multipart_uploads10682026/10/06 21:13:27 INFO Vacuumed table table=closures10692026/10/06 21:13:27 INFO Vacuumed table table=objects1070--- PASS: TestSweepRechecksPendingAfterLocking (1.03s)1071=== CONT TestGCAdvisoryLockBlocksConcurrentRun1072--- PASS: TestService_Rustfstest (0.87s)1073=== CONT TestTombstonedObjectOfferedWithoutWaiting10742026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures10752026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures10762026/10/06 21:13:27 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10772026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures1078--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.91s)1079=== CONT TestGCSweepSkipsPendingObjects10802026/10/06 21:13:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10812026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures10822026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures10832026/10/06 21:13:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10842026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures10852026/10/06 21:13:27 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWFkNjM3YWUtODllMC00YWU1LWI3NzctNzFhODcyM2JmMmEyLjE1NGY0MTk4LWMzZjAtNDBmYS1hYTEzLWNmNjkzZTI0YzkxZngxNzkxMzIxMjA3Njc1OTM5OTk410862026/10/06 21:13:27 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWFkNjM3YWUtODllMC00YWU1LWI3NzctNzFhODcyM2JmMmEyLjE1NGY0MTk4LWMzZjAtNDBmYS1hYTEzLWNmNjkzZTI0YzkxZngxNzkxMzIxMjA3Njc1OTM5OTk4 parts=110872026/10/06 21:13:27 INFO Received push request method=POST path=/api/pushes1088--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.88s)1089=== CONT TestDeduplicatedObjectsRecordedAsPending10902026/10/06 21:13:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10912026/10/06 21:13:27 INFO Signed narinfos id=1 count=110922026/10/06 21:13:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10932026/10/06 21:13:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10942026/10/06 21:13:27 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10952026/10/06 21:13:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10962026/10/06 21:13:27 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10972026/10/06 21:13:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10982026/10/06 21:13:27 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110992026/10/06 21:13:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11002026/10/06 21:13:27 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1101--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.82s)1102=== CONT TestLeadEndsOnShutdown1103=== RUN TestPush_RejectsBadRequests/no_roots1104=== PAUSE TestPush_RejectsBadRequests/no_roots1105=== RUN TestPush_RejectsBadRequests/no_objects1106=== PAUSE TestPush_RejectsBadRequests/no_objects1107=== RUN TestPush_RejectsBadRequests/bad_root1108=== PAUSE TestPush_RejectsBadRequests/bad_root1109=== RUN TestPush_RejectsBadRequests/root_not_in_objects1110=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1111=== CONT TestClientCADerivations11122026/10/06 21:13:27 INFO Received push request method=POST path=/api/pushes11132026/10/06 21:13:27 INFO Received complete push request method=POST path=/api/pushes/1/complete11142026/10/06 21:13:27 INFO Received push request method=POST path=/api/pushes11152026/10/06 21:13:27 INFO Received push request method=POST path=/api/pushes11162026/10/06 21:13:27 INFO Received complete push request method=POST path=/api/pushes/1/complete11172026/10/06 21:13:27 INFO Received push request method=POST path=/api/pushes1118--- PASS: TestPush_RepeatedRootCommitsOnce (0.48s)1119=== CONT TestLeadIncumbentAnnouncesAtOnce11202026/10/06 21:13:27 INFO Received complete push request method=POST path=/api/pushes/1/complete11212026/10/06 21:13:27 INFO Received push request method=POST path=/api/pushes1122--- PASS: TestPush_CompleteCommitsEveryRoot (0.50s)1123=== CONT TestClientFallsBackToClosures11242026/10/06 21:13:27 INFO Aborted multipart uploads count=0 kept=011252026/10/06 21:13:27 WARN Force mode enabled - objects will be deleted immediately without grace period1126--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.50s)1127=== CONT TestLeadElectsOneAndHandsOver11282026/10/06 21:13:27 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=011292026/10/06 21:13:27 INFO Vacuumed table table=pending_closures11302026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures11312026/10/06 21:13:27 INFO Vacuumed table table=pending_objects11322026/10/06 21:13:27 INFO Vacuumed table table=multipart_uploads11332026/10/06 21:13:27 INFO Vacuumed table table=closures11342026/10/06 21:13:27 INFO Vacuumed table table=objects11352026/10/06 21:13:27 INFO Received complete push request method=POST path=/api/pushes/2/complete1136--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.59s)1137=== CONT TestClientPushesUseOnePush1138--- PASS: TestPushWaitsForSweepHoldingRow (1.61s)1139=== CONT TestConnectWaitsForAPeerMigration11402026/10/06 21:13:27 INFO Aborted multipart uploads count=0 kept=011412026/10/06 21:13:27 WARN Force mode enabled - objects will be deleted immediately without grace period11422026/10/06 21:13: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=011432026/10/06 21:13:27 INFO Vacuumed table table=pending_closures11442026/10/06 21:13:27 INFO Vacuumed table table=pending_objects11452026/10/06 21:13:27 INFO Vacuumed table table=multipart_uploads11462026/10/06 21:13:27 INFO Vacuumed table table=closures11472026/10/06 21:13:27 INFO Vacuumed table table=objects11482026/10/06 21:13:27 INFO Aborted multipart uploads count=0 kept=011492026/10/06 21:13:27 WARN Force mode enabled - objects will be deleted immediately without grace period11502026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures11512026/10/06 21:13: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=011522026/10/06 21:13:27 INFO Vacuumed table table=pending_closures11532026/10/06 21:13:27 INFO Vacuumed table table=pending_objects11542026/10/06 21:13:27 INFO Vacuumed table table=multipart_uploads11552026/10/06 21:13:27 INFO Vacuumed table table=closures11562026/10/06 21:13:27 INFO Vacuumed table table=objects11572026/10/06 21:13:27 INFO Aborted multipart uploads count=0 kept=01158--- PASS: TestSweepSkipsRowsLockedByPush (0.54s)1159=== CONT TestPinProtectsFromGC11602026/10/06 21:13: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=011612026/10/06 21:13:27 INFO Vacuumed table table=pending_closures11622026/10/06 21:13:27 INFO Vacuumed table table=pending_objects11632026/10/06 21:13:27 INFO Vacuumed table table=multipart_uploads11642026/10/06 21:13:27 INFO Vacuumed table table=closures11652026/10/06 21:13:27 INFO Vacuumed table table=objects11662026/10/06 21:13:27 INFO Aborted multipart uploads count=0 kept=011672026/10/06 21:13:27 WARN Force mode enabled - objects will be deleted immediately without grace period11682026/10/06 21:13: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=011692026/10/06 21:13:27 INFO Vacuumed table table=pending_closures11702026/10/06 21:13:27 INFO Vacuumed table table=pending_objects11712026/10/06 21:13:27 INFO Received uploads request method=POST path=/api/pending_closures11722026/10/06 21:13:27 INFO Vacuumed table table=multipart_uploads11732026/10/06 21:13:27 INFO Vacuumed table table=closures11742026/10/06 21:13:27 INFO Vacuumed table table=objects11752026/10/06 21:13:28 INFO Aborted multipart uploads count=0 kept=011762026/10/06 21:13:28 WARN Force mode enabled - objects will be deleted immediately without grace period11772026/10/06 21:13: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=01178--- PASS: TestGCMetrics (0.51s)1179=== CONT TestResolveDBConnectionString1180=== RUN TestResolveDBConnectionString/flag_wins1181=== PAUSE TestResolveDBConnectionString/flag_wins1182=== RUN TestResolveDBConnectionString/file_when_flag_empty1183=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1184=== RUN TestResolveDBConnectionString/missing_file_is_an_error1185=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1186=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1187=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1188=== RUN TestResolveDBConnectionString/nothing_configured1189=== PAUSE TestResolveDBConnectionString/nothing_configured1190=== CONT TestClientSharedPathCommittedMidPush11912026/10/06 21:13:28 INFO Vacuumed table table=pending_closures11922026/10/06 21:13:28 INFO Vacuumed table table=pending_objects11932026/10/06 21:13:28 INFO Vacuumed table table=multipart_uploads11942026/10/06 21:13:28 INFO Vacuumed table table=closures11952026/10/06 21:13:28 INFO Vacuumed table table=objects1196--- PASS: TestPushDedupSurvivesConcurrentGC (0.61s)1197=== CONT TestClientWithDependencies11982026/10/06 21:13:28 INFO Aborted multipart uploads count=0 kept=011992026/10/06 21:13:28 INFO Received uploads request method=POST path=/api/pending_closures12002026/10/06 21:13:28 WARN Force mode enabled - objects will be deleted immediately without grace period12012026/10/06 21:13:28 INFO Aborted multipart uploads count=0 kept=012022026/10/06 21:13:28 WARN Force mode enabled - objects will be deleted immediately without grace period1203--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.51s)1204=== CONT TestClientMultipleUploads12052026/10/06 21:13:28 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12062026/10/06 21:13:28 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12072026/10/06 21:13:28 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=012082026/10/06 21:13:28 INFO Vacuumed table table=pending_closures12092026/10/06 21:13:28 INFO Vacuumed table table=pending_objects12102026/10/06 21:13:28 INFO Vacuumed table table=multipart_uploads1211--- PASS: TestFailedS3DeleteKeepsTombstone (0.61s)12122026/10/06 21:13:28 INFO Vacuumed table table=closures1213=== CONT TestClientIntegration12142026/10/06 21:13:28 INFO Vacuumed table table=objects1215--- PASS: TestGCSweepDeliversEachKeyOnce (0.56s)1216=== CONT TestReadProxyDisabled12172026/10/06 21:13: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"1218--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.54s)1219=== CONT TestClientErrorHandling1220=== RUN TestClientErrorHandling/InvalidStorePath1221=== PAUSE TestClientErrorHandling/InvalidStorePath1222=== RUN TestClientErrorHandling/InvalidAuthToken1223=== PAUSE TestClientErrorHandling/InvalidAuthToken1224=== RUN TestClientErrorHandling/ServerNotAvailable1225=== PAUSE TestClientErrorHandling/ServerNotAvailable1226=== CONT TestReadProxyHead12272026/10/06 21:13:28 INFO Received uploads request method=POST path=/api/pending_closures12282026/10/06 21:13:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12292026/10/06 21:13:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12302026/10/06 21:13:28 INFO Aborted multipart uploads count=0 kept=012312026/10/06 21:13:28 WARN Force mode enabled - objects will be deleted immediately without grace period12322026/10/06 21:13:28 INFO Received uploads request method=POST path=/api/pending_closures12332026/10/06 21:13: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=012342026/10/06 21:13:28 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YWFkNjM3YWUtODllMC00YWU1LWI3NzctNzFhODcyM2JmMmEyLmQ1NDc5YTQ3LTQzNDctNDUwNC1iYTg4LWRiYzg2ZDU2NzhhNngxNzkxMzIxMjA3NjQ3OTQ2ODI0 parts=1212352026/10/06 21:13:28 INFO Vacuumed table table=pending_closures1236--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.45s)1237=== CONT TestReadProxyContentNegotiation12382026/10/06 21:13:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YWFkNjM3YWUtODllMC00YWU1LWI3NzctNzFhODcyM2JmMmEyLmUzMWFjMjVlLThjNmItNDBkMC05YTM1LWM4N2Q4MjI3NDBhZngxNzkxMzIxMjA3Njk0NzM0NjYx parts=1212392026/10/06 21:13:28 INFO Vacuumed table table=pending_objects12402026/10/06 21:13:28 INFO Vacuumed table table=multipart_uploads12412026/10/06 21:13:28 INFO Received uploads request method=POST path=/api/pending_closures12422026/10/06 21:13:28 INFO Vacuumed table table=closures1243--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.66s)1244=== CONT TestReadProxyRangeRequest12452026/10/06 21:13:28 INFO Vacuumed table table=objects12462026/10/06 21:13:28 INFO Received uploads request method=POST path=/api/pending_closures12472026/10/06 21:13:28 INFO Received uploads request method=POST path=/api/pending_closures1248--- PASS: TestGCSweepSkipsPendingObjects (0.52s)1249=== CONT TestReadProxyInvalidPath12502026/10/06 21:13:28 INFO lead: acquired remote=192.0.2.1:12341251--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.42s)1252=== CONT TestReadProxyRootRedirectsToIndexHTML12532026/10/06 21:13:28 INFO lead: acquired remote=192.0.2.1:123412542026/10/06 21:13:28 INFO lead: released remote=192.0.2.1:12341255--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.41s)1256=== CONT TestReadRedirectKeepsNarinfoProxied1257--- PASS: TestGCBugBareHashReferences (0.76s)1258=== CONT TestReadProxy40412592026/10/06 21:13:28 INFO lead: acquired remote=192.0.2.1:12341260--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.84s)1261=== CONT TestReadProxyConditionalGet1262=== NAME TestClientCADerivations1263 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2753148232/001/store/s4zvp4xl5z0fxgi9z3z14bsc58s2jv31-ca-test1264 client_ca_test.go:139: Found 1 dependencies (including self)1265--- PASS: TestReadProxyDisabled (0.29s)1266=== CONT TestReadRedirectNar1267=== NAME TestPinProtectsFromGC1268 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3201827662/001/store/h07r0vdj47z9mm4j1fz52f6ic7hw0vy7-pinned-file.txt1269 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3201827662/001/store/ig2fl9fc6gaw4n1h18abc6gfp7qqqgdw-unpinned-file.txt1270=== NAME TestClientMultipleUploads1271 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2917687885/001/store/dmh81wp5lzkx8pplmp0j4ipf0w92d38a-test-file-0.txt1272--- PASS: TestReadProxyHead (0.33s)1273=== CONT TestReadProxyNarStreaming1274=== NAME TestClientWithDependencies1275 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies923381179/001/store/gypddmyv99nzb3i2w6lxy5rkxspslis4-test-script1276--- PASS: TestReadProxyInvalidPath (0.29s)1277=== CONT TestReadProxyOutlastsServerWriteTimeout1278=== NAME TestClientMultipleUploads1279 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2917687885/001/store/cpgmd1g83xriw90219rar90cdsgccjql-test-file-1.txt1280=== NAME TestClientIntegration1281 client_integration_test.go:286: Created store path: /build/TestClientIntegration4260566354/002/store/xi8ihykbn1mk6sl3bxqv4mw72k7j3jpg-test-file.txt12822026/10/06 21:13:28 INFO Received uploads request method=POST path=/api/pending_closures12832026/10/06 21:13:28 INFO Received uploads request method=POST path=/api/pending_closures12842026/10/06 21:13:28 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12852026/10/06 21:13:28 INFO Uploading 3dn0fvbk7sb13llakx3v4aqmpmyxrbia-shared-dep (136B)12862026/10/06 21:13:28 INFO Uploading qadk3zdvlc7wm05l253yqrs1yyg983mw-a (216B)12872026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes12882026/10/06 21:13:28 WARN Failed to register uploaded object key=k1fpb1lxl88bqsrsygmhkd5dy9p8f8m4.ls error="server returned 404: 404 page not found\n"12892026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/0313q4nyffv1kpfq4a7z7d1ypwykj6a4wnldsgrfhdm663imn1g4.nar.zst error="server returned 404: 404 page not found\n"12902026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12912026/10/06 21:13:28 WARN Failed to register uploaded object key=qadk3zdvlc7wm05l253yqrs1yyg983mw.ls error="server returned 404: 404 page not found\n"12922026/10/06 21:13:28 WARN Failed to register uploaded object key=3dn0fvbk7sb13llakx3v4aqmpmyxrbia.ls error="server returned 404: 404 page not found\n"12932026/10/06 21:13:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12942026/10/06 21:13:28 INFO Signed narinfos id=1 count=212952026/10/06 21:13:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12962026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes12972026/10/06 21:13:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12982026/10/06 21:13:28 INFO Uploading s4zvp4xl5z0fxgi9z3z14bsc58s2jv31-ca-test (144B)12992026/10/06 21:13:28 INFO Signed narinfos id=2 count=213002026/10/06 21:13:28 INFO Uploading 4 narinfos13012026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13022026/10/06 21:13:28 WARN Failed to register uploaded object key=log/v5j1b1bms8mni9f4cbpkr0mbhx58fvkb-ca-test.drv error="server returned 404: 404 page not found\n"13032026/10/06 21:13:28 WARN Failed to register uploaded object key=k1fpb1lxl88bqsrsygmhkd5dy9p8f8m4.narinfo error="server returned 404: 404 page not found\n"13042026/10/06 21:13:28 WARN Failed to register uploaded object key=3dn0fvbk7sb13llakx3v4aqmpmyxrbia.narinfo error="server returned 404: 404 page not found\n"13052026/10/06 21:13:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13062026/10/06 21:13:28 INFO Uploading h07r0vdj47z9mm4j1fz52f6ic7hw0vy7-pinned-file.txt (128B)13072026/10/06 21:13:28 WARN Failed to register uploaded object key=s4zvp4xl5z0fxgi9z3z14bsc58s2jv31.ls error="server returned 404: 404 page not found\n"13082026/10/06 21:13:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13092026/10/06 21:13:28 INFO Signed narinfos id=1 count=113102026/10/06 21:13:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13112026/10/06 21:13:28 WARN Failed to register uploaded object key=qadk3zdvlc7wm05l253yqrs1yyg983mw.narinfo error="server returned 404: 404 page not found\n"13122026/10/06 21:13:28 INFO Uploading 1 narinfos13132026/10/06 21:13:28 WARN Failed to register uploaded object key=3dn0fvbk7sb13llakx3v4aqmpmyxrbia.narinfo error="server returned 404: 404 page not found\n"13142026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13152026/10/06 21:13:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13162026/10/06 21:13:28 WARN Failed to register uploaded object key=h07r0vdj47z9mm4j1fz52f6ic7hw0vy7.ls error="server returned 404: 404 page not found\n"13172026/10/06 21:13:28 INFO Signed narinfos id=1 count=113182026/10/06 21:13:28 INFO Uploading 1 narinfos13192026/10/06 21:13:28 INFO Received complete push request method=POST path=/api/pushes/1/complete13202026/10/06 21:13:28 WARN Failed to register uploaded object key=s4zvp4xl5z0fxgi9z3z14bsc58s2jv31.narinfo error="server returned 404: 404 page not found\n"13212026/10/06 21:13:28 INFO Completed upload id=113222026/10/06 21:13:28 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1323--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.32s)1324=== CONT TestReadProxyNarinfo13252026/10/06 21:13:28 INFO Completed upload id=213262026/10/06 21:13:28 INFO Upload complete. (70ms)13272026/10/06 21:13:28 INFO Received complete push request method=POST path=/api/pushes/1/complete13282026/10/06 21:13:28 WARN Failed to register uploaded object key=h07r0vdj47z9mm4j1fz52f6ic7hw0vy7.narinfo error="server returned 404: 404 page not found\n"1329=== NAME TestClientFallsBackToClosures1330 client_pushes_test.go:112: Retrieved narinfo from S3:1331 StorePath: /build/TestClientFallsBackToClosures3631186952/001/store/3dn0fvbk7sb13llakx3v4aqmpmyxrbia-shared-dep1332 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1333 Compression: zstd1334 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821335 NarSize: 1361336 References: 1337=== NAME TestClientWithDependencies1338 client_integration_test.go:615: Found 1 dependencies (including self)1339=== NAME TestClientFallsBackToClosures1340 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1341 client_pushes_test.go:112: Retrieved narinfo from S3:1342 StorePath: /build/TestClientFallsBackToClosures3631186952/001/store/qadk3zdvlc7wm05l253yqrs1yyg983mw-a1343 URL: nar/0313q4nyffv1kpfq4a7z7d1ypwykj6a4wnldsgrfhdm663imn1g4.nar.zst1344 Compression: zstd1345 NarHash: sha256:0313q4nyffv1kpfq4a7z7d1ypwykj6a4wnldsgrfhdm663imn1g41346 NarSize: 2161347 References: /build/TestClientFallsBackToClosures3631186952/001/store/3dn0fvbk7sb13llakx3v4aqmpmyxrbia-shared-dep1348 CA: text:sha256:1dx7y63rf2yfnmyjk1ry9zh0fwsk1fr59j9h5x242wcd0k15wsw21349 client_pushes_test.go:112: Retrieved narinfo from S3:1350 StorePath: /build/TestClientFallsBackToClosures3631186952/001/store/k1fpb1lxl88bqsrsygmhkd5dy9p8f8m4-b1351 URL: nar/0313q4nyffv1kpfq4a7z7d1ypwykj6a4wnldsgrfhdm663imn1g4.nar.zst1352 Compression: zstd1353 NarHash: sha256:0313q4nyffv1kpfq4a7z7d1ypwykj6a4wnldsgrfhdm663imn1g41354 NarSize: 2161355 References: /build/TestClientFallsBackToClosures3631186952/001/store/3dn0fvbk7sb13llakx3v4aqmpmyxrbia-shared-dep1356 CA: text:sha256:1dx7y63rf2yfnmyjk1ry9zh0fwsk1fr59j9h5x242wcd0k15wsw21357--- PASS: TestClientFallsBackToClosures (0.66s)1358=== NAME TestClientMultipleUploads1359 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2917687885/001/store/3sj7wf4c7dlmsw89k13spy624yxvg18p-test-file-2.txt1360=== CONT TestIsValidCachePath1361=== RUN TestIsValidCachePath/narinfo1362=== PAUSE TestIsValidCachePath/narinfo1363=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1364=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1365=== RUN TestIsValidCachePath/nar_zst1366=== PAUSE TestIsValidCachePath/nar_zst1367=== RUN TestIsValidCachePath/nar_xz1368=== PAUSE TestIsValidCachePath/nar_xz1369=== RUN TestIsValidCachePath/nar_bz21370=== PAUSE TestIsValidCachePath/nar_bz21371=== RUN TestIsValidCachePath/nar_uncompressed1372=== PAUSE TestIsValidCachePath/nar_uncompressed1373=== RUN TestIsValidCachePath/ls1374=== PAUSE TestIsValidCachePath/ls1375=== RUN TestIsValidCachePath/log1376=== PAUSE TestIsValidCachePath/log1377=== RUN TestIsValidCachePath/realisation1378=== PAUSE TestIsValidCachePath/realisation1379=== RUN TestIsValidCachePath/nix-cache-info1380=== PAUSE TestIsValidCachePath/nix-cache-info1381=== RUN TestIsValidCachePath/index.html1382=== PAUSE TestIsValidCachePath/index.html1383=== RUN TestIsValidCachePath/traversal_parent1384=== PAUSE TestIsValidCachePath/traversal_parent1385=== RUN TestIsValidCachePath/traversal_in_middle1386=== PAUSE TestIsValidCachePath/traversal_in_middle1387=== RUN TestIsValidCachePath/invalid_char_e1388=== PAUSE TestIsValidCachePath/invalid_char_e1389=== RUN TestIsValidCachePath/invalid_char_u1390=== PAUSE TestIsValidCachePath/invalid_char_u1391=== RUN TestIsValidCachePath/random_path1392=== PAUSE TestIsValidCachePath/random_path1393=== RUN TestIsValidCachePath/empty1394=== PAUSE TestIsValidCachePath/empty1395=== RUN TestIsValidCachePath/leading_slash1396=== PAUSE TestIsValidCachePath/leading_slash1397=== RUN TestIsValidCachePath/wrong_extension1398=== PAUSE TestIsValidCachePath/wrong_extension1399=== RUN TestIsValidCachePath/short_hash1400=== PAUSE TestIsValidCachePath/short_hash1401=== CONT TestService_RequireScope_OIDC14022026/10/06 21:13:28 INFO Upload complete. (122ms)14032026/10/06 21:13:28 INFO Upload complete. (74ms)1404--- PASS: TestReadProxyContentNegotiation (0.36s)1405=== CONT TestReadProxyNarinfoAlreadyDecompressed1406=== NAME TestClientCADerivations1407 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2753148232/001/store/s4zvp4xl5z0fxgi9z3z14bsc58s2jv31-ca-test1408 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1409 Compression: zstd1410 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1411 NarSize: 1441412 References: 1413 Deriver: /build/TestClientCADerivations2753148232/001/store/v5j1b1bms8mni9f4cbpkr0mbhx58fvkb-ca-test.drv1414 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1415 client_ca_test.go:185: Checking for realisation files in S3...1416 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1417 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14182026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes1419--- PASS: TestReadProxyRangeRequest (0.36s)1420=== CONT TestService_ReadAuthMiddleware14212026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes14222026/10/06 21:13:28 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14232026/10/06 21:13:28 INFO Uploading mh09d8ynl0r1br5yjb122c9jsx6z3gbl-a (216B)14242026/10/06 21:13:28 INFO Uploading bfx9dmkf3q4bhb1bd02cqkrc9l5lhccg-shared-dep (136B)14252026/10/06 21:13:28 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14262026/10/06 21:13:28 INFO Uploading 5cfi8mlps4j3qk2bilyavzdbxy47aqcv-top (224B)14272026/10/06 21:13:28 INFO Uploading ai57wabvxa6c0sbv32s3mpn1qbykbqvl-shared-dep (136B)14282026/10/06 21:13:28 WARN Failed to register uploaded object key=5vnx921fdnsdcncysfv51n1q6q3jk6ar.ls error="server returned 404: 404 page not found\n"14292026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/0khmjrmkww0nbdp2v7f6rmp1l9gia4bc1zh57y53ybzjdhvzm378.nar.zst error="server returned 404: 404 page not found\n"14302026/10/06 21:13:28 WARN Failed to register uploaded object key=mh09d8ynl0r1br5yjb122c9jsx6z3gbl.ls error="server returned 404: 404 page not found\n"14312026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14322026/10/06 21:13:28 WARN Failed to register uploaded object key=bfx9dmkf3q4bhb1bd02cqkrc9l5lhccg.ls error="server returned 404: 404 page not found\n"14332026/10/06 21:13:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14342026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14352026/10/06 21:13:28 WARN Failed to register uploaded object key=ai57wabvxa6c0sbv32s3mpn1qbykbqvl.ls error="server returned 404: 404 page not found\n"14362026/10/06 21:13:28 INFO Signed narinfos id=1 count=314372026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/1zp46rh9mwvi5kig2gxpgbzx5p2ajks5jzr8fws2cxijdvfzjlrb.nar.zst error="server returned 404: 404 page not found\n"14382026/10/06 21:13:28 INFO Uploading 3 narinfos14392026/10/06 21:13:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14402026/10/06 21:13:28 INFO Signed narinfos id=1 count=214412026/10/06 21:13:28 WARN Failed to register uploaded object key=5cfi8mlps4j3qk2bilyavzdbxy47aqcv.ls error="server returned 404: 404 page not found\n"14422026/10/06 21:13:28 INFO Uploading 2 narinfos14432026/10/06 21:13:28 WARN Failed to register uploaded object key=5cfi8mlps4j3qk2bilyavzdbxy47aqcv.narinfo error="server returned 404: 404 page not found\n"14442026/10/06 21:13:28 WARN Failed to register uploaded object key=bfx9dmkf3q4bhb1bd02cqkrc9l5lhccg.narinfo error="server returned 404: 404 page not found\n"14452026/10/06 21:13:28 WARN Failed to register uploaded object key=5vnx921fdnsdcncysfv51n1q6q3jk6ar.narinfo error="server returned 404: 404 page not found\n"14462026/10/06 21:13:28 INFO Received complete push request method=POST path=/api/pushes/1/complete14472026/10/06 21:13:28 WARN Failed to register uploaded object key=ai57wabvxa6c0sbv32s3mpn1qbykbqvl.narinfo error="server returned 404: 404 page not found\n"14482026/10/06 21:13:28 INFO Received complete push request method=POST path=/api/pushes/1/complete14492026/10/06 21:13:28 WARN Failed to register uploaded object key=mh09d8ynl0r1br5yjb122c9jsx6z3gbl.narinfo error="server returned 404: 404 page not found\n"1450--- PASS: TestReadRedirectKeepsNarinfoProxied (0.32s)1451=== CONT TestCacheStatsHandler14522026/10/06 21:13:28 INFO Upload complete. (79ms)14532026/10/06 21:13:28 INFO Upload complete. (80ms)1454=== NAME TestClientPushesUseOnePush1455 client_pushes_test.go:97: Retrieved narinfo from S3:1456 StorePath: /build/TestClientPushesUseOnePush3131015864/001/store/bfx9dmkf3q4bhb1bd02cqkrc9l5lhccg-shared-dep1457 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1458 Compression: zstd1459 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821460 NarSize: 1361461 References: 1462 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1463=== NAME TestClientSharedPathCommittedMidPush1464 client_integration_test.go:680: Retrieved narinfo from S3:1465 StorePath: /build/TestClientSharedPathCommittedMidPush2006556528/001/store/ai57wabvxa6c0sbv32s3mpn1qbykbqvl-shared-dep1466 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1467 Compression: zstd1468 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821469 NarSize: 1361470 References: 1471 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14722026/10/06 21:13:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33869/oidc14732026/10/06 21:13:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1474=== NAME TestClientPushesUseOnePush1475 client_pushes_test.go:97: Retrieved narinfo from S3:1476 StorePath: /build/TestClientPushesUseOnePush3131015864/001/store/mh09d8ynl0r1br5yjb122c9jsx6z3gbl-a1477 URL: nar/0khmjrmkww0nbdp2v7f6rmp1l9gia4bc1zh57y53ybzjdhvzm378.nar.zst1478 Compression: zstd1479 NarHash: sha256:0khmjrmkww0nbdp2v7f6rmp1l9gia4bc1zh57y53ybzjdhvzm3781480 NarSize: 2161481 References: /build/TestClientPushesUseOnePush3131015864/001/store/bfx9dmkf3q4bhb1bd02cqkrc9l5lhccg-shared-dep1482 CA: text:sha256:06d3zzhdklfy6jh542h5w4if3rkmf0z0x9vmj3z27a2pqhvc04291483=== NAME TestClientSharedPathCommittedMidPush1484 client_integration_test.go:680: Retrieved narinfo from S3:1485 StorePath: /build/TestClientSharedPathCommittedMidPush2006556528/001/store/5cfi8mlps4j3qk2bilyavzdbxy47aqcv-top1486 URL: nar/1zp46rh9mwvi5kig2gxpgbzx5p2ajks5jzr8fws2cxijdvfzjlrb.nar.zst1487 Compression: zstd1488 NarHash: sha256:1zp46rh9mwvi5kig2gxpgbzx5p2ajks5jzr8fws2cxijdvfzjlrb1489 NarSize: 2241490 References: /build/TestClientSharedPathCommittedMidPush2006556528/001/store/ai57wabvxa6c0sbv32s3mpn1qbykbqvl-shared-dep1491 CA: text:sha256:068b8zqm0vsx1jc7pnawmn7zb3b8smjxrvjfnvgc4qrrr05w85js1492=== NAME TestClientPushesUseOnePush1493 client_pushes_test.go:97: Retrieved narinfo from S3:1494 StorePath: /build/TestClientPushesUseOnePush3131015864/001/store/5vnx921fdnsdcncysfv51n1q6q3jk6ar-b1495 URL: nar/0khmjrmkww0nbdp2v7f6rmp1l9gia4bc1zh57y53ybzjdhvzm378.nar.zst1496 Compression: zstd1497 NarHash: sha256:0khmjrmkww0nbdp2v7f6rmp1l9gia4bc1zh57y53ybzjdhvzm3781498 NarSize: 2161499 References: /build/TestClientPushesUseOnePush3131015864/001/store/bfx9dmkf3q4bhb1bd02cqkrc9l5lhccg-shared-dep1500 CA: text:sha256:06d3zzhdklfy6jh542h5w4if3rkmf0z0x9vmj3z27a2pqhvc042915012026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes1502--- PASS: TestClientPushesUseOnePush (0.65s)1503=== CONT TestService_AuthMiddleware_OIDC1504--- PASS: TestClientSharedPathCommittedMidPush (0.56s)1505=== CONT TestCacheConfigHandler1506=== RUN TestCacheConfigHandler/full_config,_no_issuer1507=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1508=== RUN TestCacheConfigHandler/no_cache_url_configured1509=== PAUSE TestCacheConfigHandler/no_cache_url_configured1510=== RUN TestCacheConfigHandler/no_signing_keys1511=== PAUSE TestCacheConfigHandler/no_signing_keys1512=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1513=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1514=== CONT TestService_ReadScope_PublicByDefault15152026/10/06 21:13:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15162026/10/06 21:13:28 INFO Uploading xi8ihykbn1mk6sl3bxqv4mw72k7j3jpg-test-file.txt (152B)15172026/10/06 21:13:28 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YWFkNjM3YWUtODllMC00YWU1LWI3NzctNzFhODcyM2JmMmEyLmE5OGRmYjBiLTAzODAtNGZjYi04MzdiLTkyOWNjOGVjOTQwN3gxNzkxMzIxMjA4MTcyNDQ0MTAz error="Get \"http://127.0.0.1:1/bucket35/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15182026/10/06 21:13:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YWFkNjM3YWUtODllMC00YWU1LWI3NzctNzFhODcyM2JmMmEyLjc1MGM1ZWUzLTdiYWYtNDI0MS1iYjExLWFhMDkyMzQ4YmJlN3gxNzkxMzIxMjA4MTY2MzkyNTk5 parts=1215192026/10/06 21:13:28 INFO Received cleanup request method=DELETE path=/api/pending_closures15202026/10/06 21:13:28 WARN Failed to register uploaded object key=xi8ihykbn1mk6sl3bxqv4mw72k7j3jpg.ls error="server returned 404: 404 page not found\n"15212026/10/06 21:13:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15222026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15232026/10/06 21:13:28 INFO Signed narinfos id=1 count=115242026/10/06 21:13:28 INFO Uploading 1 narinfos15252026/10/06 21:13:28 INFO Aborted multipart uploads count=1 kept=015262026/10/06 21:13:28 INFO Received complete push request method=POST path=/api/pushes/1/complete15272026/10/06 21:13:28 WARN Failed to register uploaded object key=xi8ihykbn1mk6sl3bxqv4mw72k7j3jpg.narinfo error="server returned 404: 404 page not found\n"1528--- PASS: TestRedundantMultipartUpload (1.72s)1529=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1530--- PASS: TestReadProxy404 (0.31s)1531=== CONT TestService_AuthMiddleware_MTLSProxyHeader15322026/10/06 21:13:28 INFO Upload complete. (83ms)15332026/10/06 21:13:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42149/oidc15342026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes1535--- PASS: TestReadProxyConditionalGet (0.29s)1536=== CONT TestProxyWriteTimeout/narinfo1537=== CONT TestProxyWriteTimeout/unknown_size1538=== CONT TestProxyWriteTimeout/10_GiB_nar1539=== CONT TestProxyWriteTimeout/1_GiB_nar1540--- PASS: TestProxyWriteTimeout (0.00s)1541 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1542 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1543 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1544 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1545=== CONT TestServerTLSConfig/no_client_CA1546=== CONT TestServerTLSConfig/not_a_PEM_file1547=== CONT TestServerTLSConfig/missing_CA_file1548--- PASS: TestServerTLSConfig (0.08s)1549 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1550 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1551 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1552=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15532026/10/06 21:13:28 INFO Received uploads request method=POST path=/1554=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15552026/10/06 21:13:28 INFO Received complete multipart upload request method=POST path=/1556=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15572026/10/06 21:13:28 INFO Received request for more parts method=POST path=/1558=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15592026/10/06 21:13:28 INFO Received uploads request method=POST path=/1560--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1561 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1562 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1563 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1564 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1565=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale15662026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes15672026/10/06 21:13:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15682026/10/06 21:13:28 INFO Uploading gypddmyv99nzb3i2w6lxy5rkxspslis4-test-script (136B)15692026/10/06 21:13:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15702026/10/06 21:13:28 INFO Uploading ig2fl9fc6gaw4n1h18abc6gfp7qqqgdw-unpinned-file.txt (128B)1571--- PASS: TestReadRedirectNar (0.21s)1572=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh15732026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15742026/10/06 21:13:28 WARN Failed to register uploaded object key=gypddmyv99nzb3i2w6lxy5rkxspslis4.ls error="server returned 404: 404 page not found\n"15752026/10/06 21:13:28 WARN Failed to register uploaded object key=log/xip8sql7dj4z829vw8a32mhvafj4im3b-test-script.drv error="server returned 404: 404 page not found\n"15762026/10/06 21:13:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15772026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes15782026/10/06 21:13:28 INFO Signed narinfos id=1 count=115792026/10/06 21:13:28 INFO Uploading 1 narinfos15802026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15812026/10/06 21:13:28 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15822026/10/06 21:13:28 WARN Failed to register uploaded object key=ig2fl9fc6gaw4n1h18abc6gfp7qqqgdw.ls error="server returned 404: 404 page not found\n"15832026/10/06 21:13:28 INFO Signed narinfos id=2 count=115842026/10/06 21:13:28 INFO Uploading 1 narinfos15852026/10/06 21:13:28 INFO Received complete push request method=POST path=/api/pushes/1/complete15862026/10/06 21:13:28 WARN Failed to register uploaded object key=gypddmyv99nzb3i2w6lxy5rkxspslis4.narinfo error="server returned 404: 404 page not found\n"15872026/10/06 21:13:28 INFO Received complete push request method=POST path=/api/pushes/2/complete15882026/10/06 21:13:28 WARN Failed to register uploaded object key=ig2fl9fc6gaw4n1h18abc6gfp7qqqgdw.narinfo error="server returned 404: 404 page not found\n"15892026/10/06 21:13:28 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15902026/10/06 21:13:28 INFO Uploading 3sj7wf4c7dlmsw89k13spy624yxvg18p-test-file-2.txt (160B)15912026/10/06 21:13:28 INFO Uploading dmh81wp5lzkx8pplmp0j4ipf0w92d38a-test-file-0.txt (160B)15922026/10/06 21:13:28 INFO Uploading cpgmd1g83xriw90219rar90cdsgccjql-test-file-1.txt (160B)15932026/10/06 21:13:28 INFO Upload complete. (82ms)15942026/10/06 21:13:28 INFO All 1 paths already cached15952026/10/06 21:13:28 INFO Upload complete. (61ms)1596=== NAME TestClientIntegration1597 client_integration_test.go:312: Retrieved narinfo from S3:1598 StorePath: /build/TestClientIntegration4260566354/002/store/xi8ihykbn1mk6sl3bxqv4mw72k7j3jpg-test-file.txt1599 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1600 Compression: zstd1601 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11602 NarSize: 1521603 References: 1604 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk116052026/10/06 21:13:28 WARN Failed to register uploaded object key=cpgmd1g83xriw90219rar90cdsgccjql.ls error="server returned 404: 404 page not found\n"16062026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1607=== NAME TestClientWithDependencies1608 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies923381179/001/store) requires matching store prefix16092026/10/06 21:13:28 WARN Failed to register uploaded object key=3sj7wf4c7dlmsw89k13spy624yxvg18p.ls error="server returned 404: 404 page not found\n"16102026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16112026/10/06 21:13:28 WARN Failed to register uploaded object key=dmh81wp5lzkx8pplmp0j4ipf0w92d38a.ls error="server returned 404: 404 page not found\n"16122026/10/06 21:13:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16132026/10/06 21:13:28 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1614=== NAME TestClientIntegration1615 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)16162026/10/06 21:13:28 INFO Signed narinfos id=1 count=31617 client_integration_test.go:313: Decompressed .ls content (64 bytes):1618 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}16192026/10/06 21:13:28 INFO Uploading 3 narinfos1620 client_integration_test.go:316: Testing garbage collection...1621--- PASS: TestClientWithDependencies (0.61s)1622=== CONT TestPendingClosureWriteTimeout/empty1623=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline16242026/10/06 21:13:28 WARN Failed to register uploaded object key=3sj7wf4c7dlmsw89k13spy624yxvg18p.narinfo error="server returned 404: 404 page not found\n"16252026/10/06 21:13:28 WARN Failed to register uploaded object key=dmh81wp5lzkx8pplmp0j4ipf0w92d38a.narinfo error="server returned 404: 404 page not found\n"16262026/10/06 21:13:28 INFO Received complete push request method=POST path=/api/pushes/1/complete16272026/10/06 21:13:28 WARN Failed to register uploaded object key=cpgmd1g83xriw90219rar90cdsgccjql.narinfo error="server returned 404: 404 page not found\n"16282026/10/06 21:13:28 INFO Upload complete. (79ms)1629=== NAME TestClientMultipleUploads1630 client_integration_test.go:369: Uploaded 3 paths in 129.025192ms1631--- PASS: TestClientMultipleUploads (0.55s)1632=== CONT TestPendingClosureWriteTimeout/670k_objects1633=== CONT TestPendingClosureWriteTimeout/400_objects1634=== CONT TestIsValidUploadKey/narinfo1635=== CONT TestIsValidUploadKey/realisation1636=== CONT TestIsValidUploadKey/build_log_equals1637=== CONT TestIsValidUploadKey/build_log_question_mark1638=== CONT TestIsValidUploadKey/realisation_plus_in_output1639=== CONT TestIsValidUploadKey/build_log_plus_in_name1640=== CONT TestIsValidUploadKey/build_log_home-manager_file1641=== CONT TestIsValidUploadKey/unknown_type1642=== CONT TestIsValidUploadKey/build_log1643=== CONT TestIsValidUploadKey/empty_key1644=== CONT TestIsValidUploadKey/listing1645=== CONT TestIsValidUploadKey/absolute1646=== CONT TestIsValidUploadKey/traversal_nar1647=== CONT TestIsValidUploadKey/nar_plain1648=== CONT TestIsValidUploadKey/nar_zst1649--- PASS: TestReadProxyNarStreaming (0.20s)1650=== CONT TestIsValidUploadKey/traversal1651=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1652=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1653=== CONT TestIsValidUploadKey/index.html1654=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1655=== CONT TestIsValidUploadKey/nar_xz1656=== CONT TestIsValidUploadKey/nix-cache-info1657--- PASS: TestIsValidUploadKey (0.08s)1658 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1659 --- PASS: TestIsValidUploadKey/realisation (0.00s)1660 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1661 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1662 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1663 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1664 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1665 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1666 --- PASS: TestIsValidUploadKey/build_log (0.00s)1667 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1668 --- PASS: TestIsValidUploadKey/listing (0.00s)1669 --- PASS: TestIsValidUploadKey/absolute (0.00s)1670 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1671 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1672 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1673 --- PASS: TestIsValidUploadKey/traversal (0.00s)1674 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1675 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1676 --- PASS: TestIsValidUploadKey/index.html (0.00s)1677 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1678 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1679 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1680=== CONT TestParseSingleRange/none1681=== CONT TestParseSingleRange/open-ended1682=== CONT TestParseSingleRange/start_far_past_EOF1683=== CONT TestParseSingleRange/single_byte1684=== CONT TestParseSingleRange/start_past_EOF1685=== CONT TestParseSingleRange/suffix1686=== CONT TestParseSingleRange/end_clamped_to_size1687=== CONT TestParseSingleRange/malformed_both_empty1688=== CONT TestParseSingleRange/closed1689=== CONT TestParseSingleRange/malformed_end_before_start1690=== CONT TestParseSingleRange/malformed_no_dash1691=== CONT TestParseSingleRange/unknown_unit1692=== CONT TestParseSingleRange/suffix_exceeds_size1693=== CONT TestParseSingleRange/multi-range_ignored1694=== CONT TestGCEndsOnShutdown/before_the_run1695--- PASS: TestParseSingleRange (0.08s)1696 --- PASS: TestParseSingleRange/none (0.00s)1697 --- PASS: TestParseSingleRange/open-ended (0.00s)1698 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1699 --- PASS: TestParseSingleRange/single_byte (0.00s)1700 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1701 --- PASS: TestParseSingleRange/suffix (0.00s)1702 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1703 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1704 --- PASS: TestParseSingleRange/closed (0.00s)1705 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1706 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1707 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1708 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1709 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1710=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1711=== NAME TestClientCADerivations1712 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1713 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1714 error: binary cache 's3://bucket54?endpoint=http://localhost:42601®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2753148232/001/store'1715 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117162026/10/06 21:13:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures17172026/10/06 21:13:28 INFO Garbage collection started1718--- PASS: TestClientCADerivations (0.93s)1719=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17202026/10/06 21:13:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures17212026/10/06 21:13:28 INFO Garbage collection started17222026/10/06 21:13:28 INFO Aborted multipart uploads count=0 kept=017232026/10/06 21:13:28 INFO Aborted multipart uploads count=0 kept=017242026/10/06 21:13:28 WARN Force mode enabled - objects will be deleted immediately without grace period17252026/10/06 21:13:28 WARN Force mode enabled - objects will be deleted immediately without grace period17262026/10/06 21:13: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=017272026/10/06 21:13: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=017282026/10/06 21:13:28 INFO Vacuumed table table=pending_closures17292026/10/06 21:13:28 INFO Vacuumed table table=pending_closures17302026/10/06 21:13:28 INFO Vacuumed table table=pending_objects17312026/10/06 21:13:28 INFO Vacuumed table table=multipart_uploads17322026/10/06 21:13:28 INFO Vacuumed table table=pending_objects17332026/10/06 21:13:28 INFO Vacuumed table table=multipart_uploads17342026/10/06 21:13:28 INFO Vacuumed table table=closures17352026/10/06 21:13:28 INFO Vacuumed table table=closures17362026/10/06 21:13:28 INFO Vacuumed table table=objects17372026/10/06 21:13:28 INFO Vacuumed table table=objects1738--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.27s)1739=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17402026/10/06 21:13:28 INFO Received uploads request method=POST path=/1741--- PASS: TestService_ReadAuthMiddleware (0.28s)1742=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17432026/10/06 21:13:28 INFO Received request for more parts method=POST path=/1744--- PASS: TestCacheStatsHandler (0.30s)1745=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17462026/10/06 21:13:28 INFO Received complete multipart upload request method=POST path=/17472026/10/06 21:13:28 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1748--- PASS: TestReadProxyNarinfo (0.36s)1749=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1750=== RUN TestService_RequireScope_OIDC/builder_may_write1751=== PAUSE TestService_RequireScope_OIDC/builder_may_write1752=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1753=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1754=== RUN TestService_RequireScope_OIDC/ops_may_admin1755=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1756=== RUN TestService_RequireScope_OIDC/ops_may_not_write1757=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1758=== RUN TestService_RequireScope_OIDC/reader_may_not_write1759=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1760=== RUN TestService_RequireScope_OIDC/static_token_may_admin1761=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1762=== RUN TestService_RequireScope_OIDC/static_token_may_write1763=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1764=== RUN TestService_RequireScope_OIDC/reader_may_read1765=== PAUSE TestService_RequireScope_OIDC/reader_may_read1766=== RUN TestService_RequireScope_OIDC/writer_implies_read1767=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1768=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1769=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1770=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1771=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1772=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1773=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1774=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1775=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1776=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1777=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1778=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1779=== CONT TestPush_RejectsBadRequests/no_roots17802026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes1781=== CONT TestPush_RejectsBadRequests/bad_root17822026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes1783=== CONT TestPush_RejectsBadRequests/root_not_in_objects17842026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes1785=== CONT TestPush_RejectsBadRequests/no_objects17862026/10/06 21:13:28 INFO Received push request method=POST path=/api/pushes1787=== CONT TestResolveDBConnectionString/flag_wins1788=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1789=== CONT TestResolveDBConnectionString/nothing_configured1790=== CONT TestResolveDBConnectionString/missing_file_is_an_error1791--- PASS: TestPush_RejectsBadRequests (0.82s)1792 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1793 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1794 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1795 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1796=== CONT TestResolveDBConnectionString/file_when_flag_empty1797=== CONT TestClientErrorHandling/InvalidStorePath1798--- PASS: TestResolveDBConnectionString (0.00s)1799 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1800 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1801 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1802 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1803 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1804--- PASS: TestService_ReadScope_PublicByDefault (0.32s)1805=== CONT TestClientErrorHandling/ServerNotAvailable1806=== NAME TestOrphanedObjectsGCStressTest1807 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1808=== CONT TestClientErrorHandling/InvalidAuthToken18092026/10/06 21:13:28 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18102026/10/06 21:13:28 WARN mTLS auth: bound subjects configured but subject DN unavailable18112026/10/06 21:13:28 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1812--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.33s)1813=== CONT TestIsValidCachePath/narinfo1814=== CONT TestIsValidCachePath/index.html1815=== CONT TestIsValidCachePath/short_hash1816=== CONT TestIsValidCachePath/wrong_extension1817=== CONT TestIsValidCachePath/leading_slash1818=== CONT TestIsValidCachePath/empty1819=== CONT TestIsValidCachePath/random_path1820=== CONT TestIsValidCachePath/invalid_char_u1821=== CONT TestIsValidCachePath/invalid_char_e1822=== CONT TestIsValidCachePath/traversal_in_middle1823=== CONT TestIsValidCachePath/traversal_parent1824=== CONT TestIsValidCachePath/nar_xz1825=== CONT TestIsValidCachePath/nar_bz21826=== CONT TestIsValidCachePath/realisation1827=== CONT TestIsValidCachePath/nar_uncompressed1828=== CONT TestIsValidCachePath/nix-cache-info1829=== CONT TestIsValidCachePath/log1830=== CONT TestIsValidCachePath/nar_zst1831=== CONT TestIsValidCachePath/ls1832=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1833=== CONT TestCacheConfigHandler/full_config,_no_issuer1834--- PASS: TestIsValidCachePath (0.00s)1835 --- PASS: TestIsValidCachePath/narinfo (0.00s)1836 --- PASS: TestIsValidCachePath/index.html (0.00s)1837 --- PASS: TestIsValidCachePath/short_hash (0.00s)1838 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1839 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1840 --- PASS: TestIsValidCachePath/empty (0.00s)1841 --- PASS: TestIsValidCachePath/random_path (0.00s)1842 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1843 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1844 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1845 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1846 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1847 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1848 --- PASS: TestIsValidCachePath/realisation (0.00s)1849 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1850 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1851 --- PASS: TestIsValidCachePath/log (0.00s)1852 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1853 --- PASS: TestIsValidCachePath/ls (0.00s)1854 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1855=== CONT TestCacheConfigHandler/no_signing_keys1856=== CONT TestCacheConfigHandler/no_cache_url_configured1857=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1858--- PASS: TestCacheConfigHandler (0.00s)1859 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1860 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1861 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1862 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1863=== CONT TestService_RequireScope_OIDC/builder_may_write1864=== CONT TestService_RequireScope_OIDC/reader_may_read1865=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1866=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18672026/10/06 21:13:28 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]1868=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1869=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1870=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1871=== CONT TestService_RequireScope_OIDC/writer_implies_read1872=== CONT TestService_RequireScope_OIDC/reader_may_not_write1873=== CONT TestService_RequireScope_OIDC/static_token_may_write1874=== CONT TestService_RequireScope_OIDC/static_token_may_admin1875=== CONT TestService_RequireScope_OIDC/ops_may_admin1876=== CONT TestService_RequireScope_OIDC/ops_may_not_write1877=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1878--- PASS: TestService_RequireScope_OIDC (0.35s)1879 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1880 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1881 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1882 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1883 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1884 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1885 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1886 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1887 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1888 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1889 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1890 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1891 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1892 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1893=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1894=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1895=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1896=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1897=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1898=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1899=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1900=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1901=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1902=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19032026/10/06 21:13:28 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]1904=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1905=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19062026/10/06 21:13:28 WARN Authentication failed token_preview=eyJhbGciOi...ONAgtjV1Uw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1907--- PASS: TestService_AuthMiddleware_OIDC (0.37s)1908 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1909 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1910 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1911 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1912=== NAME TestOrphanedObjectsGCStressTest1913 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1914--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.37s)19152026/10/06 21:13:28 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/present19162026/10/06 21:13:29 INFO Received uploads request method=POST path=/api/pending_closures19172026/10/06 21:13:29 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.231312ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19182026/10/06 21:13:29 INFO Aborted multipart uploads count=0 kept=019192026/10/06 21:13:29 WARN Force mode enabled - objects will be deleted immediately without grace period19202026/10/06 21:13:29 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:42601/bucket89/?delete=\": context canceled"19212026/10/06 21:13:29 INFO Aborted multipart uploads count=0 kept=019222026/10/06 21:13:29 WARN Force mode enabled - objects will be deleted immediately without grace period19232026/10/06 21:13:29 INFO Received uploads request method=POST path=/api/pending_closures1924--- PASS: TestGCEndsOnShutdown (0.00s)1925 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.41s)1926 --- PASS: TestGCEndsOnShutdown/before_the_run (0.43s)1927 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.48s)19282026/10/06 21:13:29 INFO Aborted multipart uploads count=0 kept=019292026/10/06 21:13:29 WARN Force mode enabled - objects will be deleted immediately without grace period19302026/10/06 21:13: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=019312026/10/06 21:13:29 INFO Vacuumed table table=pending_closures19322026/10/06 21:13:29 INFO Vacuumed table table=pending_objects19332026/10/06 21:13:29 INFO Vacuumed table table=multipart_uploads19342026/10/06 21:13:29 INFO Vacuumed table table=closures19352026/10/06 21:13:29 INFO Vacuumed table table=objects19362026/10/06 21:13:29 INFO Received uploads request method=POST path=/api/pending_closures19372026/10/06 21:13:29 INFO Aborted multipart uploads count=0 kept=019382026/10/06 21:13:29 WARN Force mode enabled - objects will be deleted immediately without grace period19392026/10/06 21:13: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=019402026/10/06 21:13:29 INFO Vacuumed table table=pending_closures19412026/10/06 21:13:29 INFO Vacuumed table table=pending_objects19422026/10/06 21:13:29 INFO Vacuumed table table=multipart_uploads19432026/10/06 21:13:29 INFO Vacuumed table table=closures19442026/10/06 21:13:29 INFO Vacuumed table table=objects1945--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1946 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.33s)1947 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.34s)19482026/10/06 21:13:29 INFO lead: released remote=192.0.2.1:12341949--- PASS: TestLeadEndsOnShutdown (1.50s)19502026/10/06 21:13:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=424.674078ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19512026/10/06 21:13:29 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1952=== NAME TestOrphanedObjectsGCStressTest1953 orphaned_objects_gc_test.go:509: Stress test completed successfully:1954 orphaned_objects_gc_test.go:510: - Active objects preserved: 201955 orphaned_objects_gc_test.go:511: - Objects deleted: 2101956 orphaned_objects_gc_test.go:512: - Total GC'd: 2101957--- PASS: TestOrphanedObjectsGCStressTest (3.07s)19582026/10/06 21:13:29 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19592026/10/06 21:13:29 INFO lead: released remote=192.0.2.1:12341960--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.08s)1961 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.89s)1962 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.90s)19632026/10/06 21:13:29 INFO lead: acquired remote=192.0.2.1:12341964--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1965 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1966 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)1967 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.75s)19682026/10/06 21:13:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=759.818888ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1969--- PASS: TestPendingClosureWriteTimeout (0.08s)1970 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1971 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1972 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1973 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.21s)19742026/10/06 21:13:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.626013787s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19752026/10/06 21:13:30 INFO lead: released remote=192.0.2.1:12341976--- PASS: TestLeadElectsOneAndHandsOver (2.72s)19772026/10/06 21:13:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019782026/10/06 21:13:30 INFO Received create pin request method=POST path=/api/pins/myapp19792026/10/06 21:13:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01980=== NAME TestClientIntegration1981 client_integration_test.go:323: Objects in database after GC:19822026/10/06 21:13:30 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3201827662/001/store/h07r0vdj47z9mm4j1fz52f6ic7hw0vy7-pinned-file.txt narinfo_key=h07r0vdj47z9mm4j1fz52f6ic7hw0vy7.narinfo1983 client_integration_test.go:323: Successfully deleted all objects with GC --force19842026/10/06 21:13:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures19852026/10/06 21:13:30 INFO Garbage collection started1986--- PASS: TestClientIntegration (2.57s)19872026/10/06 21:13:30 INFO Aborted multipart uploads count=0 kept=019882026/10/06 21:13:30 WARN Force mode enabled - objects will be deleted immediately without grace period19892026/10/06 21:13: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=019902026/10/06 21:13:30 INFO Vacuumed table table=pending_closures19912026/10/06 21:13:30 INFO Vacuumed table table=pending_objects19922026/10/06 21:13:30 INFO Vacuumed table table=multipart_uploads19932026/10/06 21:13:30 INFO Vacuumed table table=closures19942026/10/06 21:13:30 INFO Vacuumed table table=objects19952026/10/06 21:13:31 WARN Rate limiter enabled after throttle name=s3-test rate=519962026/10/06 21:13:31 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1997=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1998 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101999 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002000--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.44s)20012026/10/06 21:13: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-config20022026/10/06 21:13:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.868206ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20032026/10/06 21:13:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=405.576314ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2004=== NAME TestPinProtectsFromGC2005 client_integration_test.go:840: Pin successfully protected closure from garbage collection2006--- PASS: TestPinProtectsFromGC (4.72s)20072026/10/06 21:13:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=780.208811ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2008--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.42s)2009--- PASS: TestConnectWaitsForAPeerMigration (5.18s)20102026/10/06 21:13:33 INFO Aborted multipart uploads count=1 kept=020112026/10/06 21:13:33 INFO Received cleanup request method=DELETE path=/api/pending_closures20122026/10/06 21:13:33 INFO Aborted multipart uploads count=1 kept=02013--- PASS: TestPendingCleanupUsesOneCutoff (7.08s)20142026/10/06 21:13:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.505774821s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20152026/10/06 21:13: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"20162026/10/06 21:13: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-config20172026/10/06 21:13:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=211.4461ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20182026/10/06 21:13:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.064932ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20192026/10/06 21:13:35 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=852.099279ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20202026/10/06 21:13:36 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.482790011s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20212026/10/06 21:13:38 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_closures20222026/10/06 21:13:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.019148ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20232026/10/06 21:13:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=430.181437ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20242026/10/06 21:13:38 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=819.894127ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20252026/10/06 21:13:39 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.472574409s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2026--- PASS: TestClientErrorHandling (0.00s)2027 --- PASS: TestClientErrorHandling/InvalidStorePath (0.31s)2028 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.44s)2029 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.34s)2030PASS2031{"timestamp":"2026-10-06T21:13:41.224668324Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41074","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(397)"}2032{"timestamp":"2026-10-06T21:13:41.225196083Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41686","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)"}20332026-10-06 21:13:41.661 UTC [129] LOG: received smart shutdown request20342026-10-06 21:13:41.666 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120352026-10-06 21:13:41.676 UTC [134] LOG: shutting down20362026-10-06 21:13:41.676 UTC [134] LOG: checkpoint starting: shutdown immediate20372026-10-06 21:13:43.146 UTC [134] LOG: checkpoint complete: wrote 11073 buffers (67.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=0.462 s, sync=0.941 s, total=1.471 s; sync files=32344, longest=0.009 s, average=0.001 s; distance=446745 kB, estimate=446745 kB; lsn=0/1CBAC380, redo lsn=0/1CBAC38020382026-10-06 21:13:43.222 UTC [129] LOG: database system is shut down2039Running OIDC tests...2040=== RUN TestAudienceForIssuer2041=== PAUSE TestAudienceForIssuer2042=== RUN TestGlobMatch2043=== PAUSE TestGlobMatch2044=== RUN TestValidateToken_ValidToken2045=== PAUSE TestValidateToken_ValidToken2046=== RUN TestValidateToken_WrongAudience2047=== PAUSE TestValidateToken_WrongAudience2048=== RUN TestValidateToken_Expired2049=== PAUSE TestValidateToken_Expired2050=== RUN TestValidateToken_BoundClaimsMismatch2051=== PAUSE TestValidateToken_BoundClaimsMismatch2052=== RUN TestValidateToken_BoundSubjectMismatch2053=== PAUSE TestValidateToken_BoundSubjectMismatch2054=== RUN TestValidateToken_MultipleProviders2055=== PAUSE TestValidateToken_MultipleProviders2056=== RUN TestValidateToken_NoMatchingProvider2057=== PAUSE TestValidateToken_NoMatchingProvider2058=== RUN TestValidateToken_KubernetesServiceAccount2059=== PAUSE TestValidateToken_KubernetesServiceAccount2060=== RUN TestNewValidator_KubernetesRequiresCA2061=== PAUSE TestNewValidator_KubernetesRequiresCA2062=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2063=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2064=== RUN TestPins_ReservedForMatchingRule2065=== PAUSE TestPins_ReservedForMatchingRule2066=== RUN TestPins_TopLevelShorthand2067=== PAUSE TestPins_TopLevelShorthand2068=== RUN TestPins_ConfigValidation2069=== PAUSE TestPins_ConfigValidation2070=== RUN TestScopes_LegacyProviderDefaultsToWrite2071=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2072=== RUN TestScopes_Rules2073=== PAUSE TestScopes_Rules2074=== RUN TestScopes_ConfigValidation2075=== PAUSE TestScopes_ConfigValidation2076=== CONT TestAudienceForIssuer2077=== CONT TestValidateToken_BoundClaimsMismatch2078=== CONT TestPins_ConfigValidation2079=== CONT TestValidateToken_KubernetesServiceAccount2080--- PASS: TestAudienceForIssuer (0.00s)2081=== CONT TestPins_TopLevelShorthand2082=== CONT TestValidateToken_Expired2083=== CONT TestValidateToken_WrongAudience2084=== CONT TestValidateToken_ValidToken2085=== CONT TestPins_ReservedForMatchingRule2086=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2087=== CONT TestGlobMatch2088=== CONT TestScopes_Rules2089=== CONT TestNewValidator_KubernetesRequiresCA2090=== CONT TestValidateToken_MultipleProviders2091=== CONT TestScopes_ConfigValidation2092=== CONT TestValidateToken_NoMatchingProvider2093=== CONT TestValidateToken_BoundSubjectMismatch2094=== CONT TestScopes_LegacyProviderDefaultsToWrite2095--- PASS: TestPins_ConfigValidation (0.00s)2096--- PASS: TestScopes_ConfigValidation (0.00s)2097=== RUN TestGlobMatch/foo_foo2098=== PAUSE TestGlobMatch/foo_foo2099=== RUN TestGlobMatch/foo_bar2100=== PAUSE TestGlobMatch/foo_bar2101=== RUN TestGlobMatch/*_2102=== PAUSE TestGlobMatch/*_2103=== RUN TestGlobMatch/*_anything2104=== PAUSE TestGlobMatch/*_anything2105=== RUN TestGlobMatch/foo*_foo2106=== PAUSE TestGlobMatch/foo*_foo2107=== RUN TestGlobMatch/foo*_foobar2108=== PAUSE TestGlobMatch/foo*_foobar2109=== RUN TestGlobMatch/foo*_bar2110=== PAUSE TestGlobMatch/foo*_bar2111=== RUN TestGlobMatch/*bar_bar2112=== PAUSE TestGlobMatch/*bar_bar2113=== RUN TestGlobMatch/*bar_foobar2114=== PAUSE TestGlobMatch/*bar_foobar2115=== RUN TestGlobMatch/*bar_foo2116=== PAUSE TestGlobMatch/*bar_foo2117=== RUN TestGlobMatch/foo*bar_foobar2118=== PAUSE TestGlobMatch/foo*bar_foobar2119=== RUN TestGlobMatch/foo*bar_foo123bar2120=== PAUSE TestGlobMatch/foo*bar_foo123bar2121=== RUN TestGlobMatch/foo*bar_foobarbaz2122=== PAUSE TestGlobMatch/foo*bar_foobarbaz2123=== RUN TestGlobMatch/*/*_foo/bar2124=== PAUSE TestGlobMatch/*/*_foo/bar2125=== RUN TestGlobMatch/*/*_foo2126=== PAUSE TestGlobMatch/*/*_foo2127=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2128=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2129=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02130=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02131=== RUN TestGlobMatch/refs/*/main_refs/heads/main2132=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2133=== RUN TestGlobMatch/fo?_foo2134=== PAUSE TestGlobMatch/fo?_foo2135=== RUN TestGlobMatch/fo?_fo2136=== PAUSE TestGlobMatch/fo?_fo2137=== RUN TestGlobMatch/fo?_fooo2138=== PAUSE TestGlobMatch/fo?_fooo2139=== RUN TestGlobMatch/?oo_foo2140=== PAUSE TestGlobMatch/?oo_foo2141=== RUN TestGlobMatch/?oo_boo2142=== PAUSE TestGlobMatch/?oo_boo2143=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2144=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2145=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2146=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2147=== CONT TestGlobMatch/foo_foo2148=== CONT TestGlobMatch/foo*_bar2149=== CONT TestGlobMatch/foo*_foobar2150=== CONT TestGlobMatch/*/*_foo2151=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2152=== CONT TestGlobMatch/*_anything2153=== CONT TestGlobMatch/foo*_foo2154=== CONT TestGlobMatch/foo*bar_foo123bar2155=== CONT TestGlobMatch/*/*_foo/bar2156=== CONT TestGlobMatch/foo*bar_foobarbaz2157=== CONT TestGlobMatch/*bar_foo2158=== CONT TestGlobMatch/foo*bar_foobar2159=== CONT TestGlobMatch/*bar_foobar2160=== CONT TestGlobMatch/foo_bar2161=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2162=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2163=== CONT TestGlobMatch/?oo_boo2164=== CONT TestGlobMatch/?oo_foo2165=== CONT TestGlobMatch/fo?_fooo2166=== CONT TestGlobMatch/fo?_fo2167=== CONT TestGlobMatch/fo?_foo2168=== CONT TestGlobMatch/refs/*/main_refs/heads/main2169=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02170=== CONT TestGlobMatch/*_2171=== CONT TestGlobMatch/*bar_bar2172--- PASS: TestGlobMatch (0.01s)2173 --- PASS: TestGlobMatch/foo_foo (0.00s)2174 --- PASS: TestGlobMatch/foo*_bar (0.00s)2175 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2176 --- PASS: TestGlobMatch/*/*_foo (0.00s)2177 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2178 --- PASS: TestGlobMatch/*_anything (0.00s)2179 --- PASS: TestGlobMatch/foo*_foo (0.00s)2180 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2181 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2182 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2183 --- PASS: TestGlobMatch/*bar_foo (0.00s)2184 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2185 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2186 --- PASS: TestGlobMatch/foo_bar (0.00s)2187 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2188 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2189 --- PASS: TestGlobMatch/?oo_boo (0.00s)2190 --- PASS: TestGlobMatch/?oo_foo (0.00s)2191 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2192 --- PASS: TestGlobMatch/fo?_fo (0.00s)2193 --- PASS: TestGlobMatch/fo?_foo (0.00s)2194 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2195 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2196 --- PASS: TestGlobMatch/*_ (0.00s)2197 --- PASS: TestGlobMatch/*bar_bar (0.00s)21982026/10/06 21:13:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46425/oidc21992026/10/06 21:13:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35973/oidc2200--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)2201--- PASS: TestScopes_Rules (0.03s)22022026/10/06 21:13:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44043/oidc2203--- PASS: TestValidateToken_WrongAudience (0.04s)22042026/10/06 21:13:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43169/oidc2205--- PASS: TestValidateToken_ValidToken (0.05s)22062026/10/06 21:13:46 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3657922072026/10/06 21:13:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41723/oidc2208--- PASS: TestValidateToken_KubernetesServiceAccount (0.06s)2209--- PASS: TestPins_ReservedForMatchingRule (0.06s)22102026/10/06 21:13:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39213/oidc22112026/10/06 21:13:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43685/oidc2212--- PASS: TestValidateToken_Expired (0.07s)2213--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)22142026/10/06 21:13:46 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232215--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)22162026/10/06 21:13:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43465/oidc2217--- PASS: TestPins_TopLevelShorthand (0.10s)22182026/10/06 21:13:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37231/oidc2219--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)22202026/10/06 21:13:46 http: TLS handshake error from 127.0.0.1:56722: remote error: tls: bad certificate2221--- PASS: TestNewValidator_KubernetesRequiresCA (0.11s)22222026/10/06 21:13:46 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35847/oidc22232026/10/06 21:13:46 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34277/oidc2224--- PASS: TestValidateToken_MultipleProviders (0.12s)22252026/10/06 21:13:46 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37087/oidc2226--- PASS: TestValidateToken_NoMatchingProvider (0.13s)2227PASS2228Running hook tests...2229=== RUN TestSendPathsEmpty2230=== PAUSE TestSendPathsEmpty2231=== RUN TestQueueEnqueueAndFetch2232=== PAUSE TestQueueEnqueueAndFetch2233=== RUN TestQueueDeduplication2234=== PAUSE TestQueueDeduplication2235=== RUN TestQueueRemove2236=== PAUSE TestQueueRemove2237=== RUN TestQueueFetchBatchLimit2238=== PAUSE TestQueueFetchBatchLimit2239=== RUN TestQueueRetryMovesToBack2240=== PAUSE TestQueueRetryMovesToBack2241=== RUN TestQueueFetchRemoveLifecycle2242=== PAUSE TestQueueFetchRemoveLifecycle2243=== RUN TestQueueConcurrentWriters2244=== PAUSE TestQueueConcurrentWriters2245=== RUN TestQueueRemoveLargeClosure2246=== PAUSE TestQueueRemoveLargeClosure2247=== RUN TestServerClientIntegration2248=== PAUSE TestServerClientIntegration2249=== RUN TestServerQueueError2250=== PAUSE TestServerQueueError2251=== RUN TestGetListenerSocketActivation2252 server_test.go:210: === RUN TestGetListenerSocketActivation2253 --- PASS: TestGetListenerSocketActivation (0.00s)2254 PASS2255 2256--- PASS: TestGetListenerSocketActivation (0.01s)2257=== RUN TestDrainIsolatesPoisonPath2258=== PAUSE TestDrainIsolatesPoisonPath2259=== RUN TestRunNotBlockedByPoisonHead2260=== PAUSE TestRunNotBlockedByPoisonHead2261=== RUN TestDrainGivesUpWhenServerDown2262=== PAUSE TestDrainGivesUpWhenServerDown2263=== RUN TestFailedPathPrunedByLaterClosure2264=== PAUSE TestFailedPathPrunedByLaterClosure2265=== RUN TestWorkerUploadsAndRemoves2266=== PAUSE TestWorkerUploadsAndRemoves2267=== RUN TestWorkerSkipsGCdPaths2268=== PAUSE TestWorkerSkipsGCdPaths2269=== RUN TestWorkerPrunesClosureDeps2270=== PAUSE TestWorkerPrunesClosureDeps2271=== RUN TestDrainTimeout2272=== PAUSE TestDrainTimeout2273=== CONT TestSendPathsEmpty2274=== CONT TestFailedPathPrunedByLaterClosure2275=== CONT TestQueueRetryMovesToBack2276=== CONT TestServerQueueError2277=== CONT TestDrainTimeout2278=== CONT TestWorkerPrunesClosureDeps2279=== CONT TestWorkerSkipsGCdPaths2280=== CONT TestWorkerUploadsAndRemoves2281=== CONT TestServerClientIntegration2282=== CONT TestQueueRemoveLargeClosure22832026/10/06 21:13:46 ERROR Failed to queue paths error="permission denied" count=12284=== CONT TestQueueConcurrentWriters2285=== CONT TestQueueFetchRemoveLifecycle2286=== CONT TestRunNotBlockedByPoisonHead2287=== CONT TestDrainGivesUpWhenServerDown2288=== CONT TestQueueRemove2289=== CONT TestQueueFetchBatchLimit2290=== CONT TestQueueDeduplication2291=== CONT TestQueueEnqueueAndFetch2292=== CONT TestDrainIsolatesPoisonPath2293--- PASS: TestSendPathsEmpty (0.00s)2294--- PASS: TestServerQueueError (0.00s)2295--- PASS: TestServerClientIntegration (0.00s)22962026/10/06 21:13:46 INFO Upload queue status pending=222972026/10/06 21:13:46 INFO Upload queue status pending=222982026/10/06 21:13:46 INFO Uploading batch count=122992026/10/06 21:13:46 INFO Uploading batch count=223002026/10/06 21:13:46 ERROR Upload failed error="upload failed" count=123012026/10/06 21:13:46 INFO Upload queue status pending=223022026/10/06 21:13:46 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2982905993/002/nonexistent23032026/10/06 21:13:46 INFO Upload queue status pending=323042026/10/06 21:13:46 INFO Uploading batch count=423052026/10/06 21:13:46 ERROR Upload failed error="upload failed" count=423062026/10/06 21:13:46 INFO Uploading batch count=223072026/10/06 21:13:46 INFO Uploading batch count=12308--- PASS: TestQueueEnqueueAndFetch (0.02s)23092026/10/06 21:13:46 INFO Uploading batch count=22310--- PASS: TestQueueDeduplication (0.02s)23112026/10/06 21:13:46 INFO Uploading batch count=123122026/10/06 21:13:46 INFO Uploading batch count=12313--- PASS: TestQueueFetchBatchLimit (0.02s)23142026/10/06 21:13:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath750093843/002/bbb23152026/10/06 21:13:46 ERROR Upload failed error="upload failed" count=223162026/10/06 21:13:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3643632097/002/a23172026/10/06 21:13:46 ERROR Upload failed error="upload failed" count=12318--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23192026/10/06 21:13:46 INFO Uploading batch count=12320--- PASS: TestQueueRetryMovesToBack (0.02s)2321--- PASS: TestQueueRemove (0.02s)23222026/10/06 21:13:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3643632097/002/b23232026/10/06 21:13:46 INFO Uploading batch count=123242026/10/06 21:13:46 INFO Uploading batch count=123252026/10/06 21:13:46 ERROR Upload failed error="upload failed" count=123262026/10/06 21:13:46 INFO Uploading batch count=223272026/10/06 21:13:46 ERROR Upload failed error="upload failed" count=223282026/10/06 21:13:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3643632097/002/c23292026/10/06 21:13:46 INFO Uploading batch count=123302026/10/06 21:13:46 ERROR Upload failed error="upload failed" count=123312026/10/06 21:13:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3643632097/002/d23322026/10/06 21:13:46 INFO Uploading batch count=223332026/10/06 21:13:46 ERROR Upload failed error="upload failed" count=223342026/10/06 21:13:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3643632097/002/e23352026/10/06 21:13:46 INFO Uploading batch count=123362026/10/06 21:13:46 ERROR Upload failed error="upload failed" count=123372026/10/06 21:13:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3643632097/002/f2338--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)23392026/10/06 21:13:46 ERROR Drain finished with paths left in queue remaining=1023402026/10/06 21:13:46 ERROR Drain finished with paths left in queue remaining=12341--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2342--- PASS: TestDrainIsolatesPoisonPath (0.02s)2343--- PASS: TestWorkerSkipsGCdPaths (0.04s)2344--- PASS: TestWorkerUploadsAndRemoves (0.04s)2345--- PASS: TestWorkerPrunesClosureDeps (0.04s)2346--- PASS: TestQueueRemoveLargeClosure (0.05s)23472026/10/06 21:13:46 ERROR Upload failed error="context deadline exceeded" count=223482026/10/06 21:13:46 ERROR Drain finished with paths left in queue remaining=42349--- PASS: TestDrainTimeout (0.22s)2350--- PASS: TestQueueConcurrentWriters (0.27s)23512026/10/06 21:13:47 INFO Uploading batch count=123522026/10/06 21:13:47 INFO Uploading batch count=123532026/10/06 21:13:47 INFO Uploading batch count=123542026/10/06 21:13:47 ERROR Upload failed error="upload failed" count=123552026/10/06 21:13:47 INFO Uploading batch count=123562026/10/06 21:13:47 ERROR Upload failed error="upload failed" count=123572026/10/06 21:13:47 INFO Uploading batch count=123582026/10/06 21:13:47 ERROR Upload failed error="upload failed" count=123592026/10/06 21:13:47 INFO Uploading batch count=123602026/10/06 21:13:47 ERROR Upload failed error="upload failed" count=123612026/10/06 21:13:47 ERROR Drain finished with paths left in queue remaining=12362--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2363PASS2364Running signing tests...2365=== RUN TestExternalSigner2366=== PAUSE TestExternalSigner2367=== RUN TestExternalSignerWrongPublicKey2368=== PAUSE TestExternalSignerWrongPublicKey2369=== RUN TestExternalSignerErrors2370=== PAUSE TestExternalSignerErrors2371=== RUN TestExternalSignerRestartsAfterCrash2372=== PAUSE TestExternalSignerRestartsAfterCrash2373=== RUN TestExternalSignerProgramErrorKeepsProcess2374=== PAUSE TestExternalSignerProgramErrorKeepsProcess2375=== RUN TestExternalSignerClose2376=== PAUSE TestExternalSignerClose2377=== RUN TestExternalSignerRejectsInvalidPublicKey2378=== PAUSE TestExternalSignerRejectsInvalidPublicKey2379=== RUN TestExternalSignerCancellation2380=== PAUSE TestExternalSignerCancellation2381=== RUN TestGenerateFingerprint2382=== PAUSE TestGenerateFingerprint2383=== RUN TestParseSigningKey2384=== PAUSE TestParseSigningKey2385=== RUN TestSign2386=== PAUSE TestSign2387=== RUN TestSignBatch2388=== PAUSE TestSignBatch2389=== RUN TestNilKeyPublicKey2390=== PAUSE TestNilKeyPublicKey2391=== RUN TestSignErrors2392=== PAUSE TestSignErrors2393=== CONT TestExternalSigner2394=== CONT TestSignErrors2395=== CONT TestSignBatch2396=== CONT TestNilKeyPublicKey2397=== CONT TestSign2398=== CONT TestParseSigningKey2399=== CONT TestExternalSignerProgramErrorKeepsProcess2400=== CONT TestExternalSignerRejectsInvalidPublicKey2401=== RUN TestParseSigningKey/valid_32-byte_key2402=== PAUSE TestParseSigningKey/valid_32-byte_key2403=== RUN TestExternalSignerRejectsInvalidPublicKey/#002404=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002405=== CONT TestExternalSignerErrors2406=== CONT TestExternalSignerRestartsAfterCrash2407=== CONT TestGenerateFingerprint2408=== CONT TestExternalSignerWrongPublicKey2409=== CONT TestExternalSignerCancellation2410--- PASS: TestNilKeyPublicKey (0.00s)2411=== CONT TestExternalSignerClose2412=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2413=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2414--- PASS: TestSign (0.00s)2415--- PASS: TestSignBatch (0.00s)2416=== RUN TestGenerateFingerprint/basic_with_references2417=== PAUSE TestGenerateFingerprint/basic_with_references2418=== RUN TestGenerateFingerprint/no_references2419=== PAUSE TestGenerateFingerprint/no_references2420=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2421=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2422=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2423=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2424=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2425=== RUN TestSignErrors/nil_key2426=== PAUSE TestSignErrors/nil_key2427=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2428=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2429=== RUN TestGenerateFingerprint/invalid_nar_hash_length2430=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2431=== RUN TestParseSigningKey/no_colon2432=== PAUSE TestParseSigningKey/no_colon2433=== RUN TestParseSigningKey/empty_name2434=== PAUSE TestParseSigningKey/empty_name2435=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2436=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2437=== RUN TestExternalSignerErrors/null2438=== PAUSE TestExternalSignerErrors/null2439=== RUN TestSignErrors/nil_narinfo2440=== PAUSE TestSignErrors/nil_narinfo2441=== RUN TestSignErrors/invalid_narinfo2442=== PAUSE TestSignErrors/invalid_narinfo2443=== RUN TestSignErrors/canceled2444=== RUN TestExternalSignerErrors/wrong_signature_name2445=== PAUSE TestExternalSignerErrors/wrong_signature_name2446=== RUN TestExternalSignerErrors/invalid_signature_base642447=== PAUSE TestExternalSignerErrors/invalid_signature_base642448=== RUN TestExternalSignerErrors/wrong_shape2449=== PAUSE TestExternalSignerErrors/wrong_shape2450=== RUN TestExternalSignerErrors/wrong_id2451=== PAUSE TestExternalSignerErrors/wrong_id2452=== RUN TestExternalSignerErrors/wrong_signatures_shape2453=== RUN TestParseSigningKey/invalid_base642454=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2455=== RUN TestGenerateFingerprint/invalid_store_path_prefix2456=== PAUSE TestSignErrors/canceled2457=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2458=== RUN TestGenerateFingerprint/invalid_reference_prefix2459=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2460=== CONT TestGenerateFingerprint/basic_with_references2461=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2462=== CONT TestSignErrors/nil_key2463--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2464=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2465=== CONT TestSignErrors/canceled2466=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2467=== CONT TestSignErrors/invalid_narinfo2468=== PAUSE TestParseSigningKey/invalid_base642469=== CONT TestSignErrors/nil_narinfo2470=== CONT TestGenerateFingerprint/invalid_nar_hash_length2471=== CONT TestGenerateFingerprint/invalid_reference_prefix2472=== CONT TestGenerateFingerprint/invalid_store_path_prefix2473=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2474=== CONT TestGenerateFingerprint/no_references2475--- PASS: TestExternalSignerClose (0.00s)2476--- PASS: TestExternalSignerWrongPublicKey (0.00s)2477--- PASS: TestSignErrors (0.00s)2478 --- PASS: TestSignErrors/nil_key (0.00s)2479 --- PASS: TestSignErrors/canceled (0.00s)2480 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2481 --- PASS: TestSignErrors/nil_narinfo (0.00s)2482=== RUN TestExternalSignerErrors/too_few_signatures2483=== PAUSE TestExternalSignerErrors/too_few_signatures2484=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2485=== RUN TestParseSigningKey/wrong_length2486=== PAUSE TestParseSigningKey/wrong_length2487=== CONT TestParseSigningKey/valid_32-byte_key2488--- PASS: TestGenerateFingerprint (0.00s)2489 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2490 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2491 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2492 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2493 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2494 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2495 --- PASS: TestGenerateFingerprint/no_references (0.00s)2496=== RUN TestExternalSignerErrors/missing_signature_name2497=== PAUSE TestExternalSignerErrors/missing_signature_name2498=== RUN TestExternalSignerErrors/exit_at_startup2499=== PAUSE TestExternalSignerErrors/exit_at_startup2500=== RUN TestExternalSignerErrors/exit_on_request2501=== PAUSE TestExternalSignerErrors/exit_on_request2502=== RUN TestExternalSignerErrors/missing_signatures2503=== PAUSE TestExternalSignerErrors/missing_signatures2504=== CONT TestExternalSignerRejectsInvalidPublicKey/#002505=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2506=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2507=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2508=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2509--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)2510 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2511 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2512 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2513 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2514 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2515=== CONT TestParseSigningKey/empty_name2516=== CONT TestParseSigningKey/wrong_length2517=== CONT TestParseSigningKey/invalid_base642518=== CONT TestParseSigningKey/no_colon2519=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2520--- PASS: TestParseSigningKey (0.01s)2521 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2522 --- PASS: TestParseSigningKey/empty_name (0.00s)2523 --- PASS: TestParseSigningKey/wrong_length (0.00s)2524 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2525 --- PASS: TestParseSigningKey/no_colon (0.00s)2526 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2527=== RUN TestExternalSignerErrors/null_signatures2528=== PAUSE TestExternalSignerErrors/null_signatures2529--- PASS: TestExternalSigner (0.01s)2530=== RUN TestExternalSignerErrors/wrong_signature_length2531=== PAUSE TestExternalSignerErrors/wrong_signature_length2532=== RUN TestExternalSignerErrors/program_error2533=== PAUSE TestExternalSignerErrors/program_error2534=== RUN TestExternalSignerErrors/unrequested_key2535=== PAUSE TestExternalSignerErrors/unrequested_key2536=== RUN TestExternalSignerErrors/invalid_JSON2537=== PAUSE TestExternalSignerErrors/invalid_JSON2538=== CONT TestExternalSignerErrors/null2539=== CONT TestExternalSignerErrors/exit_on_request2540=== CONT TestExternalSignerErrors/exit_at_startup2541=== CONT TestExternalSignerErrors/invalid_JSON2542=== CONT TestExternalSignerErrors/unrequested_key2543=== CONT TestExternalSignerErrors/program_error2544=== CONT TestExternalSignerErrors/wrong_signature_length2545=== CONT TestExternalSignerErrors/null_signatures2546=== CONT TestExternalSignerErrors/missing_signatures2547=== CONT TestExternalSignerErrors/invalid_signature_base642548=== CONT TestExternalSignerErrors/wrong_shape2549=== CONT TestExternalSignerErrors/wrong_id2550=== CONT TestExternalSignerErrors/missing_signature_name2551=== CONT TestExternalSignerErrors/too_few_signatures2552=== CONT TestExternalSignerErrors/wrong_signature_name2553=== CONT TestExternalSignerErrors/wrong_signatures_shape2554--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2555--- PASS: TestExternalSignerCancellation (0.02s)2556--- PASS: TestExternalSignerErrors (0.01s)2557 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2558 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2559 --- PASS: TestExternalSignerErrors/null (0.02s)2560 --- PASS: TestExternalSignerErrors/program_error (0.02s)2561 --- PASS: TestExternalSignerErrors/exit_at_startup (0.02s)2562 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.02s)2563 --- PASS: TestExternalSignerErrors/unrequested_key (0.02s)2564 --- PASS: TestExternalSignerErrors/wrong_shape (0.02s)2565 --- PASS: TestExternalSignerErrors/missing_signature_name (0.02s)2566 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.02s)2567 --- PASS: TestExternalSignerErrors/wrong_id (0.02s)2568 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.02s)2569 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.02s)2570 --- PASS: TestExternalSignerErrors/null_signatures (0.02s)2571 --- PASS: TestExternalSignerErrors/missing_signatures (0.02s)2572 --- PASS: TestExternalSignerErrors/too_few_signatures (0.02s)2573PASS2574Running OpenBao signer tests...2575=== RUN TestSign2576=== PAUSE TestSign2577=== RUN TestSignErrors2578=== PAUSE TestSignErrors2579=== RUN TestServe2580=== PAUSE TestServe2581=== RUN TestServeRejectsGarbage2582=== PAUSE TestServeRejectsGarbage2583=== CONT TestSign2584=== CONT TestServe2585=== CONT TestServeRejectsGarbage2586=== CONT TestSignErrors2587=== RUN TestSignErrors/invalid_json2588=== PAUSE TestSignErrors/invalid_json2589=== RUN TestSignErrors/no_prefix2590=== PAUSE TestSignErrors/no_prefix2591=== RUN TestSignErrors/invalid_base642592=== PAUSE TestSignErrors/invalid_base642593=== RUN TestSignErrors/http_error2594=== PAUSE TestSignErrors/http_error2595--- PASS: TestServeRejectsGarbage (0.00s)2596=== CONT TestSignErrors/invalid_json2597=== CONT TestSignErrors/invalid_base642598--- PASS: TestServe (0.01s)2599=== CONT TestSignErrors/no_prefix2600=== CONT TestSignErrors/http_error2601--- PASS: TestSign (0.01s)2602--- PASS: TestSignErrors (0.00s)2603 --- PASS: TestSignErrors/http_error (0.00s)2604 --- PASS: TestSignErrors/no_prefix (0.00s)2605 --- PASS: TestSignErrors/invalid_base64 (0.00s)2606 --- PASS: TestSignErrors/invalid_json (0.00s)2607PASS