niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #460
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestUploadMultipart_ReturnsAfterDroppedBody22=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody23=== RUN TestPartSizeForNAR24=== PAUSE TestPartSizeForNAR25=== RUN TestUploadMultipart_SupersededByPeer26=== PAUSE TestUploadMultipart_SupersededByPeer27=== RUN TestDumpPathCaseHackMatchesNix28--- PASS: TestDumpPathCaseHackMatchesNix (0.14s)29=== RUN TestDumpPathCaseHackCollision30--- PASS: TestDumpPathCaseHackCollision (0.00s)31=== RUN TestSupersededNARStillUploadsListing32=== PAUSE TestSupersededNARStillUploadsListing33=== RUN TestDumpPathMatchesNix34=== PAUSE TestDumpPathMatchesNix35=== RUN TestDumpPathSingleFile36=== PAUSE TestDumpPathSingleFile37=== RUN TestDumpPathWriterError38=== PAUSE TestDumpPathWriterError39=== RUN TestEncodeNixBase3240=== PAUSE TestEncodeNixBase3241=== RUN TestEncodeNixBase32WithRealHash42=== PAUSE TestEncodeNixBase32WithRealHash43=== RUN TestConvertHashToNix3244=== PAUSE TestConvertHashToNix3245=== RUN TestGetStorePathHash46=== PAUSE TestGetStorePathHash47=== RUN TestPathInfoHashCompatibility48=== PAUSE TestPathInfoHashCompatibility49=== RUN TestParsePathInfoJSON50=== PAUSE TestParsePathInfoJSON51=== RUN TestParsePathInfoJSONMultiplePaths52=== PAUSE TestParsePathInfoJSONMultiplePaths53=== RUN TestPathInfoCACompatibility54=== PAUSE TestPathInfoCACompatibility55=== RUN TestRateLimiterFeedback56=== PAUSE TestRateLimiterFeedback57=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess58=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess59=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer60=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer61=== RUN TestResolveStorePath62=== PAUSE TestResolveStorePath63=== RUN TestDoWithRetry_BodyReplayedViaGetBody64=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody65=== RUN TestRetryTimeoutOutlastsMaxRetries66=== PAUSE TestRetryTimeoutOutlastsMaxRetries67=== RUN TestDoWithRetry_FinalResponseBodyReadable68=== PAUSE TestDoWithRetry_FinalResponseBodyReadable69=== RUN TestShellSplit70=== PAUSE TestShellSplit71=== RUN TestShellSplitErrors72=== PAUSE TestShellSplitErrors73=== RUN TestStreamPushReportsEveryPath74=== PAUSE TestStreamPushReportsEveryPath75=== RUN TestStreamPushBatchesUnderLoad76=== PAUSE TestStreamPushBatchesUnderLoad77=== RUN TestStreamPushIsolatesFailures78=== PAUSE TestStreamPushIsolatesFailures79=== RUN TestStreamPushGivesUpOnDeadServer80=== PAUSE TestStreamPushGivesUpOnDeadServer81=== RUN TestStreamPushRequestLine82=== PAUSE TestStreamPushRequestLine83=== RUN TestStreamPushReportsSignatures84=== PAUSE TestStreamPushReportsSignatures85=== RUN TestStreamPushReportsSkippedPaths86=== PAUSE TestStreamPushReportsSkippedPaths87=== RUN TestClientSignaturesByStorePath88=== PAUSE TestClientSignaturesByStorePath89=== RUN TestStreamPushStopsWhenCanceled90=== PAUSE TestStreamPushStopsWhenCanceled91=== RUN TestSetClientTLS92=== PAUSE TestSetClientTLS93=== RUN TestSetClientTLSDoesNotMutateDefaultTransport94=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport95=== RUN TestSetClientTLSErrors96=== PAUSE TestSetClientTLSErrors97=== RUN TestStaticToken98=== PAUSE TestStaticToken99=== RUN TestFileTokenReadsAndCaches100=== PAUSE TestFileTokenReadsAndCaches101=== RUN TestFileTokenMissing102=== PAUSE TestFileTokenMissing103=== RUN TestFileTokenEmpty104=== PAUSE TestFileTokenEmpty105=== RUN TestScriptTokenNoExpiryRerunsEveryCall106=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall107=== RUN TestScriptTokenCachesUntilRefresh108=== PAUSE TestScriptTokenCachesUntilRefresh109=== RUN TestScriptTokenEmptyToken110=== PAUSE TestScriptTokenEmptyToken111=== RUN TestScriptTokenBadJSON112=== PAUSE TestScriptTokenBadJSON113=== RUN TestScriptTokenScriptFails114=== PAUSE TestScriptTokenScriptFails115=== RUN TestScriptTokenEmptyCommand116=== PAUSE TestScriptTokenEmptyCommand117=== CONT TestDoServerRequestAttachesToken118=== CONT TestDoWithRetry_BodyReplayedViaGetBody119=== CONT TestDumpPathSingleFile120=== CONT TestDumpPathMatchesNix121=== CONT TestSupersededNARStillUploadsListing122=== RUN TestSupersededNARStillUploadsListing/small_NAR123=== PAUSE TestSupersededNARStillUploadsListing/small_NAR124=== RUN TestSupersededNARStillUploadsListing/dump_cut_short125=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short126=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails127=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails128=== CONT TestUploadMultipart_SupersededByPeer129=== RUN TestUploadMultipart_SupersededByPeer/exists130=== PAUSE TestUploadMultipart_SupersededByPeer/exists131=== RUN TestUploadMultipart_SupersededByPeer/missing132=== PAUSE TestUploadMultipart_SupersededByPeer/missing133=== CONT TestScriptTokenEmptyCommand134--- PASS: TestScriptTokenEmptyCommand (0.00s)135=== CONT TestScriptTokenBadJSON136=== CONT TestPartSizeForNAR137=== RUN TestPartSizeForNAR/zero_stays_at_minimum138=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum139=== RUN TestPartSizeForNAR/small_stays_at_minimum140=== PAUSE TestPartSizeForNAR/small_stays_at_minimum141=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum142=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum143=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts144=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts145=== RUN TestPartSizeForNAR/1_TiB146=== PAUSE TestPartSizeForNAR/1_TiB147=== CONT TestScriptTokenScriptFails148=== RUN TestPartSizeForNAR/5_TiB_S3_max_object149=== CONT TestUploadMultipart_ReturnsAfterDroppedBody150=== CONT TestUploadMultipart_FailedPartBufferNotReused151=== CONT TestUploadMultipart_PartsInParallel152=== CONT TestFilterOversizedClosures153=== CONT TestCaseHackSuffix154=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun155=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica156=== CONT TestRegisterUploadedObjectReusesConnections157=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry158=== CONT TestParsePathInfoJSON159=== CONT TestResolveStorePath160=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer161=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess162=== CONT TestRateLimiterFeedback163=== CONT TestPathInfoCACompatibility164=== CONT TestParsePathInfoJSONMultiplePaths165=== CONT TestSetClientTLS166--- PASS: TestDumpPathSingleFile (0.10s)167=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object168=== RUN TestPartSizeForNAR/capped_at_5_GiB169=== PAUSE TestPartSizeForNAR/capped_at_5_GiB170=== CONT TestScriptTokenCachesUntilRefresh171=== RUN TestPathInfoCACompatibility/null_ca_field172=== PAUSE TestPathInfoCACompatibility/null_ca_field173=== RUN TestPathInfoCACompatibility/old_string_format_-_text174=== RUN TestParsePathInfoJSON/Nix_format175=== RUN TestFilterOversizedClosures/no_limit_keeps_everything176=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1772026/11/04 20:13:38 WARN Rate limiter enabled after throttle name=server-test rate=5178=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything179--- PASS: TestScriptTokenScriptFails (0.01s)180=== CONT TestScriptTokenNoExpiryRerunsEveryCall181=== CONT TestScriptTokenEmptyToken182=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive183=== PAUSE TestParsePathInfoJSON/Nix_format184=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped185=== RUN TestParsePathInfoJSON/Lix_format186--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)187=== PAUSE TestParsePathInfoJSON/Lix_format188=== RUN TestParsePathInfoJSON/empty_input189=== RUN TestRateLimiterFeedback/429_enables_limiter190=== PAUSE TestRateLimiterFeedback/429_enables_limiter191=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths192=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths193=== RUN TestRateLimiterFeedback/503_enables_limiter194=== PAUSE TestRateLimiterFeedback/503_enables_limiter195=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter196=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths197=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths198=== CONT TestFileTokenMissing199=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped200=== RUN TestFilterOversizedClosures/all_closures_skipped201=== PAUSE TestFilterOversizedClosures/all_closures_skipped202=== CONT TestFileTokenReadsAndCaches203=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive204=== RUN TestPathInfoCACompatibility/new_structured_format_-_text2052026/11/04 20:13:38 WARN Rate limiter enabled after throttle name=server-test rate=52062026/11/04 20:13:38 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46557207=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text208=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method2092026/11/04 20:13:38 WARN Rate limiter backed off name=server-test rate=52102026/11/04 20:13:38 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:46557211--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.24s)212=== CONT TestStaticToken2132026/11/04 20:13:38 INFO Garbage collection started2142026/11/04 20:13:38 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=0215=== RUN TestSetClientTLS/rejects_connection_without_client_cert216=== CONT TestFileTokenEmpty217--- PASS: TestDoServerRequestAttachesToken (0.27s)218=== CONT TestSetClientTLSErrors2192026/11/04 20:13:38 WARN Garbage collection finished on another replica. Its statistics are not available here220--- PASS: TestResolveStorePath (0.18s)2212026/11/04 20:13:38 INFO Garbage collection started222=== CONT TestSetClientTLSDoesNotMutateDefaultTransport223=== CONT TestPathInfoHashCompatibility224=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)225=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)226=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon227=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon228=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI229=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI230=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512231=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512232=== CONT TestGetStorePathHash233=== RUN TestGetStorePathHash/valid_store_path234=== PAUSE TestGetStorePathHash/valid_store_path235=== RUN TestGetStorePathHash/basename_without_hyphen_should_error236=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error237=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error238=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error239=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error240=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error241=== CONT TestStreamPushIsolatesFailures242=== CONT TestStreamPushStopsWhenCanceled243=== CONT TestClientSignaturesByStorePath244=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method245=== CONT TestStreamPushReportsSkippedPaths2462026/11/04 20:13:38 ERROR Upload failed error="bad path" count=3247=== CONT TestStreamPushRequestLine248=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter249=== CONT TestStreamPushGivesUpOnDeadServer250=== CONT TestEncodeNixBase32251=== RUN TestEncodeNixBase32/test_string_hash252=== PAUSE TestEncodeNixBase32/test_string_hash253=== RUN TestEncodeNixBase32/empty_input2542026/11/04 20:13:38 ERROR Upload failed error="connection refused" count=20255=== PAUSE TestEncodeNixBase32/empty_input2562026/11/04 20:13:38 ERROR Server seems unavailable, giving up on batch untried=172572026/11/04 20:13:38 ERROR Upload failed error=boom count=1258=== CONT TestDumpPathWriterError259=== CONT TestShellSplitErrors260=== CONT TestStreamPushBatchesUnderLoad261=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false262=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false263=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true264=== CONT TestStreamPushReportsEveryPath265=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true266=== CONT TestShellSplit267=== CONT TestRetryTimeoutOutlastsMaxRetries268=== CONT TestDoWithRetry_FinalResponseBodyReadable269=== CONT TestConvertHashToNix32270=== RUN TestConvertHashToNix32/SRI_format_to_Nix32271=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32272=== RUN TestConvertHashToNix32/already_Nix32_format273=== PAUSE TestConvertHashToNix32/already_Nix32_format2742026/11/04 20:13:38 WARN Rate limiter enabled after throttle name=s3-test rate=5275=== RUN TestConvertHashToNix32/invalid_format2762026/11/04 20:13:38 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35717277=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter278=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter279=== CONT TestEncodeNixBase32WithRealHash280=== CONT TestUploadMultipart_SupersededByPeer/exists281=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails282=== CONT TestSupersededNARStillUploadsListing/dump_cut_short283=== PAUSE TestConvertHashToNix32/invalid_format284=== PAUSE TestParsePathInfoJSON/empty_input285=== CONT TestPartSizeForNAR/zero_stays_at_minimum286=== CONT TestPartSizeForNAR/1_TiB287=== CONT TestPartSizeForNAR/capped_at_5_GiB288=== CONT TestPartSizeForNAR/5_TiB_S3_max_object289=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum290=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts2912026/11/04 20:13:38 INFO Uploading abc-hello (1.0GB)292=== CONT TestPartSizeForNAR/small_stays_at_minimum293=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2942026/11/04 20:13:38 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:41689295=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths296=== CONT TestFilterOversizedClosures/no_limit_keeps_everything297=== CONT TestFilterOversizedClosures/all_closures_skipped298=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped299=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3002026/11/04 20:13:38 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=50301=== RUN TestParsePathInfoJSON/whitespace_only302=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512303=== PAUSE TestParsePathInfoJSON/whitespace_only304=== RUN TestParsePathInfoJSON/invalid_JSON3052026/11/04 20:13:38 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=2000306=== PAUSE TestParsePathInfoJSON/invalid_JSON307=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI308=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error309=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error310=== CONT TestPathInfoCACompatibility/null_ca_field311=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3122026/11/04 20:13:38 WARN Rate limiter enabled after throttle name=server-test rate=53132026/11/04 20:13:38 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:33227314=== CONT TestPathInfoCACompatibility/new_structured_format_-_text315=== CONT TestGetStorePathHash/valid_store_path316=== CONT TestPathInfoCACompatibility/old_string_format_-_text317=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false318=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive319=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true320=== CONT TestGetStorePathHash/basename_without_hyphen_should_error321=== CONT TestRateLimiterFeedback/429_enables_limiter322=== CONT TestUploadMultipart_SupersededByPeer/missing323=== CONT TestConvertHashToNix32/SRI_format_to_Nix32324=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter325--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.17s)3262026/11/04 20:13:39 WARN Rate limiter backed off name=server-test rate=5327--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.16s)328=== CONT TestEncodeNixBase32/test_string_hash329=== CONT TestSupersededNARStillUploadsListing/small_NAR330=== CONT TestStreamPushReportsSignatures331=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert332=== RUN TestSetClientTLSErrors/missing_cert_file333=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon334--- PASS: TestFileTokenReadsAndCaches (0.00s)335--- PASS: TestFileTokenEmpty (0.00s)336--- PASS: TestClientSignaturesByStorePath (0.00s)337--- PASS: TestStaticToken (0.00s)338--- PASS: TestStreamPushStopsWhenCanceled (0.00s)339--- PASS: TestStreamPushIsolatesFailures (0.00s)340--- PASS: TestStreamPushReportsSkippedPaths (0.00s)341--- PASS: TestFileTokenMissing (0.00s)342--- PASS: TestShellSplitErrors (0.00s)343--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)344--- PASS: TestStreamPushReportsEveryPath (0.00s)345--- PASS: TestShellSplit (0.00s)346--- PASS: TestEncodeNixBase32WithRealHash (0.00s)347--- PASS: TestScriptTokenBadJSON (0.28s)348--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)349--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.18s)350--- PASS: TestScriptTokenEmptyToken (0.03s)351--- PASS: TestCaseHackSuffix (0.46s)352--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.18s)353--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.45s)354--- PASS: TestPathInfoCACompatibility (0.25s)355 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)356 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)357 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)358 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)359 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)360=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA361=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA362=== RUN TestSetClientTLS/preserves_debug_logging_transport363=== PAUSE TestSetClientTLS/preserves_debug_logging_transport364=== CONT TestConvertHashToNix32/invalid_format365=== CONT TestConvertHashToNix32/already_Nix32_format366--- PASS: TestConvertHashToNix32 (0.00s)367 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)368 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)369 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)370=== CONT TestParsePathInfoJSON/Nix_format371=== CONT TestEncodeNixBase32/empty_input372=== CONT TestParsePathInfoJSON/invalid_JSON373=== CONT TestParsePathInfoJSON/whitespace_only374=== CONT TestParsePathInfoJSON/empty_input375=== CONT TestParsePathInfoJSON/Lix_format376--- PASS: TestParsePathInfoJSON (0.18s)377 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)378 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)379 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)380 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)381 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)382=== CONT TestSetClientTLS/rejects_connection_without_client_cert3832026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:416893842026/11/04 20:13:39 INFO Uploading abc-hello (1.0GB)385--- PASS: TestStreamPushBatchesUnderLoad (0.00s)386 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)387 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.35s)388=== CONT TestSetClientTLS/preserves_debug_logging_transport3892026/11/04 20:13:39 ERROR Upload failed error=boom count=1390--- PASS: TestStreamPushReportsSignatures (0.00s)391=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA392=== PAUSE TestSetClientTLSErrors/missing_cert_file3932026/11/04 20:13:39 WARN Rate limiter enabled after throttle name=server-test rate=5394=== RUN TestSetClientTLSErrors/missing_key_file3952026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:38213396=== PAUSE TestSetClientTLSErrors/missing_key_file397=== RUN TestSetClientTLSErrors/missing_ca_file398=== PAUSE TestSetClientTLSErrors/missing_ca_file399--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)400 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)401 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.35s)402--- PASS: TestEncodeNixBase32 (0.00s)403 --- PASS: TestEncodeNixBase32/empty_input (0.00s)404 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)405--- PASS: TestPathInfoHashCompatibility (0.00s)406 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)407 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)408 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)409 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)4102026/11/04 20:13:39 WARN Rate limiter backed off name=server-test rate=5411=== RUN TestSetClientTLSErrors/invalid_ca_file412=== PAUSE TestSetClientTLSErrors/invalid_ca_file413=== CONT TestSetClientTLSErrors/missing_cert_file414=== CONT TestSetClientTLSErrors/invalid_ca_file415=== CONT TestSetClientTLSErrors/missing_key_file416=== CONT TestSetClientTLSErrors/missing_ca_file417--- PASS: TestPartSizeForNAR (0.08s)418 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)419 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)420 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)421 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)422 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)423 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)424 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)425=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter426--- PASS: TestParsePathInfoJSONMultiplePaths (0.20s)427 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)428 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)429--- PASS: TestFilterOversizedClosures (0.22s)430 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)431 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)432 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)433--- PASS: TestGetStorePathHash (0.08s)434 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)435 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)436 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)437 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)438=== CONT TestRateLimiterFeedback/503_enables_limiter439--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.36s)440--- PASS: TestSetClientTLSErrors (0.36s)441 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)442 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)443 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)444 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)4452026/11/04 20:13:39 WARN Rate limiter enabled after throttle name=server-test rate=54462026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:413574472026/11/04 20:13:39 WARN Rate limiter backed off name=server-test rate=5448--- PASS: TestRateLimiterFeedback (0.17s)449 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.35s)450 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.35s)451 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)452 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)4532026/11/04 20:13:39 INFO Uploading abc-hello (1.0GB)4542026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:416894552026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:416894562026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:416894572026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:416894582026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:416894592026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:416894602026/11/04 20:13:39 http: TLS handshake error from 127.0.0.1:47020: remote error: tls: bad certificate461--- PASS: TestSetClientTLS (0.53s)462 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)463 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)464 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)465--- PASS: TestRegisterUploadedObjectReusesConnections (0.40s)4662026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:416894672026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:416894682026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:416894692026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:41689470--- PASS: TestStreamPushRequestLine (0.37s)4712026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:416894722026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:416894732026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:416894742026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:416894752026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:416894762026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:416894772026/11/04 20:13:39 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:41689478--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.38s)479--- PASS: TestDumpPathWriterError (0.38s)4802026/11/04 20:13:39 WARN Rate limiter enabled after throttle name=s3-test rate=54812026/11/04 20:13:39 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:36421/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:36421/part/24822026/11/04 20:13:39 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"483--- PASS: TestDumpPathMatchesNix (0.70s)484--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4852026/11/04 20:13:39 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:43971/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:43971/api/uploads/complete4862026/11/04 20:13:39 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4872026/11/04 20:13:39 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:43971/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:43971/api/uploads/complete4882026/11/04 20:13:39 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4892026/11/04 20:13:39 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:43971/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:43971/api/uploads/complete4902026/11/04 20:13:39 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"491--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.02s)492--- PASS: TestSupersededNARStillUploadsListing (0.00s)493 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.35s)494 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.00s)495 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.89s)496--- PASS: TestUploadMultipart_PartsInParallel (1.11s)497--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.97s)498PASS499Running server tests...500The files belonging to this database system will be owned by user "nixbld".501This user must also own the server process.502503The database cluster will be initialized with locale "C".504The default database encoding has accordingly been set to "SQL_ASCII".505The default text search configuration will be set to "english".506507Data page checksums are enabled.508509creating directory /build/postgres2361431489/data ... ok510creating subdirectories ... ok511selecting dynamic shared memory implementation ... posix512selecting default "max_connections" ... 100513selecting default "shared_buffers" ... 128MB514selecting default time zone ... UTC515creating configuration files ... ok516running bootstrap script ... ok517performing post-bootstrap initialization ... ok518syncing data to disk ... ok519520initdb: warning: enabling "trust" authentication for local connections521initdb: 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.522523Success. You can now start the database server using:524525 pg_ctl -D /build/postgres2361431489/data -l logfile start526527/build/postgres2361431489:5432 - no response5282026-11-04 20:13:41.414 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5292026-11-04 20:13:41.414 UTC [128] LOG: listening on Unix socket "/build/postgres2361431489/.s.PGSQL.5432"5302026-11-04 20:13:41.420 UTC [135] LOG: database system was shut down at 2026-11-04 20:13:41 UTC5312026-11-04 20:13:41.424 UTC [128] LOG: database system is ready to accept connections532/build/postgres2361431489:5432 - accepting connections533{"timestamp":"2026-11-04T20:13:42.379159548Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7ee08cd3-4be5-42f7-95c1-fa4db2ff3a3f","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":7,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(196)"}534=== RUN TestService_AuthMiddleware535=== PAUSE TestService_AuthMiddleware536=== RUN TestService_AuthMiddleware_MTLSProxyHeader537=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader538=== RUN TestService_AuthMiddleware_MTLSBoundSubjects539=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects540=== RUN TestService_ReadAuthMiddleware541=== PAUSE TestService_ReadAuthMiddleware542=== RUN TestService_AuthMiddleware_OIDC543=== PAUSE TestService_AuthMiddleware_OIDC544=== RUN TestService_RequireScope_OIDC545=== PAUSE TestService_RequireScope_OIDC546=== RUN TestService_ReadScope_PublicByDefault547=== PAUSE TestService_ReadScope_PublicByDefault548=== RUN TestCacheConfigHandler549=== PAUSE TestCacheConfigHandler550=== RUN TestCacheStatsHandler551=== PAUSE TestCacheStatsHandler552=== RUN TestClientCADerivations553=== PAUSE TestClientCADerivations554=== RUN TestClientErrorHandling555=== PAUSE TestClientErrorHandling556=== RUN TestClientIntegration557=== PAUSE TestClientIntegration558=== RUN TestClientMultipleUploads559=== PAUSE TestClientMultipleUploads560=== RUN TestClientWithDependencies561=== PAUSE TestClientWithDependencies562=== RUN TestClientSharedPathCommittedMidPush563=== PAUSE TestClientSharedPathCommittedMidPush564=== RUN TestPinProtectsFromGC565=== PAUSE TestPinProtectsFromGC566=== RUN TestClientPushesUseOnePush567=== PAUSE TestClientPushesUseOnePush568=== RUN TestClientFallsBackToClosures569=== PAUSE TestClientFallsBackToClosures570=== RUN TestDeleteClosuresRacingPins571=== PAUSE TestDeleteClosuresRacingPins572=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock573=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock574=== RUN TestResolveDBConnectionString575=== PAUSE TestResolveDBConnectionString576=== RUN TestConnectWaitsForAPeerMigration577=== PAUSE TestConnectWaitsForAPeerMigration578=== RUN TestLeadElectsOneAndHandsOver579=== PAUSE TestLeadElectsOneAndHandsOver580=== RUN TestLeadIncumbentWinsAfterRestart5812026/11/04 20:13:42 INFO lead: acquired remote=192.0.2.1:12345822026/11/04 20:13:43 INFO lead: released remote=192.0.2.1:12345832026/11/04 20:13:43 INFO lead: acquired remote=192.0.2.1:12345842026/11/04 20:13:44 INFO lead: released remote=192.0.2.1:1234585--- PASS: TestLeadIncumbentWinsAfterRestart (2.21s)586=== RUN TestLeadIncumbentAnnouncesAtOnce587=== PAUSE TestLeadIncumbentAnnouncesAtOnce588=== RUN TestLeadEndsOnShutdown589=== PAUSE TestLeadEndsOnShutdown590=== RUN TestLeadEndsWhenItsConnectionHangs5912026/11/04 20:13:45 INFO lead: acquired remote=192.0.2.1:12345922026-11-04 20:13:46.473 UTC [381] FATAL: terminating connection due to administrator command5932026/11/04 20:13:46 INFO lead: acquired remote=192.0.2.1:12345942026/11/04 20:13:47 WARN lead: lock connection lost error="timeout: context deadline exceeded"5952026/11/04 20:13:47 INFO lead: released remote=192.0.2.1:12345962026/11/04 20:13:48 INFO lead: released remote=192.0.2.1:1234597--- PASS: TestLeadEndsWhenItsConnectionHangs (3.35s)598=== RUN TestGCAdvisoryLockBlocksConcurrentRun599=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun600=== RUN TestGCBugBareHashReferences601=== PAUSE TestGCBugBareHashReferences602=== RUN TestGCMetrics603=== PAUSE TestGCMetrics604=== RUN TestPushDedupSurvivesConcurrentGC605=== PAUSE TestPushDedupSurvivesConcurrentGC606=== RUN TestDeduplicatedObjectsRecordedAsPending607=== PAUSE TestDeduplicatedObjectsRecordedAsPending608=== RUN TestGCSweepSkipsPendingObjects609=== PAUSE TestGCSweepSkipsPendingObjects610=== RUN TestTombstonedObjectOfferedWithoutWaiting611=== PAUSE TestTombstonedObjectOfferedWithoutWaiting612=== RUN TestGCSweepDeliversEachKeyOnce613=== PAUSE TestGCSweepDeliversEachKeyOnce614=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection615=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection616=== RUN TestForceGCDuringPushOffersSweptObject617=== PAUSE TestForceGCDuringPushOffersSweptObject618=== RUN TestFailedS3DeleteKeepsTombstone619=== PAUSE TestFailedS3DeleteKeepsTombstone620=== RUN TestSweepSkipsRowsLockedByPush621=== PAUSE TestSweepSkipsRowsLockedByPush622=== RUN TestRegisterCompletedObjectNeedsPendingRow623=== PAUSE TestRegisterCompletedObjectNeedsPendingRow624=== RUN TestGetExistingObjectsLocksRows625=== PAUSE TestGetExistingObjectsLocksRows626=== RUN TestSweepRechecksPendingAfterLocking627=== PAUSE TestSweepRechecksPendingAfterLocking628=== RUN TestPushWaitsForSweepHoldingRow629=== PAUSE TestPushWaitsForSweepHoldingRow630=== RUN TestCommitRacingPendingCleanupKeepsObjects631=== PAUSE TestCommitRacingPendingCleanupKeepsObjects632=== RUN TestGCEndsOnShutdown633=== PAUSE TestGCEndsOnShutdown634=== RUN TestGCTaskStore_StartNew635=== PAUSE TestGCTaskStore_StartNew636=== RUN TestGCTaskStore_DeduplicateSameParams637=== PAUSE TestGCTaskStore_DeduplicateSameParams638=== RUN TestGCTaskStore_ConflictDifferentParams639=== PAUSE TestGCTaskStore_ConflictDifferentParams640=== RUN TestGCTaskStore_GetEmpty641=== PAUSE TestGCTaskStore_GetEmpty642=== RUN TestGCTaskStore_GetReturnsLatest643=== PAUSE TestGCTaskStore_GetReturnsLatest644=== RUN TestGCTaskStore_CompletedAllowsNewTask645=== PAUSE TestGCTaskStore_CompletedAllowsNewTask646=== RUN TestGCTaskStore_PhaseUpdates647=== PAUSE TestGCTaskStore_PhaseUpdates648=== RUN TestGCTaskStore_Fail649=== PAUSE TestGCTaskStore_Fail650=== RUN TestGracefulShutdownDrainsInflight651=== PAUSE TestGracefulShutdownDrainsInflight652=== RUN TestService_healthCheckHandler653=== PAUSE TestService_healthCheckHandler654=== RUN TestService_readinessHandler655=== PAUSE TestService_readinessHandler656=== RUN TestGenerateLandingPage657=== PAUSE TestGenerateLandingPage658=== RUN TestCacheConfigHandlerMaxNarSize659=== PAUSE TestCacheConfigHandlerMaxNarSize660=== RUN TestCreatePendingClosureRejectsOversizedNAR661=== PAUSE TestCreatePendingClosureRejectsOversizedNAR662=== RUN TestNARDeduplicationMetadataUploadBug663=== PAUSE TestNARDeduplicationMetadataUploadBug664=== RUN TestMetricsInventory665=== PAUSE TestMetricsInventory666=== RUN TestMetricsCommit667=== PAUSE TestMetricsCommit668=== RUN TestService_NativeMTLS669=== PAUSE TestService_NativeMTLS670=== RUN TestServerTLSConfig671=== PAUSE TestServerTLSConfig672=== RUN TestMultipartCleanup673=== PAUSE TestMultipartCleanup674=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded675=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded676=== RUN TestPendingCleanupUsesOneCutoff677=== PAUSE TestPendingCleanupUsesOneCutoff678=== RUN TestObjectStatsTrigger679=== PAUSE TestObjectStatsTrigger680=== RUN TestObjectStatsUpdatedOncePerCommit681=== PAUSE TestObjectStatsUpdatedOncePerCommit682=== RUN TestOrphanedObjectsGC683=== PAUSE TestOrphanedObjectsGC684=== RUN TestOrphanedObjectsGCStressTest685=== PAUSE TestOrphanedObjectsGCStressTest686=== RUN TestCreatePin_ReservedPins687=== PAUSE TestCreatePin_ReservedPins688=== RUN TestPresentReportsOnlyClosureRoots689=== PAUSE TestPresentReportsOnlyClosureRoots690=== RUN TestPresentRefreshesOnlyStaleClosures691=== PAUSE TestPresentRefreshesOnlyStaleClosures692=== RUN TestPresentNotReportedWhileGCDeletesClosure693=== PAUSE TestPresentNotReportedWhileGCDeletesClosure694=== RUN TestParseSingleRange695=== PAUSE TestParseSingleRange696=== RUN TestProxyHeadersOnlyTrustedOnSocket6972026/11/04 20:13:48 INFO Starting HTTP server address=127.0.0.1:363296982026/11/04 20:13:48 INFO Starting HTTP server address=proxy.sock6992026/11/04 20:13:48 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7002026/11/04 20:13:48 INFO Shutdown signal received, draining in-flight requests timeout=10s701--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.45s)702=== RUN TestIsValidCachePath703=== PAUSE TestIsValidCachePath704=== RUN TestReadProxyNarinfo705=== PAUSE TestReadProxyNarinfo706=== RUN TestReadProxyNarinfoAlreadyDecompressed707=== PAUSE TestReadProxyNarinfoAlreadyDecompressed708=== RUN TestReadProxyContentNegotiation709=== PAUSE TestReadProxyContentNegotiation710=== RUN TestReadProxyNarStreaming711=== PAUSE TestReadProxyNarStreaming712=== RUN TestReadProxy404713=== PAUSE TestReadProxy404714=== RUN TestReadProxyInvalidPath715=== PAUSE TestReadProxyInvalidPath716=== RUN TestReadProxyHead717=== PAUSE TestReadProxyHead718=== RUN TestReadProxyOutlastsServerWriteTimeout719=== PAUSE TestReadProxyOutlastsServerWriteTimeout720=== RUN TestReadProxyConditionalGet721=== PAUSE TestReadProxyConditionalGet722=== RUN TestReadProxyRootRedirectsToIndexHTML723=== PAUSE TestReadProxyRootRedirectsToIndexHTML724=== RUN TestReadProxyDisabled725=== PAUSE TestReadProxyDisabled726=== RUN TestReadRedirectNar727=== PAUSE TestReadRedirectNar728=== RUN TestReadRedirectKeepsNarinfoProxied729=== PAUSE TestReadRedirectKeepsNarinfoProxied730=== RUN TestReadProxyRangeRequest731=== PAUSE TestReadProxyRangeRequest732=== RUN TestReadRedirectUsesPublicS3URL733=== PAUSE TestReadRedirectUsesPublicS3URL734=== RUN TestPush_OverlappingRootsStoreOneRowPerKey735=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey736=== RUN TestPush_CompleteCommitsEveryRoot737=== PAUSE TestPush_CompleteCommitsEveryRoot738=== RUN TestPush_RepeatedRootCommitsOnce739=== PAUSE TestPush_RepeatedRootCommitsOnce740=== RUN TestPush_CompleteWaitsForCleanupOfThePush741=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush742=== RUN TestPush_RootsAreLockedInByteOrder743=== PAUSE TestPush_RootsAreLockedInByteOrder744=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit745=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit746=== RUN TestPush_RejectsBadRequests747=== PAUSE TestPush_RejectsBadRequests748=== RUN TestPush_SignsNarinfosOfItsPendingObjects749=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects750=== RUN TestRedundantMultipartUpload751=== PAUSE TestRedundantMultipartUpload752=== RUN TestCompleteMultipartUpload_ErrorButObjectExists753=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists754=== RUN TestCompletedNarNotReofferedAcrossClosures755=== PAUSE TestCompletedNarNotReofferedAcrossClosures756=== RUN TestPresignedUploadRegisteredBeforeCommit757=== PAUSE TestPresignedUploadRegisteredBeforeCommit758=== RUN TestService_Rustfstest759=== PAUSE TestService_Rustfstest760=== RUN TestParseSize761=== PAUSE TestParseSize762=== RUN TestSkippedUploadsHandler763=== PAUSE TestSkippedUploadsHandler764=== RUN TestSystemdListenerNotActivated765--- PASS: TestSystemdListenerNotActivated (0.00s)766=== RUN TestWatchdogBeatsWhenHealthy767--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)768=== RUN TestWatchdogSkipsWhenUnhealthy7692026/11/04 20:13:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/11/04 20:13:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/11/04 20:13:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/11/04 20:13:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/11/04 20:13:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/11/04 20:13:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/11/04 20:13:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/11/04 20:13:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/11/04 20:13:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7782026/11/04 20:13:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"779--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)780=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle781=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle782=== RUN TestProxyWriteTimeout783=== PAUSE TestProxyWriteTimeout784=== RUN TestPendingClosureWriteTimeout785=== PAUSE TestPendingClosureWriteTimeout786=== RUN TestIsValidUploadKey787=== PAUSE TestIsValidUploadKey788=== RUN TestUploadHandlersRejectInvalidKeys789=== PAUSE TestUploadHandlersRejectInvalidKeys790=== RUN TestUploadHandlersRejectOversizedBody791=== PAUSE TestUploadHandlersRejectOversizedBody792=== RUN TestService_cleanupPendingClosuresHandler793=== PAUSE TestService_cleanupPendingClosuresHandler794=== RUN TestService_createPendingClosureHandler795=== PAUSE TestService_createPendingClosureHandler796=== RUN TestService_verifyS3Integrity797=== PAUSE TestService_verifyS3Integrity798=== RUN TestService_verifyS3ReuploadsStaleNarinfo799=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo800=== RUN TestCompleteMultipartUnregistered801=== PAUSE TestCompleteMultipartUnregistered802=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT803=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT804=== CONT TestIsValidUploadKey805=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle806=== CONT TestService_verifyS3Integrity807=== CONT TestRedundantMultipartUpload808=== CONT TestCompleteMultipartUnregistered809=== CONT TestService_readinessHandler810=== CONT TestProxyWriteTimeout811=== RUN TestProxyWriteTimeout/narinfo812=== CONT TestSkippedUploadsHandler813=== CONT TestParseSize814--- PASS: TestParseSize (0.00s)815=== CONT TestPush_OverlappingRootsStoreOneRowPerKey816=== CONT TestService_Rustfstest817=== CONT TestPresignedUploadRegisteredBeforeCommit818=== CONT TestCompletedNarNotReofferedAcrossClosures8192026/11/04 20:13:48 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000820=== CONT TestCompleteMultipartUpload_ErrorButObjectExists821--- PASS: TestSkippedUploadsHandler (0.01s)822=== CONT TestReadRedirectUsesPublicS3URL823=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT824=== CONT TestReadProxyNarinfoAlreadyDecompressed825=== CONT TestPush_SignsNarinfosOfItsPendingObjects826=== CONT TestPush_RejectsBadRequests827=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit828=== CONT TestPush_RootsAreLockedInByteOrder829=== CONT TestPush_CompleteWaitsForCleanupOfThePush830=== CONT TestPush_RepeatedRootCommitsOnce831=== CONT TestPush_CompleteCommitsEveryRoot832=== CONT TestService_AuthMiddleware833=== CONT TestPendingClosureWriteTimeout834=== RUN TestPendingClosureWriteTimeout/empty835=== PAUSE TestPendingClosureWriteTimeout/empty836=== RUN TestPendingClosureWriteTimeout/400_objects837=== PAUSE TestPendingClosureWriteTimeout/400_objects838=== RUN TestPendingClosureWriteTimeout/670k_objects839=== PAUSE TestPendingClosureWriteTimeout/670k_objects840=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline841=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline842=== RUN TestIsValidUploadKey/narinfo843=== CONT TestReadProxyRangeRequest844=== PAUSE TestIsValidUploadKey/narinfo845=== RUN TestIsValidUploadKey/nar_zst846=== PAUSE TestIsValidUploadKey/nar_zst847=== RUN TestIsValidUploadKey/nar_xz848=== PAUSE TestIsValidUploadKey/nar_xz849=== RUN TestIsValidUploadKey/nar_plain850=== PAUSE TestIsValidUploadKey/nar_plain851=== RUN TestIsValidUploadKey/listing852=== PAUSE TestIsValidUploadKey/listing853=== RUN TestIsValidUploadKey/build_log854=== PAUSE TestIsValidUploadKey/build_log855=== RUN TestIsValidUploadKey/build_log_home-manager_file856=== PAUSE TestIsValidUploadKey/build_log_home-manager_file857=== RUN TestIsValidUploadKey/build_log_plus_in_name858=== PAUSE TestIsValidUploadKey/build_log_plus_in_name859=== RUN TestIsValidUploadKey/build_log_question_mark860=== PAUSE TestIsValidUploadKey/build_log_question_mark861=== RUN TestIsValidUploadKey/build_log_equals862=== PAUSE TestIsValidUploadKey/build_log_equals863=== RUN TestIsValidUploadKey/realisation864=== PAUSE TestIsValidUploadKey/realisation865=== RUN TestIsValidUploadKey/realisation_plus_in_output866=== PAUSE TestIsValidUploadKey/realisation_plus_in_output867=== RUN TestIsValidUploadKey/nix-cache-info868=== PAUSE TestIsValidUploadKey/nix-cache-info869=== RUN TestIsValidUploadKey/index.html870=== PAUSE TestIsValidUploadKey/index.html871=== RUN TestIsValidUploadKey/narinfo_key,_nar_type872=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type873=== RUN TestIsValidUploadKey/nar_key,_narinfo_type874=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type875=== RUN TestIsValidUploadKey/listing_key,_narinfo_type876=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type877=== RUN TestIsValidUploadKey/traversal878=== PAUSE TestIsValidUploadKey/traversal879=== RUN TestIsValidUploadKey/traversal_nar880=== PAUSE TestIsValidUploadKey/traversal_nar881=== RUN TestIsValidUploadKey/absolute882=== PAUSE TestIsValidUploadKey/absolute883=== RUN TestIsValidUploadKey/empty_key884=== PAUSE TestIsValidUploadKey/empty_key885=== RUN TestIsValidUploadKey/unknown_type886=== PAUSE TestIsValidUploadKey/unknown_type887=== PAUSE TestProxyWriteTimeout/narinfo888=== RUN TestProxyWriteTimeout/1_GiB_nar889=== PAUSE TestProxyWriteTimeout/1_GiB_nar890=== CONT TestReadRedirectKeepsNarinfoProxied891=== RUN TestProxyWriteTimeout/10_GiB_nar892=== PAUSE TestProxyWriteTimeout/10_GiB_nar893=== RUN TestProxyWriteTimeout/unknown_size894=== PAUSE TestProxyWriteTimeout/unknown_size895=== CONT TestReadRedirectNar896=== RUN TestPush_RejectsBadRequests/no_roots897=== PAUSE TestPush_RejectsBadRequests/no_roots898=== RUN TestPush_RejectsBadRequests/no_objects899=== PAUSE TestPush_RejectsBadRequests/no_objects900=== RUN TestPush_RejectsBadRequests/bad_root901=== PAUSE TestPush_RejectsBadRequests/bad_root902=== RUN TestPush_RejectsBadRequests/root_not_in_objects903=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects904=== CONT TestReadProxyDisabled9052026/11/04 20:13:49 INFO Received uploads request method=POST path=/api/pending_closures9062026/11/04 20:13:49 INFO Received push request method=POST path=/api/pushes9072026/11/04 20:13:49 INFO Received push request method=POST path=/api/pushes908--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.17s)909=== CONT TestReadProxyRootRedirectsToIndexHTML9102026/11/04 20:13:49 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"911--- PASS: TestService_AuthMiddleware (1.13s)912=== CONT TestReadProxyConditionalGet913--- PASS: TestReadRedirectNar (1.06s)914=== CONT TestReadProxyOutlastsServerWriteTimeout9152026/11/04 20:13:49 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9162026/11/04 20:13:49 INFO Received uploads request method=POST path=/api/pending_closures917--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.20s)918=== CONT TestReadProxyHead9192026/11/04 20:13:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9202026/11/04 20:13:49 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst921--- PASS: TestCompleteMultipartUnregistered (1.22s)922=== CONT TestService_cleanupPendingClosuresHandler9232026-11-04 20:13:49.959 UTC [507] ERROR: could not obtain lock on row in relation "closures"9242026-11-04 20:13:49.959 UTC [507] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9252026-11-04 20:13:49.960 UTC [507] ERROR: could not obtain lock on row in relation "closures"9262026-11-04 20:13:49.960 UTC [507] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9272026-11-04 20:13:49.960 UTC [507] ERROR: could not obtain lock on row in relation "closures"9282026-11-04 20:13:49.960 UTC [507] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9292026-11-04 20:13:49.960 UTC [507] ERROR: could not obtain lock on row in relation "closures"9302026-11-04 20:13:49.960 UTC [507] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9312026-11-04 20:13:49.960 UTC [507] ERROR: could not obtain lock on row in relation "closures"9322026-11-04 20:13:49.960 UTC [507] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT933--- PASS: TestPush_RootsAreLockedInByteOrder (1.20s)934=== CONT TestService_createPendingClosureHandler935--- PASS: TestReadRedirectKeepsNarinfoProxied (1.15s)936=== CONT TestReadProxyInvalidPath9372026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures938--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.30s)939=== CONT TestUploadHandlersRejectOversizedBody9402026/11/04 20:13:50 INFO Received push request method=POST path=/api/pushes941=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure942=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure943=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart944=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart945=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts946=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts947=== CONT TestReadProxy4049482026/11/04 20:13:50 INFO Received push request method=POST path=/api/pushes9492026/11/04 20:13:50 INFO Received complete push request method=POST path=/api/pushes/1/complete9502026/11/04 20:13:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9512026/11/04 20:13:50 INFO Signed narinfos id=1 count=19522026/11/04 20:13:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9532026/11/04 20:13:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9542026/11/04 20:13:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9552026/11/04 20:13:50 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9562026/11/04 20:13:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9572026/11/04 20:13:50 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9582026/11/04 20:13:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9592026/11/04 20:13:50 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19602026/11/04 20:13:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9612026/11/04 20:13:50 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo962--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.50s)963=== CONT TestObjectStatsTrigger9642026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures965--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.55s)966=== CONT TestReadProxyNarStreaming9672026/11/04 20:13:50 WARN readiness check failed error="closed pool"968--- PASS: TestService_readinessHandler (1.58s)969=== CONT TestReadProxyNarinfo9702026/11/04 20:13:50 INFO Completed push id=1 objects=6 duration=65.295124ms971--- PASS: TestPush_CompleteCommitsEveryRoot (1.54s)972=== CONT TestReadProxyContentNegotiation973--- PASS: TestReadRedirectUsesPublicS3URL (1.61s)974=== CONT TestIsValidCachePath975=== RUN TestIsValidCachePath/narinfo976=== PAUSE TestIsValidCachePath/narinfo977=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars978=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars979=== RUN TestIsValidCachePath/nar_zst980=== PAUSE TestIsValidCachePath/nar_zst981=== RUN TestIsValidCachePath/nar_xz982=== PAUSE TestIsValidCachePath/nar_xz983=== RUN TestIsValidCachePath/nar_bz2984=== PAUSE TestIsValidCachePath/nar_bz2985=== RUN TestIsValidCachePath/nar_uncompressed986=== PAUSE TestIsValidCachePath/nar_uncompressed987=== RUN TestIsValidCachePath/ls988=== PAUSE TestIsValidCachePath/ls989=== RUN TestIsValidCachePath/log990=== PAUSE TestIsValidCachePath/log991=== RUN TestIsValidCachePath/realisation992=== PAUSE TestIsValidCachePath/realisation993=== RUN TestIsValidCachePath/nix-cache-info994=== PAUSE TestIsValidCachePath/nix-cache-info995=== RUN TestIsValidCachePath/index.html996=== PAUSE TestIsValidCachePath/index.html997=== RUN TestIsValidCachePath/traversal_parent998=== PAUSE TestIsValidCachePath/traversal_parent999=== RUN TestIsValidCachePath/traversal_in_middle1000=== PAUSE TestIsValidCachePath/traversal_in_middle1001=== RUN TestIsValidCachePath/invalid_char_e1002=== PAUSE TestIsValidCachePath/invalid_char_e1003=== RUN TestIsValidCachePath/invalid_char_u1004=== PAUSE TestIsValidCachePath/invalid_char_u1005=== RUN TestIsValidCachePath/random_path1006=== PAUSE TestIsValidCachePath/random_path1007=== RUN TestIsValidCachePath/empty1008=== PAUSE TestIsValidCachePath/empty1009=== RUN TestIsValidCachePath/leading_slash1010=== PAUSE TestIsValidCachePath/leading_slash1011=== RUN TestIsValidCachePath/wrong_extension1012=== PAUSE TestIsValidCachePath/wrong_extension1013=== RUN TestIsValidCachePath/short_hash1014=== PAUSE TestIsValidCachePath/short_hash1015=== CONT TestParseSingleRange1016=== RUN TestParseSingleRange/none1017=== PAUSE TestParseSingleRange/none1018=== RUN TestParseSingleRange/unknown_unit1019=== PAUSE TestParseSingleRange/unknown_unit1020=== RUN TestParseSingleRange/multi-range_ignored1021=== PAUSE TestParseSingleRange/multi-range_ignored1022=== RUN TestParseSingleRange/malformed_no_dash1023=== PAUSE TestParseSingleRange/malformed_no_dash1024=== RUN TestParseSingleRange/malformed_both_empty1025=== PAUSE TestParseSingleRange/malformed_both_empty1026=== RUN TestParseSingleRange/malformed_end_before_start1027=== PAUSE TestParseSingleRange/malformed_end_before_start1028=== RUN TestParseSingleRange/closed1029=== PAUSE TestParseSingleRange/closed1030=== RUN TestParseSingleRange/open-ended1031=== PAUSE TestParseSingleRange/open-ended1032=== RUN TestParseSingleRange/end_clamped_to_size1033=== PAUSE TestParseSingleRange/end_clamped_to_size1034=== RUN TestParseSingleRange/suffix1035=== PAUSE TestParseSingleRange/suffix1036=== RUN TestParseSingleRange/suffix_exceeds_size1037=== PAUSE TestParseSingleRange/suffix_exceeds_size1038=== RUN TestParseSingleRange/single_byte1039=== PAUSE TestParseSingleRange/single_byte1040=== RUN TestParseSingleRange/start_past_EOF1041=== PAUSE TestParseSingleRange/start_past_EOF1042=== RUN TestParseSingleRange/start_far_past_EOF1043=== PAUSE TestParseSingleRange/start_far_past_EOF1044=== CONT TestCreatePin_ReservedPins10452026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures1046--- PASS: TestReadProxyRangeRequest (1.57s)1047=== CONT TestOrphanedObjectsGCStressTest10482026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures10492026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures10502026/11/04 20:13:50 INFO Received push request method=POST path=/api/pushes10512026/11/04 20:13:50 INFO Received complete push request method=POST path=/api/pushes/1/complete10522026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures10532026/11/04 20:13:50 INFO Received push request method=POST path=/api/pushes10542026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures10552026/11/04 20:13:50 INFO Completed push id=1 objects=4 duration=86.233378ms1056--- PASS: TestPush_RepeatedRootCommitsOnce (1.78s)1057=== CONT TestPresentNotReportedWhileGCDeletesClosure1058=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1059=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1060=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1061=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1062=== CONT TestOrphanedObjectsGC10632026/11/04 20:13:50 INFO Received push request method=POST path=/api/pushes10642026/11/04 20:13:50 INFO Received complete push request method=POST path=/api/pushes/1/complete10652026/11/04 20:13:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1066--- PASS: TestService_Rustfstest (1.86s)1067=== CONT TestObjectStatsUpdatedOncePerCommit10682026/11/04 20:13:50 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLmYyYTM1OTkwLTk1ZDYtNGY1NC1iMDgyLTA3NGNjNzQxOGEzMXgxNzkzODIzMjMwNTQyMzI2OTI210692026/11/04 20:13:50 INFO Completed push id=1 objects=4 duration=16.876896ms10702026/11/04 20:13:50 INFO Received push request method=POST path=/api/pushes10712026/11/04 20:13:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLmYyYTM1OTkwLTk1ZDYtNGY1NC1iMDgyLTA3NGNjNzQxOGEzMXgxNzkzODIzMjMwNTQyMzI2OTI2 parts=11072--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.87s)1073=== CONT TestPresentRefreshesOnlyStaleClosures1074--- PASS: TestReadProxyDisabled (0.82s)1075=== CONT TestService_verifyS3ReuploadsStaleNarinfo1076=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1077=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1078=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1079=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1080=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1081=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1082=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1083=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1084=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1085=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1086=== CONT TestPresentReportsOnlyClosureRoots10872026/11/04 20:13:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46857/oidc10882026/11/04 20:13:50 INFO Aborted multipart uploads count=0 kept=010892026/11/04 20:13:50 WARN Force mode enabled - objects will be deleted immediately without grace period10902026/11/04 20:13:50 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=010912026/11/04 20:13:50 INFO Vacuumed table table=pending_closures10922026/11/04 20:13:50 INFO Vacuumed table table=pending_objects10932026/11/04 20:13:50 INFO Vacuumed table table=multipart_uploads1094--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.85s)1095=== CONT TestGCMetrics10962026/11/04 20:13:50 INFO Vacuumed table table=closures10972026/11/04 20:13:50 INFO Vacuumed table table=objects10982026/11/04 20:13:50 INFO Received complete push request method=POST path=/api/pushes/2/complete10992026/11/04 20:13:50 INFO Completed push id=2 objects=4 duration=3.858676ms1100--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.00s)1101=== CONT TestClientSharedPathCommittedMidPush1102--- PASS: TestReadProxyHead (0.87s)1103=== CONT TestService_healthCheckHandler11042026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures11052026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures11062026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures11072026-11-04 20:13:50.811 UTC [551] ERROR: Push does not exist: id=111082026-11-04 20:13:50.811 UTC [551] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11092026-11-04 20:13:50.811 UTC [551] STATEMENT: SELECT commit_push($1)1110--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (2.05s)1111=== CONT TestGCBugBareHashReferences1112--- PASS: TestReadProxyConditionalGet (0.94s)1113=== CONT TestGracefulShutdownDrainsInflight11142026/11/04 20:13:50 INFO Starting HTTP server address=127.0.0.1:3279511152026/11/04 20:13:50 INFO Shutdown signal received, draining in-flight requests timeout=10s11162026/11/04 20:13:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11172026/11/04 20:13:50 INFO Received cleanup request method=DELETE path=/api/pending_closures11182026/11/04 20:13:50 INFO Aborted multipart uploads count=0 kept=011192026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures11202026/11/04 20:13:50 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLmQxZjAxMDc4LTc0OGYtNDZmYS1hNGYwLTUzNjk5YmNjN2QwMHgxNzkzODIzMjMwMzczMzU5MDQx parts=1211212026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures11222026/11/04 20:13:50 INFO Received cleanup request method=DELETE path=/api/pending_closures1123--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.16s)1124=== CONT TestGCAdvisoryLockBlocksConcurrentRun11252026/11/04 20:13:50 INFO Aborted multipart uploads count=1 kept=011262026/11/04 20:13:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11272026/11/04 20:13:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11282026-11-04 20:13:50.900 UTC [527] ERROR: Closure does not exist: id=111292026-11-04 20:13:50.900 UTC [527] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11302026-11-04 20:13:50.900 UTC [527] STATEMENT: -- name: CommitPendingClosure :one1131 SELECT commit_pending_closure($1::bigint)::bigint1132 1133--- PASS: TestService_cleanupPendingClosuresHandler (0.95s)1134=== CONT TestGCTaskStore_Fail1135--- PASS: TestGCTaskStore_Fail (0.00s)1136=== CONT TestLeadEndsOnShutdown1137--- PASS: TestReadProxyInvalidPath (0.89s)1138=== CONT TestGCTaskStore_PhaseUpdates1139--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1140=== CONT TestLeadIncumbentAnnouncesAtOnce11412026/11/04 20:13:50 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLjUzMDk3NzM2LTVlNGItNGQzZC05ODlmLTYzNmFmMTRkNzE1Y3gxNzkzODIzMjMwNDc5MDk4MDAw parts=1011422026/11/04 20:13:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11432026/11/04 20:13:50 INFO Completed upload id=1 objects=2 duration=4.570363ms1144--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1145=== CONT TestGCTaskStore_CompletedAllowsNewTask1146--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1147=== CONT TestLeadElectsOneAndHandsOver11482026/11/04 20:13:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11492026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures11502026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures1151--- PASS: TestReadProxyNarStreaming (0.65s)1152=== CONT TestGCTaskStore_GetReturnsLatest1153--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1154=== CONT TestConnectWaitsForAPeerMigration11552026/11/04 20:13:50 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11562026/11/04 20:13:50 WARN Found objects in DB but missing from S3, will re-upload count=11157--- PASS: TestService_verifyS3Integrity (2.21s)1158=== CONT TestGCTaskStore_GetEmpty1159--- PASS: TestGCTaskStore_GetEmpty (0.00s)1160=== CONT TestResolveDBConnectionString1161=== RUN TestResolveDBConnectionString/flag_wins1162=== PAUSE TestResolveDBConnectionString/flag_wins1163=== RUN TestResolveDBConnectionString/file_when_flag_empty1164=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1165=== RUN TestResolveDBConnectionString/missing_file_is_an_error1166=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1167=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1168=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1169=== RUN TestResolveDBConnectionString/nothing_configured1170=== PAUSE TestResolveDBConnectionString/nothing_configured1171=== CONT TestGCTaskStore_ConflictDifferentParams1172--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1173=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11742026/11/04 20:13:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLjUyY2Q4Y2YzLWY5NmMtNGM4Ny1iMzI1LWFiMzdhOWJiYTA0NXgxNzkzODIzMjMwNDEzNTYwMTcz parts=1211752026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures11762026/11/04 20:13:50 INFO Received uploads request method=POST path=/api/pending_closures1177--- PASS: TestObjectStatsTrigger (0.75s)1178=== CONT TestGCTaskStore_DeduplicateSameParams1179--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1180=== CONT TestDeleteClosuresRacingPins11812026/11/04 20:13:51 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1182--- PASS: TestReadProxyNarinfo (0.75s)1183=== CONT TestGCTaskStore_StartNew1184--- PASS: TestGCTaskStore_StartNew (0.00s)1185=== CONT TestClientPushesUseOnePush1186--- PASS: TestReadProxy404 (0.86s)1187=== CONT TestGCEndsOnShutdown1188=== RUN TestGCEndsOnShutdown/before_the_run1189=== PAUSE TestGCEndsOnShutdown/before_the_run1190=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1191=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1192=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1193=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1194=== CONT TestPinProtectsFromGC11952026/11/04 20:13:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11962026/11/04 20:13:51 WARN Refused reserved pin name=worker-x86_64-linux11972026/11/04 20:13:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11982026/11/04 20:13:51 INFO Received create pin request method=POST path=/api/pins/my-app11992026/11/04 20:13:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1200--- PASS: TestCreatePin_ReservedPins (0.80s)1201=== CONT TestClientFallsBackToClosures1202--- PASS: TestReadProxyContentNegotiation (0.84s)1203=== CONT TestUploadHandlersRejectInvalidKeys1204=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1205=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1206=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1207=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1208=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1209=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1210=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1211=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1212=== CONT TestCommitRacingPendingCleanupKeepsObjects12132026/11/04 20:13:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12142026/11/04 20:13:51 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLjU4NTFhNDhiLWUwMDAtNDU3ZS04YzNhLTI1OTdlZjlhOTQwNngxNzkzODIzMjMwODI4MTQxNjEy parts=1012152026/11/04 20:13:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12162026/11/04 20:13:51 INFO Completed upload id=1 objects=2 duration=4.646323ms12172026/11/04 20:13:51 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012182026/11/04 20:13:51 INFO Received uploads request method=POST path=/api/pending_closures12192026/11/04 20:13:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures1220--- PASS: TestPresentRefreshesOnlyStaleClosures (0.62s)1221=== CONT TestPushWaitsForSweepHoldingRow12222026/11/04 20:13:51 INFO Aborted multipart uploads count=0 kept=01223--- PASS: TestObjectStatsUpdatedOncePerCommit (0.64s)1224=== CONT TestMetricsCommit12252026/11/04 20:13:51 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=012262026/11/04 20:13:51 INFO Vacuumed table table=pending_closures12272026/11/04 20:13:51 INFO Vacuumed table table=pending_objects12282026/11/04 20:13:51 INFO Vacuumed table table=multipart_uploads12292026/11/04 20:13:51 INFO Vacuumed table table=closures12302026/11/04 20:13:51 INFO Vacuumed table table=objects12312026/11/04 20:13:51 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"1232--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.44s)1233=== CONT TestSweepRechecksPendingAfterLocking1234--- PASS: TestPresentReportsOnlyClosureRoots (0.75s)1235=== CONT TestPendingCleanupUsesOneCutoff12362026/11/04 20:13:51 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001237--- PASS: TestService_createPendingClosureHandler (1.41s)1238=== CONT TestGetExistingObjectsLocksRows1239--- PASS: TestService_healthCheckHandler (0.60s)1240=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded12412026/11/04 20:13:51 INFO lead: acquired remote=192.0.2.1:123412422026/11/04 20:13:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12432026/11/04 20:13:51 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLmY5YjdkOTk4LTY1ZTAtNDA2Zi1iYjczLTM0MjY4MmRlMzZkMHgxNzkzODIzMjMwOTc3MTIxNzUy error="Get \"http://127.0.0.1:1/bucket21/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12442026/11/04 20:13:51 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLjYxMWVjZTk0LTlkNGYtNDgxZC05MGY1LTE5ZmM1Mjg5NjUwY3gxNzkzODIzMjMwOTY5MzI3MDAw parts=1212452026/11/04 20:13:51 INFO Received cleanup request method=DELETE path=/api/pending_closures12462026/11/04 20:13:51 INFO Aborted multipart uploads count=1 kept=01247--- PASS: TestRedundantMultipartUpload (2.74s)1248=== CONT TestRegisterCompletedObjectNeedsPendingRow12492026/11/04 20:13:51 INFO Aborted multipart uploads count=0 kept=012502026/11/04 20:13:51 INFO lead: acquired remote=192.0.2.1:123412512026/11/04 20:13:51 INFO lead: released remote=192.0.2.1:12341252--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.62s)1253=== CONT TestMultipartCleanup12542026/11/04 20:13:51 INFO lead: acquired remote=192.0.2.1:12341255=== NAME TestOrphanedObjectsGC1256 orphaned_objects_gc_test.go:287: GC Test Summary:1257 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1258 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1259 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1260 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1261 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1262--- PASS: TestOrphanedObjectsGC (1.01s)1263=== CONT TestSweepSkipsRowsLockedByPush1264=== CONT TestServerTLSConfig1265=== RUN TestServerTLSConfig/no_client_CA1266=== PAUSE TestServerTLSConfig/no_client_CA1267=== RUN TestServerTLSConfig/missing_CA_file1268=== PAUSE TestServerTLSConfig/missing_CA_file1269=== RUN TestServerTLSConfig/not_a_PEM_file1270--- PASS: TestGCBugBareHashReferences (0.76s)1271=== PAUSE TestServerTLSConfig/not_a_PEM_file1272=== CONT TestFailedS3DeleteKeepsTombstone12732026/11/04 20:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period12742026/11/04 20:13:51 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=012752026/11/04 20:13:51 INFO Vacuumed table table=pending_closures12762026/11/04 20:13:51 INFO Vacuumed table table=pending_objects12772026/11/04 20:13:51 INFO Vacuumed table table=multipart_uploads12782026/11/04 20:13:51 INFO Vacuumed table table=closures12792026/11/04 20:13:51 INFO Vacuumed table table=objects1280--- PASS: TestGCMetrics (0.83s)1281=== CONT TestService_NativeMTLS12822026/11/04 20:13:51 INFO Received push request method=POST path=/api/pushes12832026/11/04 20:13:51 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12842026/11/04 20:13:51 INFO Uploading 9h2zw4s4ijqqwmbpzyr7fir0lkym0njw-shared-dep (136B)12852026/11/04 20:13:51 INFO Uploading rajb3gkax6fn5c903wvn1vfs0a34al5z-top (224B)12862026/11/04 20:13:51 WARN Failed to register uploaded object key=nar/1qzjzzksvhhw95p4addxj9wgsvcn9fyw2lgd2gvdmvzn9mx9smpl.nar.zst error="server returned 404: 404 page not found\n"12872026/11/04 20:13:51 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12882026/11/04 20:13:51 WARN Failed to register uploaded object key=rajb3gkax6fn5c903wvn1vfs0a34al5z.ls error="server returned 404: 404 page not found\n"12892026/11/04 20:13:51 WARN Failed to register uploaded object key=9h2zw4s4ijqqwmbpzyr7fir0lkym0njw.ls error="server returned 404: 404 page not found\n"12902026/11/04 20:13:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12912026/11/04 20:13:51 INFO Signed narinfos id=1 count=212922026/11/04 20:13:51 INFO Uploading 2 narinfos12932026/11/04 20:13:51 WARN Failed to register uploaded object key=9h2zw4s4ijqqwmbpzyr7fir0lkym0njw.narinfo error="server returned 404: 404 page not found\n"12942026/11/04 20:13:51 INFO Received complete push request method=POST path=/api/pushes/1/complete12952026/11/04 20:13:51 WARN Failed to register uploaded object key=rajb3gkax6fn5c903wvn1vfs0a34al5z.narinfo error="server returned 404: 404 page not found\n"12962026/11/04 20:13:51 INFO Completed push id=1 objects=6 duration=11.953751ms12972026/11/04 20:13:51 INFO Upload complete. (95ms)1298=== NAME TestClientSharedPathCommittedMidPush1299 client_integration_test.go:727: Retrieved narinfo from S3:1300 StorePath: /build/TestClientSharedPathCommittedMidPush553834075/001/store/9h2zw4s4ijqqwmbpzyr7fir0lkym0njw-shared-dep1301 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1302 Compression: zstd1303 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821304 NarSize: 1361305 References: 1306 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1307 client_integration_test.go:727: Retrieved narinfo from S3:1308 StorePath: /build/TestClientSharedPathCommittedMidPush553834075/001/store/rajb3gkax6fn5c903wvn1vfs0a34al5z-top1309 URL: nar/1qzjzzksvhhw95p4addxj9wgsvcn9fyw2lgd2gvdmvzn9mx9smpl.nar.zst1310 Compression: zstd1311 NarHash: sha256:1qzjzzksvhhw95p4addxj9wgsvcn9fyw2lgd2gvdmvzn9mx9smpl1312 NarSize: 2241313 References: /build/TestClientSharedPathCommittedMidPush553834075/001/store/9h2zw4s4ijqqwmbpzyr7fir0lkym0njw-shared-dep1314 CA: text:sha256:1icbpi1xgcad49356fs7c6bmxjsqcqi53zb9c0ii38k3s179ryxg1315--- PASS: TestClientSharedPathCommittedMidPush (0.93s)1316=== CONT TestForceGCDuringPushOffersSweptObject1317=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1318=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1319=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1320=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1321=== CONT TestCacheConfigHandler1322=== RUN TestCacheConfigHandler/full_config,_no_issuer1323=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1324=== RUN TestCacheConfigHandler/no_cache_url_configured1325=== PAUSE TestCacheConfigHandler/no_cache_url_configured1326=== RUN TestCacheConfigHandler/no_signing_keys1327=== PAUSE TestCacheConfigHandler/no_signing_keys1328=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1329=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1330=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection13312026/11/04 20:13:51 INFO Received uploads request method=POST path=/api/pending_closures13322026/11/04 20:13:51 INFO Aborted multipart uploads count=0 kept=013332026/11/04 20:13:51 INFO Received push request method=POST path=/api/pushes13342026/11/04 20:13:51 INFO Received complete push request method=POST path=/api/pushes/1/complete13352026/11/04 20:13:51 INFO Aborted multipart uploads count=0 kept=013362026/11/04 20:13:51 INFO Received uploads request method=POST path=/api/pending_closures1337--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.44s)1338=== CONT TestClientWithDependencies1339--- PASS: TestGetExistingObjectsLocksRows (0.47s)1340=== CONT TestDeduplicatedObjectsRecordedAsPending13412026/11/04 20:13:51 INFO Received uploads request method=POST path=/api/pending_closures13422026/11/04 20:13:51 INFO Received uploads request method=POST path=/api/pending_closures13432026/11/04 20:13:51 INFO Received cleanup request method=DELETE path=/api/pending_closures1344--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.43s)1345=== CONT TestClientMultipleUploads13462026/11/04 20:13:51 INFO Received uploads request method=POST path=/api/pending_closures13472026/11/04 20:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period13482026/11/04 20:13:51 WARN Force mode enabled - objects will be deleted immediately without grace period13492026/11/04 20:13:51 INFO Completed push id=1 objects=4 duration=166.406661ms13502026/11/04 20:13:51 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=013512026/11/04 20:13:51 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13522026/11/04 20:13:51 INFO Vacuumed table table=pending_closures13532026/11/04 20:13:51 INFO Completed upload id=2 objects=2 duration=2.040219ms1354=== NAME TestPinProtectsFromGC1355 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3696246317/001/store/0zaaw2raqw8zfrcp985bf2nsvrncjwss-pinned-file.txt1356 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3696246317/001/store/jf25r79kl4m350dlx6rlnvp1pykfpbhw-unpinned-file.txt1357--- PASS: TestMetricsCommit (0.73s)1358=== CONT TestPushDedupSurvivesConcurrentGC13592026/11/04 20:13:51 INFO Vacuumed table table=pending_objects13602026/11/04 20:13:51 INFO Vacuumed table table=multipart_uploads13612026/11/04 20:13:51 INFO Vacuumed table table=closures13622026/11/04 20:13:51 INFO Vacuumed table table=objects13632026/11/04 20:13:51 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=013642026/11/04 20:13:51 INFO Vacuumed table table=pending_closures13652026/11/04 20:13:51 INFO Vacuumed table table=pending_objects13662026/11/04 20:13:51 INFO Vacuumed table table=multipart_uploads13672026/11/04 20:13:51 INFO Vacuumed table table=closures13682026/11/04 20:13:51 INFO Vacuumed table table=objects1369--- PASS: TestSweepRechecksPendingAfterLocking (0.66s)1370=== CONT TestClientIntegration13712026/11/04 20:13:52 INFO Received uploads request method=POST path=/api/pending_closures13722026/11/04 20:13:52 INFO Aborted multipart uploads count=0 kept=01373--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.06s)1374=== CONT TestCacheStatsHandler1375--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.86s)1376=== CONT TestClientCADerivations13772026/11/04 20:13:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13782026/11/04 20:13:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1379--- PASS: TestService_NativeMTLS (0.45s)1380=== CONT TestClientErrorHandling1381=== RUN TestClientErrorHandling/InvalidStorePath1382=== PAUSE TestClientErrorHandling/InvalidStorePath1383=== RUN TestClientErrorHandling/InvalidAuthToken1384=== PAUSE TestClientErrorHandling/InvalidAuthToken1385=== RUN TestClientErrorHandling/ServerNotAvailable1386=== PAUSE TestClientErrorHandling/ServerNotAvailable1387=== CONT TestCreatePendingClosureRejectsOversizedNAR13882026/11/04 20:13:52 INFO Received uploads request method=POST path=/api/pending_closures1389--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1390=== CONT TestMetricsInventory13912026/11/04 20:13:52 WARN Force mode enabled - objects will be deleted immediately without grace period13922026/11/04 20:13:52 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=013932026/11/04 20:13:52 INFO Vacuumed table table=pending_closures13942026/11/04 20:13:52 INFO Vacuumed table table=pending_objects13952026/11/04 20:13:52 INFO Vacuumed table table=multipart_uploads13962026/11/04 20:13:52 INFO Vacuumed table table=closures13972026/11/04 20:13:52 INFO Vacuumed table table=objects13982026/11/04 20:13:52 INFO Received cleanup request method=DELETE path=/api/pending_closures13992026/11/04 20:13:52 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket68/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""14002026/11/04 20:13:52 INFO Aborted multipart uploads count=0 kept=114012026/11/04 20:13:52 INFO Aborted multipart uploads count=0 kept=014022026/11/04 20:13:52 INFO Received cleanup request method=DELETE path=/api/pending_closures14032026/11/04 20:13:52 INFO Aborted multipart uploads count=1 kept=01404--- PASS: TestMultipartCleanup (0.56s)1405=== CONT TestGCSweepDeliversEachKeyOnce14062026/11/04 20:13:52 INFO Received push request method=POST path=/api/pushes14072026/11/04 20:13:52 INFO Received uploads request method=POST path=/api/pending_closures14082026/11/04 20:13:52 INFO Aborted multipart uploads count=0 kept=014092026/11/04 20:13:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14102026/11/04 20:13:52 INFO Uploading 0zaaw2raqw8zfrcp985bf2nsvrncjwss-pinned-file.txt (128B)14112026/11/04 20:13:52 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14122026/11/04 20:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14132026/11/04 20:13:52 INFO Signed narinfos id=1 count=114142026/11/04 20:13:52 INFO Uploading 1 narinfos14152026/11/04 20:13:52 WARN Failed to register uploaded object key=0zaaw2raqw8zfrcp985bf2nsvrncjwss.ls error="server returned 404: 404 page not found\n"14162026/11/04 20:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete14172026/11/04 20:13:52 WARN Failed to register uploaded object key=0zaaw2raqw8zfrcp985bf2nsvrncjwss.narinfo error="server returned 404: 404 page not found\n"14182026/11/04 20:13:52 INFO Completed push id=1 objects=3 duration=8.247257ms14192026/11/04 20:13:52 INFO Upload complete. (121ms)14202026/11/04 20:13:52 INFO Received uploads request method=POST path=/api/pending_closures1421--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.34s)1422=== CONT TestNARDeduplicationMetadataUploadBug14232026/11/04 20:13:52 INFO Received uploads request method=POST path=/api/pending_closures14242026/11/04 20:13:52 WARN Force mode enabled - objects will be deleted immediately without grace period14252026/11/04 20:13:52 WARN Force mode enabled - objects will be deleted immediately without grace period1426--- PASS: TestPushWaitsForSweepHoldingRow (1.02s)1427=== CONT TestTombstonedObjectOfferedWithoutWaiting1428--- PASS: TestCacheStatsHandler (0.23s)1429=== CONT TestCacheConfigHandlerMaxNarSize1430--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1431=== CONT TestGenerateLandingPage14322026/11/04 20:13:52 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14332026/11/04 20:13:52 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1434--- PASS: TestFailedS3DeleteKeepsTombstone (0.68s)1435=== CONT TestGCSweepSkipsPendingObjects1436--- PASS: TestGenerateLandingPage (0.01s)1437=== CONT TestService_AuthMiddleware_OIDC1438=== NAME TestClientMultipleUploads1439 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads3562030069/001/store/nink4vbn1xr9k1l5nvnsdp646236lsx0-test-file-0.txt14402026/11/04 20:13:52 INFO Received push request method=POST path=/api/pushes14412026/11/04 20:13:52 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=014422026/11/04 20:13:52 INFO Vacuumed table table=pending_closures14432026/11/04 20:13:52 INFO Vacuumed table table=pending_objects14442026/11/04 20:13:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14452026/11/04 20:13:52 INFO Uploading jf25r79kl4m350dlx6rlnvp1pykfpbhw-unpinned-file.txt (128B)14462026/11/04 20:13:52 INFO Vacuumed table table=multipart_uploads14472026/11/04 20:13:52 INFO Vacuumed table table=closures14482026/11/04 20:13:52 INFO Received push request method=POST path=/api/pushes14492026/11/04 20:13:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14502026/11/04 20:13:52 INFO Uploading aqpbj742asyx5bmgfr1wdy174hz1zjya-shared-dep (136B)14512026/11/04 20:13:52 INFO Uploading fqwyhg6l00y0ib0mm5vc1ycmxqfzks6v-a (208B)14522026/11/04 20:13:52 INFO Vacuumed table table=objects14532026/11/04 20:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14542026/11/04 20:13:52 WARN Failed to register uploaded object key=jf25r79kl4m350dlx6rlnvp1pykfpbhw.ls error="server returned 404: 404 page not found\n"1455--- PASS: TestSweepSkipsRowsLockedByPush (0.73s)1456=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14572026/11/04 20:13:52 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14582026/11/04 20:13:52 INFO Signed narinfos id=2 count=114592026/11/04 20:13:52 INFO Uploading 1 narinfos14602026/11/04 20:13:52 WARN Failed to register uploaded object key=nar/12psrr9d8fia1rdp557hpjmkzf3jl0nfj3mpw229f64z9z5s8syv.nar.zst error="server returned 404: 404 page not found\n"14612026/11/04 20:13:52 WARN Failed to register uploaded object key=3wx7y1x6b01m1f85rl8a6hl0h5jddbz4.ls error="server returned 404: 404 page not found\n"14622026/11/04 20:13:52 WARN Failed to register uploaded object key=fqwyhg6l00y0ib0mm5vc1ycmxqfzks6v.ls error="server returned 404: 404 page not found\n"14632026/11/04 20:13:52 INFO Received complete push request method=POST path=/api/pushes/2/complete14642026/11/04 20:13:52 WARN Failed to register uploaded object key=aqpbj742asyx5bmgfr1wdy174hz1zjya.ls error="server returned 404: 404 page not found\n"14652026/11/04 20:13:52 WARN Failed to register uploaded object key=jf25r79kl4m350dlx6rlnvp1pykfpbhw.narinfo error="server returned 404: 404 page not found\n"14662026/11/04 20:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14672026/11/04 20:13:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14682026/11/04 20:13:52 INFO Signed narinfos id=1 count=314692026/11/04 20:13:52 INFO Uploading 3 narinfos14702026/11/04 20:13:52 INFO Completed push id=2 objects=3 duration=3.890596ms14712026/11/04 20:13:52 INFO Upload complete. (67ms)14722026/11/04 20:13:52 WARN Failed to register uploaded object key=3wx7y1x6b01m1f85rl8a6hl0h5jddbz4.narinfo error="server returned 404: 404 page not found\n"14732026/11/04 20:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete14742026/11/04 20:13:52 WARN Failed to register uploaded object key=fqwyhg6l00y0ib0mm5vc1ycmxqfzks6v.narinfo error="server returned 404: 404 page not found\n"14752026/11/04 20:13:52 WARN Failed to register uploaded object key=aqpbj742asyx5bmgfr1wdy174hz1zjya.narinfo error="server returned 404: 404 page not found\n"1476--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.61s)1477=== CONT TestService_ReadScope_PublicByDefault14782026/11/04 20:13:52 INFO Aborted multipart uploads count=0 kept=014792026/11/04 20:13:52 INFO Completed push id=1 objects=8 duration=18.38507ms14802026/11/04 20:13:52 INFO Upload complete. (87ms)1481=== NAME TestClientPushesUseOnePush1482 client_pushes_test.go:97: Retrieved narinfo from S3:1483 StorePath: /build/TestClientPushesUseOnePush777749594/001/store/aqpbj742asyx5bmgfr1wdy174hz1zjya-shared-dep1484 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1485 Compression: zstd1486 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821487 NarSize: 1361488 References: 1489 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1490 client_pushes_test.go:97: Retrieved narinfo from S3:1491 StorePath: /build/TestClientPushesUseOnePush777749594/001/store/fqwyhg6l00y0ib0mm5vc1ycmxqfzks6v-a1492 URL: nar/12psrr9d8fia1rdp557hpjmkzf3jl0nfj3mpw229f64z9z5s8syv.nar.zst1493 Compression: zstd1494 NarHash: sha256:12psrr9d8fia1rdp557hpjmkzf3jl0nfj3mpw229f64z9z5s8syv1495 NarSize: 2081496 References: /build/TestClientPushesUseOnePush777749594/001/store/aqpbj742asyx5bmgfr1wdy174hz1zjya-shared-dep1497 CA: text:sha256:0al2a7jam6g7va7x7xb3xv6xmp0dsc0ydhpl4p7jbykz24747cmr1498 client_pushes_test.go:97: Retrieved narinfo from S3:1499 StorePath: /build/TestClientPushesUseOnePush777749594/001/store/3wx7y1x6b01m1f85rl8a6hl0h5jddbz4-b1500 URL: nar/12psrr9d8fia1rdp557hpjmkzf3jl0nfj3mpw229f64z9z5s8syv.nar.zst1501 Compression: zstd1502 NarHash: sha256:12psrr9d8fia1rdp557hpjmkzf3jl0nfj3mpw229f64z9z5s8syv1503 NarSize: 2081504 References: /build/TestClientPushesUseOnePush777749594/001/store/aqpbj742asyx5bmgfr1wdy174hz1zjya-shared-dep1505 CA: text:sha256:0al2a7jam6g7va7x7xb3xv6xmp0dsc0ydhpl4p7jbykz24747cmr1506--- PASS: TestClientPushesUseOnePush (1.29s)1507=== CONT TestService_ReadAuthMiddleware1508--- PASS: TestMetricsInventory (0.30s)1509=== CONT TestService_AuthMiddleware_MTLSProxyHeader15102026/11/04 20:13:52 INFO Aborted multipart uploads count=0 kept=01511=== NAME TestClientMultipleUploads1512 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads3562030069/001/store/7l5piwgg6fy2cb523mr4178mj17xk3ml-test-file-1.txt15132026/11/04 20:13:52 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=01514=== NAME TestClientIntegration1515 client_integration_test.go:291: Created store path: /build/TestClientIntegration3150308156/002/store/vs42gvxc5ghldcf551imaf7yv29n15s7-test-file.txt15162026/11/04 20:13:52 INFO Vacuumed table table=pending_closures15172026/11/04 20:13:52 INFO Vacuumed table table=pending_objects15182026/11/04 20:13:52 INFO Vacuumed table table=multipart_uploads15192026/11/04 20:13:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46417/oidc15202026/11/04 20:13:52 INFO Vacuumed table table=closures15212026/11/04 20:13:52 INFO Vacuumed table table=objects15222026/11/04 20:13:52 INFO Aborted multipart uploads count=0 kept=015232026/11/04 20:13:52 WARN Force mode enabled - objects will be deleted immediately without grace period15242026/11/04 20:13:52 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=015252026/11/04 20:13:52 INFO Vacuumed table table=pending_closures15262026/11/04 20:13:52 INFO Vacuumed table table=pending_objects15272026/11/04 20:13:52 INFO Vacuumed table table=multipart_uploads15282026/11/04 20:13:52 INFO Vacuumed table table=closures15292026/11/04 20:13:52 INFO Vacuumed table table=objects1530--- PASS: TestPushDedupSurvivesConcurrentGC (0.51s)1531=== CONT TestService_RequireScope_OIDC15322026/11/04 20:13:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15332026/11/04 20:13:52 WARN mTLS auth: bound subjects configured but subject DN unavailable15342026/11/04 20:13:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1535--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.22s)1536=== CONT TestPendingClosureWriteTimeout/empty1537=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15382026/11/04 20:13:52 INFO lead: released remote=192.0.2.1:12341539--- PASS: TestLeadEndsOnShutdown (1.63s)1540=== CONT TestPendingClosureWriteTimeout/670k_objects1541=== CONT TestPendingClosureWriteTimeout/400_objects1542=== CONT TestIsValidUploadKey/narinfo1543=== CONT TestIsValidUploadKey/nix-cache-info1544=== CONT TestIsValidUploadKey/unknown_type1545=== CONT TestIsValidUploadKey/empty_key1546=== CONT TestIsValidUploadKey/absolute1547=== CONT TestIsValidUploadKey/traversal_nar1548=== CONT TestIsValidUploadKey/traversal1549=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1550=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1551=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1552=== CONT TestIsValidUploadKey/index.html1553=== CONT TestIsValidUploadKey/build_log_home-manager_file1554=== CONT TestIsValidUploadKey/realisation_plus_in_output1555=== CONT TestIsValidUploadKey/realisation1556=== CONT TestIsValidUploadKey/build_log_equals1557=== CONT TestIsValidUploadKey/build_log_question_mark1558=== CONT TestIsValidUploadKey/build_log_plus_in_name1559=== CONT TestIsValidUploadKey/nar_plain1560=== CONT TestIsValidUploadKey/build_log1561=== CONT TestIsValidUploadKey/listing1562=== CONT TestIsValidUploadKey/nar_xz1563=== CONT TestIsValidUploadKey/nar_zst1564--- PASS: TestIsValidUploadKey (0.10s)1565 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1566 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1567 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1568 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1569 --- PASS: TestIsValidUploadKey/absolute (0.00s)1570 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1571 --- PASS: TestIsValidUploadKey/traversal (0.00s)1572 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1573 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1574 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1575 --- PASS: TestIsValidUploadKey/index.html (0.00s)1576 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1577 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1578 --- PASS: TestIsValidUploadKey/realisation (0.00s)1579 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1580 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1581 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1582 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1583 --- PASS: TestIsValidUploadKey/build_log (0.00s)1584 --- PASS: TestIsValidUploadKey/listing (0.00s)1585 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1586 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1587=== CONT TestProxyWriteTimeout/narinfo1588=== CONT TestProxyWriteTimeout/10_GiB_nar1589=== CONT TestProxyWriteTimeout/1_GiB_nar1590=== CONT TestProxyWriteTimeout/unknown_size1591--- PASS: TestProxyWriteTimeout (0.13s)1592 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1593 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1594 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1595 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1596=== CONT TestPush_RejectsBadRequests/no_roots15972026/11/04 20:13:52 INFO Received push request method=POST path=/api/pushes1598=== CONT TestPush_RejectsBadRequests/bad_root15992026/11/04 20:13:52 INFO Received push request method=POST path=/api/pushes1600=== CONT TestPush_RejectsBadRequests/root_not_in_objects16012026/11/04 20:13:52 INFO Received push request method=POST path=/api/pushes1602=== CONT TestPush_RejectsBadRequests/no_objects16032026/11/04 20:13:52 INFO Received push request method=POST path=/api/pushes1604=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1605--- PASS: TestPush_RejectsBadRequests (1.04s)1606 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1607 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1608 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1609 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)16102026/11/04 20:13:52 INFO Received uploads request method=POST path=/16112026/11/04 20:13:52 INFO Received uploads request method=POST path=/api/pending_closures16122026/11/04 20:13:52 INFO Received uploads request method=POST path=/api/pending_closures16132026/11/04 20:13:52 WARN Force mode enabled - objects will be deleted immediately without grace period16142026/11/04 20:13:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures16152026/11/04 20:13:52 INFO Garbage collection started1616--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.31s)1617=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16182026/11/04 20:13:52 INFO Received request for more parts method=POST path=/16192026/11/04 20:13:52 INFO Received uploads request method=POST path=/api/pending_closures1620=== NAME TestClientMultipleUploads1621 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads3562030069/001/store/6qj8rq3nc65ywlfhqsppnkg0rs058spd-test-file-2.txt16222026/11/04 20:13:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16232026/11/04 20:13:52 INFO Uploading qzjpvfbgv3gr221p7gxs1vsnhwc34q1f-a (216B)16242026/11/04 20:13:52 INFO Uploading 9czgy3jmz98wy22np49b74r8a7xss2xx-shared-dep (136B)1625=== NAME TestNARDeduplicationMetadataUploadBug1626 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1326231200/001/store/6lal8ff76b85xgglp427rv8232r7307v-file1.txt16272026/11/04 20:13:52 WARN Failed to register uploaded object key=n8km8jr0wmhdxj70186bmj0lj7jrhlpb.ls error="server returned 404: 404 page not found\n"16282026/11/04 20:13:52 INFO Aborted multipart uploads count=0 kept=016292026/11/04 20:13:52 WARN Failed to register uploaded object key=qzjpvfbgv3gr221p7gxs1vsnhwc34q1f.ls error="server returned 404: 404 page not found\n"16302026/11/04 20:13:52 WARN Failed to register uploaded object key=9czgy3jmz98wy22np49b74r8a7xss2xx.ls error="server returned 404: 404 page not found\n"16312026/11/04 20:13:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16322026/11/04 20:13:52 WARN Failed to register uploaded object key=nar/14kyig81qfji2vxyiqqr5s6dd4zrjh2wy2b8vgxxwzisnmj6fvjl.nar.zst error="server returned 404: 404 page not found\n"16332026/11/04 20:13:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16342026/11/04 20:13:52 INFO Signed narinfos id=2 count=216352026/11/04 20:13:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16362026/11/04 20:13:52 INFO Signed narinfos id=1 count=216372026/11/04 20:13:52 INFO Uploading 4 narinfos16382026/11/04 20:13:52 WARN Failed to register uploaded object key=qzjpvfbgv3gr221p7gxs1vsnhwc34q1f.narinfo error="server returned 404: 404 page not found\n"16392026/11/04 20:13:52 WARN Failed to register uploaded object key=9czgy3jmz98wy22np49b74r8a7xss2xx.narinfo error="server returned 404: 404 page not found\n"16402026/11/04 20:13:52 WARN Failed to register uploaded object key=n8km8jr0wmhdxj70186bmj0lj7jrhlpb.narinfo error="server returned 404: 404 page not found\n"16412026/11/04 20:13:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16422026/11/04 20:13:52 WARN Failed to register uploaded object key=9czgy3jmz98wy22np49b74r8a7xss2xx.narinfo error="server returned 404: 404 page not found\n"16432026/11/04 20:13:52 INFO Completed upload id=1 objects=6 duration=8.6158ms16442026/11/04 20:13:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16452026/11/04 20:13:52 INFO Completed upload id=2 objects=6 duration=1.865037ms16462026/11/04 20:13:52 INFO Upload complete. (316ms)1647=== NAME TestClientFallsBackToClosures1648 client_pushes_test.go:112: Retrieved narinfo from S3:1649 StorePath: /build/TestClientFallsBackToClosures2697493555/001/store/9czgy3jmz98wy22np49b74r8a7xss2xx-shared-dep1650 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1651 Compression: zstd1652 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821653 NarSize: 1361654 References: 1655 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1656 client_pushes_test.go:112: Retrieved narinfo from S3:1657 StorePath: /build/TestClientFallsBackToClosures2697493555/001/store/qzjpvfbgv3gr221p7gxs1vsnhwc34q1f-a1658 URL: nar/14kyig81qfji2vxyiqqr5s6dd4zrjh2wy2b8vgxxwzisnmj6fvjl.nar.zst1659 Compression: zstd1660 NarHash: sha256:14kyig81qfji2vxyiqqr5s6dd4zrjh2wy2b8vgxxwzisnmj6fvjl1661 NarSize: 2161662 References: /build/TestClientFallsBackToClosures2697493555/001/store/9czgy3jmz98wy22np49b74r8a7xss2xx-shared-dep1663 CA: text:sha256:05ijrs83lwhlx59asqwpadggknkj45ss4vvsy4nji84p9kvgjxhs1664 client_pushes_test.go:112: Retrieved narinfo from S3:1665 StorePath: /build/TestClientFallsBackToClosures2697493555/001/store/n8km8jr0wmhdxj70186bmj0lj7jrhlpb-b1666 URL: nar/14kyig81qfji2vxyiqqr5s6dd4zrjh2wy2b8vgxxwzisnmj6fvjl.nar.zst1667 Compression: zstd1668 NarHash: sha256:14kyig81qfji2vxyiqqr5s6dd4zrjh2wy2b8vgxxwzisnmj6fvjl1669 NarSize: 2161670 References: /build/TestClientFallsBackToClosures2697493555/001/store/9czgy3jmz98wy22np49b74r8a7xss2xx-shared-dep1671 CA: text:sha256:05ijrs83lwhlx59asqwpadggknkj45ss4vvsy4nji84p9kvgjxhs1672--- PASS: TestClientFallsBackToClosures (1.44s)1673=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16742026/11/04 20:13:52 INFO Received complete multipart upload request method=POST path=/16752026/11/04 20:13:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45129/oidc16762026/11/04 20:13:52 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=016772026/11/04 20:13:52 INFO Vacuumed table table=pending_closures16782026/11/04 20:13:52 INFO Vacuumed table table=pending_objects16792026/11/04 20:13:52 INFO Vacuumed table table=multipart_uploads16802026/11/04 20:13:52 INFO Vacuumed table table=closures16812026/11/04 20:13:52 INFO Vacuumed table table=objects1682--- PASS: TestGCSweepDeliversEachKeyOnce (0.54s)1683=== CONT TestIsValidCachePath/narinfo1684=== CONT TestIsValidCachePath/index.html1685=== CONT TestIsValidCachePath/nar_uncompressed1686=== CONT TestIsValidCachePath/short_hash1687=== CONT TestIsValidCachePath/nix-cache-info1688=== CONT TestIsValidCachePath/wrong_extension1689=== CONT TestIsValidCachePath/realisation1690=== CONT TestIsValidCachePath/nar_xz1691=== CONT TestIsValidCachePath/leading_slash1692=== CONT TestIsValidCachePath/log1693=== CONT TestIsValidCachePath/nar_bz21694=== CONT TestIsValidCachePath/ls1695=== CONT TestIsValidCachePath/empty1696=== CONT TestIsValidCachePath/random_path1697=== CONT TestIsValidCachePath/nar_zst1698=== CONT TestIsValidCachePath/invalid_char_u1699=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1700=== CONT TestIsValidCachePath/traversal_parent1701=== CONT TestIsValidCachePath/traversal_in_middle1702=== CONT TestIsValidCachePath/invalid_char_e1703--- PASS: TestIsValidCachePath (0.00s)1704 --- PASS: TestIsValidCachePath/narinfo (0.00s)1705 --- PASS: TestIsValidCachePath/index.html (0.00s)1706 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1707 --- PASS: TestIsValidCachePath/short_hash (0.00s)1708 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1709 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1710 --- PASS: TestIsValidCachePath/realisation (0.00s)1711 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1712 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1713 --- PASS: TestIsValidCachePath/log (0.00s)1714 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1715 --- PASS: TestIsValidCachePath/ls (0.00s)1716 --- PASS: TestIsValidCachePath/empty (0.00s)1717 --- PASS: TestIsValidCachePath/random_path (0.00s)1718 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1719 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1720 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1721 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1722 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1723 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1724=== CONT TestParseSingleRange/none1725=== CONT TestParseSingleRange/open-ended1726=== CONT TestParseSingleRange/start_far_past_EOF1727=== CONT TestParseSingleRange/suffix1728=== CONT TestParseSingleRange/end_clamped_to_size1729=== CONT TestParseSingleRange/start_past_EOF1730=== CONT TestParseSingleRange/suffix_exceeds_size1731=== CONT TestParseSingleRange/single_byte1732=== CONT TestParseSingleRange/malformed_both_empty1733=== CONT TestParseSingleRange/closed1734=== CONT TestParseSingleRange/malformed_end_before_start1735=== CONT TestParseSingleRange/malformed_no_dash1736=== CONT TestParseSingleRange/multi-range_ignored1737=== CONT TestParseSingleRange/unknown_unit1738=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1739--- PASS: TestParseSingleRange (0.00s)1740 --- PASS: TestParseSingleRange/none (0.00s)1741 --- PASS: TestParseSingleRange/open-ended (0.00s)1742 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1743 --- PASS: TestParseSingleRange/suffix (0.00s)1744 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1745 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1746 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1747 --- PASS: TestParseSingleRange/single_byte (0.00s)1748 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1749 --- PASS: TestParseSingleRange/closed (0.00s)1750 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1751 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1752 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1753 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1754=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1755--- PASS: TestService_ReadAuthMiddleware (0.28s)1756=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1757--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.30s)1758=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1759=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1760=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1761=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1762=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1763=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1764=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1765=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1766=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1767=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1768=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1769--- PASS: TestService_ReadScope_PublicByDefault (0.39s)1770=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed17712026/11/04 20:13:52 INFO lead: released remote=192.0.2.1:123417722026/11/04 20:13:52 WARN Force mode enabled - objects will be deleted immediately without grace period17732026/11/04 20:13:52 INFO Received push request method=POST path=/api/pushes17742026/11/04 20:13:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17752026/11/04 20:13:52 INFO Uploading vs42gvxc5ghldcf551imaf7yv29n15s7-test-file.txt (152B)17762026/11/04 20:13:52 WARN Failed to register uploaded object key=vs42gvxc5ghldcf551imaf7yv29n15s7.ls error="server returned 404: 404 page not found\n"17772026/11/04 20:13:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17782026/11/04 20:13:52 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17792026/11/04 20:13:52 INFO Signed narinfos id=1 count=117802026/11/04 20:13:52 INFO Uploading 1 narinfos1781=== NAME TestClientCADerivations1782 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1988960892/001/store/swq0rf8ryncxm93x8v47y7dsh2fp37f8-ca-test1783=== NAME TestClientWithDependencies1784 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies1769637736/001/store/ymya185klnbmgldy8xwdhsc3978hvrh7-test-script17852026/11/04 20:13:52 INFO Received complete push request method=POST path=/api/pushes/1/complete17862026/11/04 20:13:52 WARN Failed to register uploaded object key=vs42gvxc5ghldcf551imaf7yv29n15s7.narinfo error="server returned 404: 404 page not found\n"17872026/11/04 20:13:52 INFO Completed push id=1 objects=3 duration=6.958785ms17882026/11/04 20:13:52 INFO Upload complete. (283ms)17892026/11/04 20:13:52 INFO lead: acquired remote=192.0.2.1:123417902026/11/04 20:13:52 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=017912026/11/04 20:13:52 INFO Vacuumed table table=pending_closures17922026/11/04 20:13:52 INFO Vacuumed table table=pending_objects17932026/11/04 20:13:52 INFO Vacuumed table table=multipart_uploads17942026/11/04 20:13:52 INFO Vacuumed table table=closures17952026/11/04 20:13:52 INFO Vacuumed table table=objects1796=== RUN TestService_RequireScope_OIDC/builder_may_write1797=== PAUSE TestService_RequireScope_OIDC/builder_may_write1798=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1799=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1800=== RUN TestService_RequireScope_OIDC/ops_may_admin1801=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1802=== RUN TestService_RequireScope_OIDC/ops_may_not_write1803=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1804=== RUN TestService_RequireScope_OIDC/reader_may_not_write1805=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1806=== RUN TestService_RequireScope_OIDC/static_token_may_admin1807=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1808=== RUN TestService_RequireScope_OIDC/static_token_may_write1809=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1810=== RUN TestService_RequireScope_OIDC/reader_may_read1811=== PAUSE TestService_RequireScope_OIDC/reader_may_read1812=== RUN TestService_RequireScope_OIDC/writer_implies_read1813=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1814=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1815=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1816=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1817=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1818=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1819=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1820=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1821=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1822=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1823=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1824=== CONT TestResolveDBConnectionString/flag_wins1825=== CONT TestResolveDBConnectionString/missing_file_is_an_error1826=== CONT TestResolveDBConnectionString/file_when_flag_empty1827=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1828=== CONT TestResolveDBConnectionString/nothing_configured1829=== CONT TestGCEndsOnShutdown/before_the_run1830--- PASS: TestResolveDBConnectionString (0.00s)1831 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1832 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1833 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1834 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1835 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)18362026/11/04 20:13:52 INFO Received uploads request method=POST path=/api/pending_closures18372026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures1838=== NAME TestClientCADerivations1839 client_ca_test.go:139: Found 1 dependencies (including self)1840=== NAME TestClientWithDependencies1841 client_integration_test.go:662: Found 1 dependencies (including self)18422026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures18432026/11/04 20:13:53 INFO All 1 paths already cached1844=== NAME TestClientIntegration1845 client_integration_test.go:317: Retrieved narinfo from S3:1846 StorePath: /build/TestClientIntegration3150308156/002/store/vs42gvxc5ghldcf551imaf7yv29n15s7-test-file.txt1847 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1848 Compression: zstd1849 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11850 NarSize: 1521851 References: 1852 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11853 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1854 client_integration_test.go:318: Decompressed .ls content (64 bytes):1855 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}18562026/11/04 20:13:53 INFO Aborted multipart uploads count=0 kept=018572026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures18582026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures18592026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures18602026/11/04 20:13:53 INFO Received push request method=POST path=/api/pushes18612026/11/04 20:13:53 WARN Force mode enabled - objects will be deleted immediately without grace period18622026/11/04 20:13:53 INFO Received push request method=POST path=/api/pushes18632026/11/04 20:13:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18642026/11/04 20:13:53 INFO Uploading 6lal8ff76b85xgglp427rv8232r7307v-file1.txt (160B)18652026/11/04 20:13:53 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=018662026/11/04 20:13:53 INFO Vacuumed table table=pending_closures18672026/11/04 20:13:53 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18682026/11/04 20:13:53 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18692026/11/04 20:13:53 INFO Uploading 6qj8rq3nc65ywlfhqsppnkg0rs058spd-test-file-2.txt (160B)18702026/11/04 20:13:53 INFO Uploading 7l5piwgg6fy2cb523mr4178mj17xk3ml-test-file-1.txt (160B)18712026/11/04 20:13:53 INFO Uploading nink4vbn1xr9k1l5nvnsdp646236lsx0-test-file-0.txt (160B)18722026/11/04 20:13:53 INFO Vacuumed table table=pending_objects18732026/11/04 20:13:53 INFO Vacuumed table table=multipart_uploads18742026/11/04 20:13:53 INFO Vacuumed table table=closures18752026/11/04 20:13:53 INFO Vacuumed table table=objects18762026/11/04 20:13:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18772026/11/04 20:13:53 WARN Failed to register uploaded object key=6lal8ff76b85xgglp427rv8232r7307v.ls error="server returned 404: 404 page not found\n"18782026/11/04 20:13:53 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18792026/11/04 20:13:53 WARN Failed to register uploaded object key=7l5piwgg6fy2cb523mr4178mj17xk3ml.ls error="server returned 404: 404 page not found\n"18802026/11/04 20:13:53 INFO Signed narinfos id=1 count=118812026/11/04 20:13:53 WARN Failed to register uploaded object key=6qj8rq3nc65ywlfhqsppnkg0rs058spd.ls error="server returned 404: 404 page not found\n"18822026/11/04 20:13:53 INFO Uploading 1 narinfos18832026/11/04 20:13:53 WARN Failed to register uploaded object key=nink4vbn1xr9k1l5nvnsdp646236lsx0.ls error="server returned 404: 404 page not found\n"18842026/11/04 20:13:53 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18852026/11/04 20:13:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18862026/11/04 20:13:53 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18872026/11/04 20:13:53 INFO Signed narinfos id=1 count=318882026/11/04 20:13:53 INFO Uploading 3 narinfos18892026/11/04 20:13:53 INFO Received complete push request method=POST path=/api/pushes/1/complete18902026/11/04 20:13:53 WARN Failed to register uploaded object key=6lal8ff76b85xgglp427rv8232r7307v.narinfo error="server returned 404: 404 page not found\n"18912026/11/04 20:13:53 WARN Failed to register uploaded object key=nink4vbn1xr9k1l5nvnsdp646236lsx0.narinfo error="server returned 404: 404 page not found\n"1892--- PASS: TestGCSweepSkipsPendingObjects (0.98s)1893=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18942026/11/04 20:13:53 WARN Failed to register uploaded object key=6qj8rq3nc65ywlfhqsppnkg0rs058spd.narinfo error="server returned 404: 404 page not found\n"18952026/11/04 20:13:53 INFO Received complete push request method=POST path=/api/pushes/1/complete18962026/11/04 20:13:53 INFO Completed push id=1 objects=3 duration=7.023346ms18972026/11/04 20:13:53 WARN Failed to register uploaded object key=7l5piwgg6fy2cb523mr4178mj17xk3ml.narinfo error="server returned 404: 404 page not found\n"18982026/11/04 20:13:53 INFO Upload complete. (186ms)1899=== NAME TestNARDeduplicationMetadataUploadBug1900 metadata_upload_test.go:54: Retrieved narinfo from S3:1901 StorePath: /build/TestNARDeduplicationMetadataUploadBug1326231200/001/store/6lal8ff76b85xgglp427rv8232r7307v-file1.txt1902 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1903 Compression: zstd1904 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1905 NarSize: 1601906 References: 1907 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1908 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1909 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1910 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}19112026/11/04 20:13:53 INFO Completed push id=1 objects=9 duration=10.269855ms19122026/11/04 20:13:53 INFO Upload complete. (448ms)1913=== NAME TestClientMultipleUploads1914 client_integration_test.go:416: Uploaded 3 paths in 691.604305ms1915--- PASS: TestClientMultipleUploads (1.36s)1916=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1917=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19182026/11/04 20:13:53 INFO Received uploads request method=POST path=/1919=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19202026/11/04 20:13:53 INFO Received request for more parts method=POST path=/1921=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19222026/11/04 20:13:53 INFO Received complete multipart upload request method=POST path=/1923=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19242026/11/04 20:13:53 INFO Received uploads request method=POST path=/1925--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1926 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1927 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1928 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1929 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1930=== CONT TestServerTLSConfig/no_client_CA1931=== CONT TestServerTLSConfig/not_a_PEM_file1932=== CONT TestServerTLSConfig/missing_CA_file1933--- PASS: TestServerTLSConfig (0.00s)1934 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1935 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1936 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1937=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19382026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures19392026/11/04 20:13:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1940=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19412026/11/04 20:13:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLjhhNjNiNjFiLTc2YjItNGY2YS04MmM5LTQ0MmIzNDkxZmVhMXgxNzkzODIzMjMyOTE3MjIxNjM5 parts=101942=== NAME TestOrphanedObjectsGCStressTest1943 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19442026/11/04 20:13:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19452026/11/04 20:13:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19462026/11/04 20:13:53 INFO Completed upload id=1 objects=3 duration=4.221979ms19472026/11/04 20:13:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLjk0YjBkZDMyLWRlZjktNGQzZS1hYjkxLTNkMTIxZDA3ZTBkZngxNzkzODIzMjMzMDgyMTY5NDQ2 parts=1019482026/11/04 20:13:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19492026/11/04 20:13:53 INFO Completed upload id=1 objects=3 duration=9.430287ms19502026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures19512026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures19522026/11/04 20:13:53 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst19532026/11/04 20:13:53 WARN Found objects in DB but missing from S3, will re-upload count=11954=== CONT TestCacheConfigHandler/full_config,_no_issuer1955=== CONT TestCacheConfigHandler/no_signing_keys1956=== CONT TestCacheConfigHandler/no_cache_url_configured1957=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1958--- PASS: TestCacheConfigHandler (0.00s)1959 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1960 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1961 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1962 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1963=== CONT TestClientErrorHandling/InvalidStorePath19642026/11/04 20:13:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19652026/11/04 20:13:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLjQ1ZTEwYzYwLTk2MzUtNDE1Zi04ZmQxLWJhN2FhZjNiZDIzYngxNzkzODIzMjMzMTEwODg4NDMy parts=1019662026/11/04 20:13:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19672026/11/04 20:13:53 INFO Completed upload id=1 objects=3 duration=3.932716ms19682026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures1969--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1970 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1971 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1972 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.99s)1973=== CONT TestClientErrorHandling/ServerNotAvailable19742026/11/04 20:13:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19752026/11/04 20:13:53 INFO Received push request method=POST path=/api/pushes19762026/11/04 20:13:53 INFO Received push request method=POST path=/api/pushes1977=== NAME TestNARDeduplicationMetadataUploadBug1978 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1326231200/001/store/s83bgdm79k8x394d2zkkv1y39gjgdrmw-file2.txt1979=== NAME TestOrphanedObjectsGCStressTest1980 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion19812026/11/04 20:13:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19822026/11/04 20:13:53 INFO Uploading ymya185klnbmgldy8xwdhsc3978hvrh7-test-script (136B)19832026/11/04 20:13:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLjFjNDFlMWM4LWZiNGMtNGJmYS1iMmFjLWI5OTgyNmU2NjljY3gxNzkzODIzMjMzMTYyNjEwOTkx parts=1019842026/11/04 20:13:53 INFO Object in database but missing from S3 key=vs42gvxc5ghldcf551imaf7yv29n15s7.ls19852026/11/04 20:13:53 WARN Found objects in DB but missing from S3, will re-upload count=119862026/11/04 20:13:53 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19872026/11/04 20:13:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19882026/11/04 20:13:53 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19892026/11/04 20:13:53 INFO Received complete push request method=POST path=/api/pushes/2/complete19902026/11/04 20:13:53 WARN Failed to register uploaded object key=ymya185klnbmgldy8xwdhsc3978hvrh7.ls error="server returned 404: 404 page not found\n"19912026/11/04 20:13:53 INFO Completed upload id=1 objects=3 duration=7.441309ms19922026/11/04 20:13:53 INFO Completed push id=2 objects=3 duration=4.728024ms19932026/11/04 20:13:53 INFO Upload complete. (374ms)19942026/11/04 20:13:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19952026/11/04 20:13:53 WARN Failed to register uploaded object key=log/3bf6zqpd72mwzmxwwsdcxqjfywwl7s2s-test-script.drv error="server returned 404: 404 page not found\n"19962026/11/04 20:13:53 WARN Failed to register uploaded object key=vs42gvxc5ghldcf551imaf7yv29n15s7.ls error="server returned 404: 404 page not found\n"19972026/11/04 20:13:53 INFO Signed narinfos id=1 count=119982026/11/04 20:13:53 INFO Uploading 1 narinfos1999=== NAME TestClientIntegration2000 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)2001 client_integration_test.go:335: Decompressed .ls content (49 bytes):2002 {"version":1,"root":{"type":"regular","size":39}}20032026/11/04 20:13:53 INFO Received complete push request method=POST path=/api/pushes/1/complete20042026/11/04 20:13:53 WARN Failed to register uploaded object key=ymya185klnbmgldy8xwdhsc3978hvrh7.narinfo error="server returned 404: 404 page not found\n"20052026/11/04 20:13:53 INFO Completed push id=1 objects=4 duration=9.395387ms20062026/11/04 20:13:53 INFO Upload complete. (374ms)2007=== NAME TestClientWithDependencies2008 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1769637736/001/store) requires matching store prefix2009--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2010 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.76s)2011 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (1.02s)2012=== CONT TestClientErrorHandling/InvalidAuthToken2013--- PASS: TestClientWithDependencies (1.81s)2014=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20152026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures2016=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20172026/11/04 20:13:53 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]2018=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20192026/11/04 20:13:53 WARN Authentication failed token_preview=eyJhbGciOi...EyCrxPMSlQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2020=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2021=== CONT TestService_RequireScope_OIDC/builder_may_write2022--- PASS: TestService_AuthMiddleware_OIDC (0.42s)2023 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2024 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2025 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2026 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)20272026/11/04 20:13:53 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst20282026/11/04 20:13:53 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo2029=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2030=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20312026/11/04 20:13:53 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]2032=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2033=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2034=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2035=== CONT TestService_RequireScope_OIDC/writer_implies_read2036=== CONT TestService_RequireScope_OIDC/reader_may_read2037=== CONT TestService_RequireScope_OIDC/static_token_may_write2038=== CONT TestService_RequireScope_OIDC/static_token_may_admin2039=== CONT TestService_RequireScope_OIDC/reader_may_not_write2040=== CONT TestService_RequireScope_OIDC/ops_may_not_write2041=== CONT TestService_RequireScope_OIDC/ops_may_admin2042=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2043--- PASS: TestService_RequireScope_OIDC (0.43s)2044 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2045 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2046 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2047 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2048 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2049 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2050 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2051 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2052 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2053 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2054 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2055 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2056 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2057 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20582026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures20592026/11/04 20:13:53 INFO Aborted multipart uploads count=0 kept=020602026/11/04 20:13:53 INFO Aborted multipart uploads count=0 kept=020612026/11/04 20:13:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20622026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures20632026/11/04 20:13:53 INFO Aborted multipart uploads count=0 kept=020642026/11/04 20:13:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLmY0ZjZmNmNhLWE5NGYtNGIwYi1iNzNjLWM2Mzc1YWRmYTRmZXgxNzkzODIzMjMzMzU3NDIzMTE1 parts=1020652026/11/04 20:13:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20662026/11/04 20:13:53 INFO Completed upload id=1 objects=3 duration=5.881494ms20672026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures20682026/11/04 20:13:53 INFO Aborted multipart uploads count=0 kept=020692026/11/04 20:13:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20702026/11/04 20:13:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLjdkOTlmMDQxLWNjMjctNDAzZS04MmVlLTIwNTU0YWNlN2Q3NHgxNzkzODIzMjMzNDc5NDgwMjI1 parts=1020712026/11/04 20:13:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20722026/11/04 20:13:53 INFO Completed upload id=2 objects=3 duration=1.180351ms20732026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures20742026/11/04 20:13:53 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst20752026/11/04 20:13:53 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2076--- PASS: TestPendingClosureWriteTimeout (0.00s)2077 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2078 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2079 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2080 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.35s)20812026/11/04 20:13:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20822026/11/04 20:13:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=ODI4MTIzN2QtNzkwMC00ZjNiLWE4NDAtZDk4MjgyZjI1MDcyLjE2MjdkM2ZjLWM1YjQtNGNmZi1iMjRlLTc4MWY0NDY0MGUzYngxNzkzODIzMjMzNTI3OTE3MDk0 parts=1020832026/11/04 20:13:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20842026/11/04 20:13:53 INFO Completed upload id=2 objects=3 duration=805.147µs20852026/11/04 20:13:53 WARN Force mode enabled - objects will be deleted immediately without grace period20862026/11/04 20:13:53 WARN Force mode enabled - objects will be deleted immediately without grace period20872026/11/04 20:13:53 WARN Force mode enabled - objects will be deleted immediately without grace period20882026/11/04 20:13:53 WARN Force mode enabled - objects will be deleted immediately without grace period20892026/11/04 20:13:53 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=020902026/11/04 20:13:53 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:41923/bucket101/?delete=\": context canceled"20912026/11/04 20:13:53 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20922026/11/04 20:13:53 INFO Vacuumed table table=pending_closures20932026/11/04 20:13:53 INFO Vacuumed table table=pending_objects20942026/11/04 20:13:53 INFO Vacuumed table table=multipart_uploads20952026/11/04 20:13:53 INFO Vacuumed table table=closures20962026/11/04 20:13:53 INFO Vacuumed table table=objects20972026/11/04 20:13:53 WARN Rate limiter enabled after throttle name=s3-test rate=520982026/11/04 20:13:53 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2099=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2100 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102101 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002102--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.17s)2103--- PASS: TestGCEndsOnShutdown (0.00s)2104 --- PASS: TestGCEndsOnShutdown/before_the_run (0.41s)2105 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.65s)2106 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.64s)21072026/11/04 20:13:53 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=021082026/11/04 20:13:53 INFO Received uploads request method=POST path=/api/pending_closures21092026/11/04 20:13:53 INFO Vacuumed table table=pending_closures21102026/11/04 20:13:53 INFO Vacuumed table table=pending_objects21112026/11/04 20:13:53 INFO Vacuumed table table=multipart_uploads21122026/11/04 20:13:53 INFO Vacuumed table table=closures21132026/11/04 20:13:53 INFO Vacuumed table table=objects21142026/11/04 20:13:53 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21152026/11/04 20:13:53 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2116--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.00s)2117 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.84s)2118 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (1.04s)2119 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (1.07s)2120 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.17s)2121 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.25s)2122--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2123 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.53s)2124 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.61s)21252026/11/04 20:13:53 INFO Received push request method=POST path=/api/pushes21262026/11/04 20:13:53 INFO lead: released remote=192.0.2.1:12342127--- PASS: TestLeadElectsOneAndHandsOver (3.03s)21282026/11/04 20:13:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21292026/11/04 20:13:53 INFO Uploading swq0rf8ryncxm93x8v47y7dsh2fp37f8-ca-test (144B)21302026/11/04 20:13:53 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21312026/11/04 20:13:53 WARN Failed to register uploaded object key=swq0rf8ryncxm93x8v47y7dsh2fp37f8.ls error="server returned 404: 404 page not found\n"21322026/11/04 20:13:53 WARN Failed to register uploaded object key=log/frpywk0hgsi82r58r9g3m80yfh136789-ca-test.drv error="server returned 404: 404 page not found\n"21332026/11/04 20:13:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21342026/11/04 20:13:53 INFO Signed narinfos id=1 count=121352026/11/04 20:13:53 INFO Uploading 1 narinfos21362026/11/04 20:13:53 INFO Received complete push request method=POST path=/api/pushes/1/complete21372026/11/04 20:13:53 WARN Failed to register uploaded object key=swq0rf8ryncxm93x8v47y7dsh2fp37f8.narinfo error="server returned 404: 404 page not found\n"21382026/11/04 20:13:53 INFO Completed push id=1 objects=4 duration=6.306438ms21392026/11/04 20:13:53 INFO Upload complete. (757ms)2140=== NAME TestClientCADerivations2141 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1988960892/001/store/swq0rf8ryncxm93x8v47y7dsh2fp37f8-ca-test2142 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2143 Compression: zstd2144 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2145 NarSize: 1442146 References: 2147 Deriver: /build/TestClientCADerivations1988960892/001/store/frpywk0hgsi82r58r9g3m80yfh136789-ca-test.drv2148 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2149 client_ca_test.go:185: Checking for realisation files in S3...21502026/11/04 20:13:53 WARN Request failed, retrying attempt=2 backoff=182.484549ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21512026/11/04 20:13:54 INFO Received push request method=POST path=/api/pushes2152 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2153 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21542026/11/04 20:13:54 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21552026/11/04 20:13:54 INFO Received push request method=POST path=/api/pushes21562026/11/04 20:13:54 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21572026/11/04 20:13:54 WARN Failed to register uploaded object key=s83bgdm79k8x394d2zkkv1y39gjgdrmw.ls error="server returned 404: 404 page not found\n"21582026/11/04 20:13:54 INFO Signed narinfos id=2 count=121592026/11/04 20:13:54 INFO Uploading 1 narinfos21602026/11/04 20:13:54 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21612026/11/04 20:13:54 INFO Received complete push request method=POST path=/api/pushes/2/complete21622026/11/04 20:13:54 WARN Failed to register uploaded object key=s83bgdm79k8x394d2zkkv1y39gjgdrmw.narinfo error="server returned 404: 404 page not found\n"21632026/11/04 20:13:54 INFO Received complete push request method=POST path=/api/pushes/3/complete21642026/11/04 20:13:54 WARN Failed to register uploaded object key=vs42gvxc5ghldcf551imaf7yv29n15s7.ls error="server returned 404: 404 page not found\n"21652026/11/04 20:13:54 INFO Completed push id=2 objects=3 duration=3.641954ms21662026/11/04 20:13:54 INFO Upload complete. (140ms)21672026/11/04 20:13:54 INFO Completed push id=3 objects=3 duration=3.306771ms21682026/11/04 20:13:54 INFO Upload complete. (140ms)2169=== NAME TestClientIntegration2170 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)2171=== NAME TestNARDeduplicationMetadataUploadBug2172 metadata_upload_test.go:76: Retrieved narinfo from S3:2173 StorePath: /build/TestNARDeduplicationMetadataUploadBug1326231200/001/store/s83bgdm79k8x394d2zkkv1y39gjgdrmw-file2.txt2174 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2175 Compression: zstd2176 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2177 NarSize: 1602178 References: 2179 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2180=== NAME TestClientIntegration2181 client_integration_test.go:352: Decompressed .ls content (49 bytes):2182 {"version":1,"root":{"type":"regular","size":39}}2183 client_integration_test.go:363: Testing garbage collection...2184=== NAME TestNARDeduplicationMetadataUploadBug2185 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2186 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2187 {"version":1,"root":{"type":"regular","size":44}}2188--- PASS: TestNARDeduplicationMetadataUploadBug (1.85s)21892026/11/04 20:13:54 WARN Request failed, retrying attempt=3 backoff=388.464715ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21902026/11/04 20:13:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2191--- PASS: TestDeleteClosuresRacingPins (3.19s)21922026/11/04 20:13:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures21932026/11/04 20:13:54 INFO Garbage collection started21942026/11/04 20:13:54 INFO Aborted multipart uploads count=0 kept=02195=== NAME TestOrphanedObjectsGCStressTest2196 orphaned_objects_gc_test.go:503: Stress test completed successfully:2197 orphaned_objects_gc_test.go:504: - Active objects preserved: 202198 orphaned_objects_gc_test.go:505: - Objects deleted: 2102199 orphaned_objects_gc_test.go:506: - Total GC'd: 2102200--- PASS: TestOrphanedObjectsGCStressTest (4.01s)22012026/11/04 20:13:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022022026/11/04 20:13:54 INFO Received create pin request method=POST path=/api/pins/myapp22032026/11/04 20:13:54 WARN Force mode enabled - objects will be deleted immediately without grace period22042026/11/04 20:13:54 WARN Request failed, retrying attempt=4 backoff=829.930626ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22052026/11/04 20:13:54 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3696246317/001/store/0zaaw2raqw8zfrcp985bf2nsvrncjwss-pinned-file.txt narinfo_key=0zaaw2raqw8zfrcp985bf2nsvrncjwss.narinfo22062026/11/04 20:13:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures22072026/11/04 20:13:54 INFO Garbage collection started22082026/11/04 20:13:54 INFO Aborted multipart uploads count=0 kept=022092026/11/04 20:13:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22102026/11/04 20:13:54 WARN Force mode enabled - objects will be deleted immediately without grace period22112026/11/04 20:13:54 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=022122026/11/04 20:13:54 INFO Vacuumed table table=pending_closures22132026/11/04 20:13:54 INFO Vacuumed table table=pending_objects22142026/11/04 20:13:54 INFO Vacuumed table table=multipart_uploads22152026/11/04 20:13:54 INFO Vacuumed table table=closures22162026/11/04 20:13:54 INFO Vacuumed table table=objects22172026/11/04 20:13:54 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=022182026/11/04 20:13:54 INFO Vacuumed table table=pending_closures22192026/11/04 20:13:54 INFO Vacuumed table table=pending_objects22202026/11/04 20:13:54 INFO Vacuumed table table=multipart_uploads22212026/11/04 20:13:54 INFO Vacuumed table table=closures22222026/11/04 20:13:54 INFO Vacuumed table table=objects2223--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.02s)22242026/11/04 20:13:55 WARN Request failed, retrying attempt=5 backoff=1.509745655s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2225=== NAME TestClientCADerivations2226 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2227 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2228 error: binary cache 's3://bucket81?endpoint=http://localhost:41923®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1988960892/001/store'2229 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12230--- PASS: TestClientCADerivations (3.42s)2231--- PASS: TestConnectWaitsForAPeerMigration (5.15s)22322026/11/04 20:13:56 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02233=== NAME TestClientIntegration2234 client_integration_test.go:370: Objects in database after GC:2235 client_integration_test.go:370: Successfully deleted all objects with GC --force2236--- PASS: TestClientIntegration (4.23s)2237=== NAME TestPinProtectsFromGC2238 client_integration_test.go:887: Pin successfully protected closure from garbage collection2239--- PASS: TestPinProtectsFromGC (5.47s)22402026/11/04 20:13:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22412026/11/04 20:13:57 WARN Request failed, retrying attempt=2 backoff=205.285787ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22422026/11/04 20:13:57 WARN Request failed, retrying attempt=3 backoff=383.326113ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22432026/11/04 20:13:57 WARN Request failed, retrying attempt=4 backoff=864.530644ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22442026/11/04 20:13:57 INFO Aborted multipart uploads count=1 kept=022452026/11/04 20:13:57 INFO Received cleanup request method=DELETE path=/api/pending_closures22462026/11/04 20:13:57 INFO Aborted multipart uploads count=1 kept=02247--- PASS: TestPendingCleanupUsesOneCutoff (6.54s)22482026/11/04 20:13:58 WARN Request failed, retrying attempt=5 backoff=1.722708606s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22492026/11/04 20:14:00 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"22502026/11/04 20:14:00 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22512026/11/04 20:14:00 WARN Request failed, retrying attempt=2 backoff=214.985093ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22522026/11/04 20:14:00 WARN Request failed, retrying attempt=3 backoff=378.882818ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22532026/11/04 20:14:00 WARN Request failed, retrying attempt=4 backoff=768.746103ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22542026/11/04 20:14:01 WARN Request failed, retrying attempt=5 backoff=1.582659107s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22552026/11/04 20:14:03 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22562026/11/04 20:14:03 WARN Request failed, retrying attempt=2 backoff=216.757554ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22572026/11/04 20:14:03 WARN Request failed, retrying attempt=3 backoff=370.51179ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22582026/11/04 20:14:03 WARN Request failed, retrying attempt=4 backoff=877.734032ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22592026/11/04 20:14:04 WARN Request failed, retrying attempt=5 backoff=1.64615867s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2260--- PASS: TestClientErrorHandling (0.00s)2261 --- PASS: TestClientErrorHandling/InvalidStorePath (0.53s)2262 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.93s)2263 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.00s)2264PASS2265{"timestamp":"2026-11-04T20:14:06.535381169Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:46008","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(195)"}2266{"timestamp":"2026-11-04T20:14:06.535384349Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:47296","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(196)"}2267{"timestamp":"2026-11-04T20:14:06.535384429Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:47336","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(208)"}2268{"timestamp":"2026-11-04T20:14:06.535382989Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:47244","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(206)"}22692026-11-04 20:14:06.781 UTC [128] LOG: received smart shutdown request22702026-11-04 20:14:06.792 UTC [128] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122712026-11-04 20:14:06.802 UTC [133] LOG: shutting down22722026-11-04 20:14:06.803 UTC [133] LOG: checkpoint starting: shutdown immediate22732026-11-04 20:14:07.907 UTC [133] LOG: checkpoint complete: wrote 10989 buffers (67.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.278 s, sync=0.776 s, total=1.105 s; sync files=35725, longest=0.008 s, average=0.001 s; distance=516934 kB, estimate=516934 kB; lsn=0/210376A8, redo lsn=0/210376A822742026-11-04 20:14:07.994 UTC [128] LOG: database system is shut down2275Running OIDC tests...2276=== RUN TestAudienceForIssuer2277=== PAUSE TestAudienceForIssuer2278=== RUN TestGlobMatch2279=== PAUSE TestGlobMatch2280=== RUN TestValidateToken_ValidToken2281=== PAUSE TestValidateToken_ValidToken2282=== RUN TestValidateToken_WrongAudience2283=== PAUSE TestValidateToken_WrongAudience2284=== RUN TestValidateToken_Expired2285=== PAUSE TestValidateToken_Expired2286=== RUN TestValidateToken_BoundClaimsMismatch2287=== PAUSE TestValidateToken_BoundClaimsMismatch2288=== RUN TestValidateToken_BoundSubjectMismatch2289=== PAUSE TestValidateToken_BoundSubjectMismatch2290=== RUN TestValidateToken_MultipleProviders2291=== PAUSE TestValidateToken_MultipleProviders2292=== RUN TestValidateToken_NoMatchingProvider2293=== PAUSE TestValidateToken_NoMatchingProvider2294=== RUN TestValidateToken_KubernetesServiceAccount2295=== PAUSE TestValidateToken_KubernetesServiceAccount2296=== RUN TestNewValidator_KubernetesRequiresCA2297=== PAUSE TestNewValidator_KubernetesRequiresCA2298=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2299=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2300=== RUN TestPins_ReservedForMatchingRule2301=== PAUSE TestPins_ReservedForMatchingRule2302=== RUN TestPins_TopLevelShorthand2303=== PAUSE TestPins_TopLevelShorthand2304=== RUN TestPins_ConfigValidation2305=== PAUSE TestPins_ConfigValidation2306=== RUN TestScopes_LegacyProviderDefaultsToWrite2307=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2308=== RUN TestScopes_Rules2309=== PAUSE TestScopes_Rules2310=== RUN TestScopes_ConfigValidation2311=== PAUSE TestScopes_ConfigValidation2312=== CONT TestAudienceForIssuer2313--- PASS: TestAudienceForIssuer (0.00s)2314=== CONT TestValidateToken_NoMatchingProvider2315=== CONT TestValidateToken_KubernetesServiceAccount2316=== CONT TestPins_ConfigValidation2317=== CONT TestValidateToken_Expired2318=== CONT TestValidateToken_ValidToken2319=== CONT TestScopes_Rules2320--- PASS: TestPins_ConfigValidation (0.00s)2321=== CONT TestScopes_LegacyProviderDefaultsToWrite2322=== CONT TestPins_ReservedForMatchingRule2323=== CONT TestValidateToken_WrongAudience2324=== CONT TestScopes_ConfigValidation2325--- PASS: TestScopes_ConfigValidation (0.00s)2326=== CONT TestPins_TopLevelShorthand2327=== CONT TestGlobMatch2328=== RUN TestGlobMatch/foo_foo2329=== PAUSE TestGlobMatch/foo_foo2330=== RUN TestGlobMatch/foo_bar2331=== PAUSE TestGlobMatch/foo_bar2332=== RUN TestGlobMatch/*_2333=== PAUSE TestGlobMatch/*_2334=== RUN TestGlobMatch/*_anything2335=== PAUSE TestGlobMatch/*_anything2336=== RUN TestGlobMatch/foo*_foo2337=== PAUSE TestGlobMatch/foo*_foo2338=== RUN TestGlobMatch/foo*_foobar2339=== PAUSE TestGlobMatch/foo*_foobar2340=== RUN TestGlobMatch/foo*_bar2341=== PAUSE TestGlobMatch/foo*_bar2342=== RUN TestGlobMatch/*bar_bar2343=== PAUSE TestGlobMatch/*bar_bar2344=== RUN TestGlobMatch/*bar_foobar2345=== PAUSE TestGlobMatch/*bar_foobar2346=== RUN TestGlobMatch/*bar_foo2347=== PAUSE TestGlobMatch/*bar_foo2348=== RUN TestGlobMatch/foo*bar_foobar2349=== PAUSE TestGlobMatch/foo*bar_foobar2350=== RUN TestGlobMatch/foo*bar_foo123bar2351=== PAUSE TestGlobMatch/foo*bar_foo123bar2352=== RUN TestGlobMatch/foo*bar_foobarbaz2353=== PAUSE TestGlobMatch/foo*bar_foobarbaz2354=== RUN TestGlobMatch/*/*_foo/bar2355=== PAUSE TestGlobMatch/*/*_foo/bar2356=== RUN TestGlobMatch/*/*_foo2357=== PAUSE TestGlobMatch/*/*_foo2358=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2359=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2360=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02361=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02362=== RUN TestGlobMatch/refs/*/main_refs/heads/main2363=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2364=== RUN TestGlobMatch/fo?_foo2365=== PAUSE TestGlobMatch/fo?_foo2366=== RUN TestGlobMatch/fo?_fo2367=== PAUSE TestGlobMatch/fo?_fo2368=== RUN TestGlobMatch/fo?_fooo2369=== PAUSE TestGlobMatch/fo?_fooo2370=== RUN TestGlobMatch/?oo_foo2371=== PAUSE TestGlobMatch/?oo_foo2372=== RUN TestGlobMatch/?oo_boo2373=== PAUSE TestGlobMatch/?oo_boo2374=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2375=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2376=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2377=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2378=== CONT TestGlobMatch/foo_foo2379=== CONT TestValidateToken_MultipleProviders2380=== CONT TestValidateToken_BoundSubjectMismatch2381=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2382=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2383=== CONT TestGlobMatch/?oo_boo2384=== CONT TestGlobMatch/?oo_foo2385=== CONT TestGlobMatch/fo?_fooo2386=== CONT TestGlobMatch/fo?_fo2387=== CONT TestGlobMatch/fo?_foo2388=== CONT TestGlobMatch/refs/*/main_refs/heads/main2389=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02390=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2391=== CONT TestValidateToken_BoundClaimsMismatch2392=== CONT TestGlobMatch/*_anything2393=== CONT TestGlobMatch/*bar_foobar2394=== CONT TestGlobMatch/*bar_bar2395=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2396=== CONT TestNewValidator_KubernetesRequiresCA2397=== CONT TestGlobMatch/*/*_foo2398=== CONT TestGlobMatch/foo*_foo2399=== CONT TestGlobMatch/*/*_foo/bar2400=== CONT TestGlobMatch/foo*bar_foobarbaz2401=== CONT TestGlobMatch/foo*_bar2402=== CONT TestGlobMatch/*_2403=== CONT TestGlobMatch/foo*bar_foo123bar2404=== CONT TestGlobMatch/foo_bar2405=== CONT TestGlobMatch/foo*bar_foobar2406=== CONT TestGlobMatch/*bar_foo2407=== CONT TestGlobMatch/foo*_foobar2408--- PASS: TestGlobMatch (0.00s)2409 --- PASS: TestGlobMatch/foo_foo (0.00s)2410 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2411 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2412 --- PASS: TestGlobMatch/?oo_boo (0.00s)2413 --- PASS: TestGlobMatch/?oo_foo (0.00s)2414 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2415 --- PASS: TestGlobMatch/fo?_fo (0.00s)2416 --- PASS: TestGlobMatch/fo?_foo (0.00s)2417 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2418 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2419 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2420 --- PASS: TestGlobMatch/*_anything (0.00s)2421 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2422 --- PASS: TestGlobMatch/*bar_bar (0.00s)2423 --- PASS: TestGlobMatch/*/*_foo (0.00s)2424 --- PASS: TestGlobMatch/foo*_foo (0.00s)2425 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2426 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2427 --- PASS: TestGlobMatch/foo*_bar (0.00s)2428 --- PASS: TestGlobMatch/*_ (0.00s)2429 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2430 --- PASS: TestGlobMatch/foo_bar (0.00s)2431 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2432 --- PASS: TestGlobMatch/*bar_foo (0.00s)2433 --- PASS: TestGlobMatch/foo*_foobar (0.00s)24342026/11/04 20:14:10 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324352026/11/04 20:14:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40303/oidc2436--- PASS: TestPins_TopLevelShorthand (0.28s)2437--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.12s)24382026/11/04 20:14:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37399/oidc2439--- PASS: TestValidateToken_Expired (0.31s)24402026/11/04 20:14:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36453/oidc24412026/11/04 20:14:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40099/oidc24422026/11/04 20:14:10 http: TLS handshake error from 127.0.0.1:36206: remote error: tls: bad certificate2443--- PASS: TestNewValidator_KubernetesRequiresCA (0.20s)2444--- PASS: TestValidateToken_ValidToken (0.38s)2445--- PASS: TestScopes_Rules (0.38s)24462026/11/04 20:14:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42227/oidc2447--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.40s)24482026/11/04 20:14:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33901/oidc2449--- PASS: TestValidateToken_BoundClaimsMismatch (0.24s)24502026/11/04 20:14:10 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:365452451--- PASS: TestValidateToken_KubernetesServiceAccount (0.42s)24522026/11/04 20:14:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43695/oidc2453--- PASS: TestValidateToken_BoundSubjectMismatch (0.26s)24542026/11/04 20:14:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35115/oidc2455--- PASS: TestValidateToken_WrongAudience (0.43s)24562026/11/04 20:14:10 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45973/oidc24572026/11/04 20:14:10 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34235/oidc2458--- PASS: TestValidateToken_MultipleProviders (0.47s)24592026/11/04 20:14:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36577/oidc2460--- PASS: TestPins_ReservedForMatchingRule (0.59s)24612026/11/04 20:14:10 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39465/oidc2462--- PASS: TestValidateToken_NoMatchingProvider (0.73s)2463PASS2464Running hook tests...2465=== RUN TestSendPathsEmpty2466=== PAUSE TestSendPathsEmpty2467=== RUN TestQueueEnqueueAndFetch2468=== PAUSE TestQueueEnqueueAndFetch2469=== RUN TestQueueDeduplication2470=== PAUSE TestQueueDeduplication2471=== RUN TestQueueRemove2472=== PAUSE TestQueueRemove2473=== RUN TestQueueFetchBatchLimit2474=== PAUSE TestQueueFetchBatchLimit2475=== RUN TestQueueRetryMovesToBack2476=== PAUSE TestQueueRetryMovesToBack2477=== RUN TestQueueFetchRemoveLifecycle2478=== PAUSE TestQueueFetchRemoveLifecycle2479=== RUN TestQueueConcurrentWriters2480=== PAUSE TestQueueConcurrentWriters2481=== RUN TestQueueRemoveLargeClosure2482=== PAUSE TestQueueRemoveLargeClosure2483=== RUN TestServerClientIntegration2484--- PASS: TestServerClientIntegration (0.01s)2485=== RUN TestServerQueueError24862026/11/04 20:14:11 ERROR Failed to queue paths error="permission denied" count=12487--- PASS: TestServerQueueError (0.00s)2488=== RUN TestGetListenerSocketActivation2489 server_test.go:218: === RUN TestGetListenerSocketActivation2490 --- PASS: TestGetListenerSocketActivation (0.00s)2491 PASS2492 2493--- PASS: TestGetListenerSocketActivation (0.81s)2494=== RUN TestServerStalledClientDoesNotBlockShutdown2495=== PAUSE TestServerStalledClientDoesNotBlockShutdown2496=== RUN TestServerBacksOffOnAcceptErrors2497=== PAUSE TestServerBacksOffOnAcceptErrors2498=== RUN TestDrainIsolatesPoisonPath2499=== PAUSE TestDrainIsolatesPoisonPath2500=== RUN TestRunNotBlockedByPoisonHead2501=== PAUSE TestRunNotBlockedByPoisonHead2502=== RUN TestDrainGivesUpWhenServerDown2503=== PAUSE TestDrainGivesUpWhenServerDown2504=== RUN TestFailedPathPrunedByLaterClosure2505=== PAUSE TestFailedPathPrunedByLaterClosure2506=== RUN TestWorkerUploadsAndRemoves2507=== PAUSE TestWorkerUploadsAndRemoves2508=== RUN TestWorkerSkipsGCdPaths2509=== PAUSE TestWorkerSkipsGCdPaths2510=== RUN TestWorkerPrunesClosureDeps2511=== PAUSE TestWorkerPrunesClosureDeps2512=== RUN TestDrainTimeout2513=== PAUSE TestDrainTimeout2514=== RUN TestWorkerRemoveFailureIsNotProgress2515=== PAUSE TestWorkerRemoveFailureIsNotProgress2516=== RUN TestWorkerKeepsPathItCannotStat2517=== PAUSE TestWorkerKeepsPathItCannotStat2518=== CONT TestSendPathsEmpty2519--- PASS: TestSendPathsEmpty (0.00s)2520=== CONT TestServerStalledClientDoesNotBlockShutdown2521=== CONT TestDrainTimeout2522=== CONT TestWorkerKeepsPathItCannotStat2523=== CONT TestFailedPathPrunedByLaterClosure2524=== CONT TestWorkerRemoveFailureIsNotProgress2525=== CONT TestWorkerPrunesClosureDeps2526=== CONT TestWorkerSkipsGCdPaths2527=== CONT TestWorkerUploadsAndRemoves2528=== CONT TestQueueRetryMovesToBack2529=== CONT TestQueueRemoveLargeClosure2530=== CONT TestQueueConcurrentWriters2531=== CONT TestQueueFetchRemoveLifecycle2532=== CONT TestQueueRemove2533=== CONT TestQueueFetchBatchLimit2534=== CONT TestRunNotBlockedByPoisonHead2535=== CONT TestDrainGivesUpWhenServerDown2536=== CONT TestQueueDeduplication2537=== CONT TestQueueEnqueueAndFetch2538=== CONT TestDrainIsolatesPoisonPath2539=== CONT TestServerBacksOffOnAcceptErrors25402026/11/04 20:14:11 ERROR Accept failed error="too many open files"25412026/11/04 20:14:11 ERROR Accept failed error="too many open files"25422026/11/04 20:14:11 ERROR Accept failed error="too many open files"25432026/11/04 20:14:11 ERROR Accept failed error="too many open files"25442026/11/04 20:14:11 ERROR Accept failed error="too many open files"25452026/11/04 20:14:11 ERROR Accept failed error="too many open files"25462026/11/04 20:14:12 INFO Uploading batch count=425472026/11/04 20:14:12 ERROR Upload failed error="upload failed" count=425482026/11/04 20:14:12 INFO Upload queue status pending=225492026/11/04 20:14:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath656198808/002/bbb25502026/11/04 20:14:12 INFO Uploading batch count=125512026/11/04 20:14:12 ERROR Upload failed error="upload failed" count=125522026/11/04 20:14:12 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths635520120/002/nonexistent2553--- PASS: TestQueueFetchBatchLimit (0.16s)25542026/11/04 20:14:12 INFO Upload queue status pending=225552026/11/04 20:14:12 INFO Upload queue status pending=325562026/11/04 20:14:12 INFO Uploading batch count=125572026/11/04 20:14:12 INFO Uploading batch count=125582026/11/04 20:14:12 ERROR Upload failed error="upload failed" count=125592026/11/04 20:14:12 INFO Uploading batch count=125602026/11/04 20:14:12 ERROR Upload failed error="upload failed" count=125612026/11/04 20:14:12 INFO Uploading batch count=125622026/11/04 20:14:12 ERROR Upload failed error="upload failed" count=125632026/11/04 20:14:12 INFO Uploading batch count=225642026/11/04 20:14:12 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat497490004/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat497490004/002/locked/aaa: permission denied"25652026/11/04 20:14:12 INFO Uploading batch count=125662026/11/04 20:14:12 INFO Uploading batch count=125672026/11/04 20:14:12 ERROR Upload failed error="upload failed" count=125682026/11/04 20:14:12 INFO Uploading batch count=22569--- PASS: TestQueueRemove (0.17s)25702026/11/04 20:14:12 ERROR Drain finished with paths left in queue remaining=125712026/11/04 20:14:12 INFO Uploading batch count=12572--- PASS: TestQueueEnqueueAndFetch (0.17s)25732026/11/04 20:14:12 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat497490004/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat497490004/002/locked/aaa: permission denied"2574--- PASS: TestQueueDeduplication (0.17s)25752026/11/04 20:14:12 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat497490004/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat497490004/002/locked/aaa: permission denied"25762026/11/04 20:14:12 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1277106316/002/nonexistent2577--- PASS: TestQueueRetryMovesToBack (0.17s)25782026/11/04 20:14:12 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125792026/11/04 20:14:12 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1277106316/002/nonexistent25802026/11/04 20:14:12 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125812026/11/04 20:14:12 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1277106316/002/nonexistent2582--- PASS: TestQueueFetchRemoveLifecycle (0.18s)25832026/11/04 20:14:12 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125842026/11/04 20:14:12 ERROR Drain finished with paths left in queue remaining=12585--- PASS: TestWorkerRemoveFailureIsNotProgress (0.18s)25862026/11/04 20:14:12 ERROR Drain finished with paths left in queue remaining=125872026/11/04 20:14:12 INFO Upload queue status pending=225882026/11/04 20:14:12 INFO Uploading batch count=125892026/11/04 20:14:12 INFO Uploading batch count=225902026/11/04 20:14:12 ERROR Upload failed error="upload failed" count=225912026/11/04 20:14:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown614695091/002/a2592--- PASS: TestDrainIsolatesPoisonPath (0.18s)2593--- PASS: TestWorkerKeepsPathItCannotStat (0.18s)25942026/11/04 20:14:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown614695091/002/b25952026/11/04 20:14:12 INFO Uploading batch count=225962026/11/04 20:14:12 ERROR Upload failed error="upload failed" count=225972026/11/04 20:14:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown614695091/002/c25982026/11/04 20:14:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown614695091/002/d2599--- PASS: TestFailedPathPrunedByLaterClosure (0.18s)26002026/11/04 20:14:12 INFO Uploading batch count=226012026/11/04 20:14:12 ERROR Upload failed error="upload failed" count=226022026/11/04 20:14:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown614695091/002/e26032026/11/04 20:14:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown614695091/002/f26042026/11/04 20:14:12 ERROR Drain finished with paths left in queue remaining=102605--- PASS: TestDrainGivesUpWhenServerDown (0.18s)2606--- PASS: TestWorkerSkipsGCdPaths (0.18s)2607--- PASS: TestWorkerUploadsAndRemoves (0.19s)2608--- PASS: TestWorkerPrunesClosureDeps (0.20s)26092026/11/04 20:14:12 ERROR Failed to decode request error="read unix /build/hook594080165/test.sock->@: i/o timeout"26102026/11/04 20:14:12 ERROR Failed to write response error="write unix /build/hook594080165/test.sock->@: i/o timeout"2611--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)2612--- PASS: TestQueueConcurrentWriters (0.28s)2613--- PASS: TestQueueRemoveLargeClosure (0.30s)26142026/11/04 20:14:12 ERROR Accept failed error="too many open files"26152026/11/04 20:14:12 ERROR Upload failed error="context deadline exceeded" count=226162026/11/04 20:14:12 ERROR Drain finished with paths left in queue remaining=42617--- PASS: TestDrainTimeout (0.37s)26182026/11/04 20:14:12 ERROR Accept failed error="too many open files"2619--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26202026/11/04 20:14:13 INFO Uploading batch count=126212026/11/04 20:14:13 INFO Uploading batch count=126222026/11/04 20:14:13 INFO Uploading batch count=126232026/11/04 20:14:13 ERROR Upload failed error="upload failed" count=126242026/11/04 20:14:13 INFO Uploading batch count=126252026/11/04 20:14:13 ERROR Upload failed error="upload failed" count=126262026/11/04 20:14:13 INFO Uploading batch count=126272026/11/04 20:14:13 ERROR Upload failed error="upload failed" count=126282026/11/04 20:14:13 INFO Uploading batch count=126292026/11/04 20:14:13 ERROR Upload failed error="upload failed" count=126302026/11/04 20:14:13 ERROR Drain finished with paths left in queue remaining=12631--- PASS: TestRunNotBlockedByPoisonHead (1.18s)2632PASS2633Running signing tests...2634=== RUN TestExternalSigner2635=== PAUSE TestExternalSigner2636=== RUN TestExternalSignerWrongPublicKey2637=== PAUSE TestExternalSignerWrongPublicKey2638=== RUN TestExternalSignerErrors2639=== PAUSE TestExternalSignerErrors2640=== RUN TestExternalSignerRestartsAfterCrash2641=== PAUSE TestExternalSignerRestartsAfterCrash2642=== RUN TestExternalSignerProgramErrorKeepsProcess2643=== PAUSE TestExternalSignerProgramErrorKeepsProcess2644=== RUN TestExternalSignerClose2645=== PAUSE TestExternalSignerClose2646=== RUN TestExternalSignerRejectsInvalidPublicKey2647=== PAUSE TestExternalSignerRejectsInvalidPublicKey2648=== RUN TestExternalSignerCancellation2649=== PAUSE TestExternalSignerCancellation2650=== RUN TestGenerateFingerprint2651=== PAUSE TestGenerateFingerprint2652=== RUN TestParseSigningKey2653=== PAUSE TestParseSigningKey2654=== RUN TestSign2655=== PAUSE TestSign2656=== RUN TestSignBatch2657=== PAUSE TestSignBatch2658=== RUN TestNilKeyPublicKey2659=== PAUSE TestNilKeyPublicKey2660=== RUN TestSignErrors2661=== PAUSE TestSignErrors2662=== CONT TestExternalSigner2663=== CONT TestExternalSignerProgramErrorKeepsProcess2664=== CONT TestExternalSignerWrongPublicKey2665=== CONT TestExternalSignerCancellation2666=== CONT TestSignErrors2667=== CONT TestExternalSignerRejectsInvalidPublicKey2668=== RUN TestExternalSignerRejectsInvalidPublicKey/#002669=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002670=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2671=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2672=== CONT TestNilKeyPublicKey2673--- PASS: TestNilKeyPublicKey (0.00s)2674=== CONT TestSignBatch2675=== CONT TestSign2676=== CONT TestParseSigningKey2677=== RUN TestParseSigningKey/valid_32-byte_key2678=== PAUSE TestParseSigningKey/valid_32-byte_key2679=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2680=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2681=== RUN TestParseSigningKey/no_colon2682=== PAUSE TestParseSigningKey/no_colon2683=== RUN TestParseSigningKey/empty_name2684=== PAUSE TestParseSigningKey/empty_name2685=== RUN TestParseSigningKey/invalid_base642686=== PAUSE TestParseSigningKey/invalid_base642687=== RUN TestParseSigningKey/wrong_length2688=== PAUSE TestParseSigningKey/wrong_length2689=== CONT TestParseSigningKey/valid_32-byte_key2690=== CONT TestParseSigningKey/wrong_length2691=== CONT TestParseSigningKey/invalid_base642692=== CONT TestParseSigningKey/no_colon2693=== CONT TestGenerateFingerprint2694=== RUN TestGenerateFingerprint/basic_with_references2695=== PAUSE TestGenerateFingerprint/basic_with_references2696=== RUN TestGenerateFingerprint/no_references2697=== PAUSE TestGenerateFingerprint/no_references2698=== CONT TestExternalSignerErrors2699=== RUN TestExternalSignerErrors/exit_at_startup2700=== PAUSE TestExternalSignerErrors/exit_at_startup2701=== CONT TestExternalSignerRestartsAfterCrash2702=== CONT TestExternalSignerClose2703=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2704=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2705=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2706=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2707=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2708=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2709=== CONT TestExternalSignerRejectsInvalidPublicKey/#002710=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2711=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2712=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2713=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2714=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2715=== RUN TestGenerateFingerprint/invalid_nar_hash_length2716=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2717=== RUN TestGenerateFingerprint/invalid_store_path_prefix2718=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2719=== RUN TestGenerateFingerprint/invalid_reference_prefix2720=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2721=== CONT TestGenerateFingerprint/basic_with_references2722=== CONT TestParseSigningKey/empty_name2723=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2724=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2725=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2726=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2727--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2728 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2729 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2730 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2731 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2732 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2733=== CONT TestGenerateFingerprint/invalid_reference_prefix2734=== CONT TestGenerateFingerprint/invalid_store_path_prefix2735=== CONT TestGenerateFingerprint/invalid_nar_hash_length2736=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2737=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2738=== CONT TestGenerateFingerprint/no_references2739--- PASS: TestGenerateFingerprint (0.00s)2740 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2741 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2742 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2743 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2744 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2745 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2746 --- PASS: TestGenerateFingerprint/no_references (0.00s)2747=== RUN TestExternalSignerErrors/exit_on_request2748=== PAUSE TestExternalSignerErrors/exit_on_request2749=== RUN TestExternalSignerErrors/null2750=== PAUSE TestExternalSignerErrors/null2751=== RUN TestExternalSignerErrors/unrequested_key2752=== PAUSE TestExternalSignerErrors/unrequested_key2753=== RUN TestExternalSignerErrors/invalid_signature_base642754=== PAUSE TestExternalSignerErrors/invalid_signature_base642755=== RUN TestExternalSignerErrors/wrong_signature_length2756=== PAUSE TestExternalSignerErrors/wrong_signature_length2757=== RUN TestExternalSignerErrors/program_error2758=== PAUSE TestExternalSignerErrors/program_error2759=== RUN TestExternalSignerErrors/null_signatures2760=== PAUSE TestExternalSignerErrors/null_signatures2761=== RUN TestExternalSignerErrors/too_few_signatures2762=== PAUSE TestExternalSignerErrors/too_few_signatures2763=== RUN TestExternalSignerErrors/missing_signature_name2764=== PAUSE TestExternalSignerErrors/missing_signature_name2765=== RUN TestExternalSignerErrors/invalid_JSON2766=== PAUSE TestExternalSignerErrors/invalid_JSON2767=== RUN TestExternalSignerErrors/wrong_id2768=== PAUSE TestExternalSignerErrors/wrong_id2769=== RUN TestExternalSignerErrors/wrong_shape2770=== PAUSE TestExternalSignerErrors/wrong_shape2771=== RUN TestExternalSignerErrors/missing_signatures2772=== PAUSE TestExternalSignerErrors/missing_signatures2773=== RUN TestExternalSignerErrors/wrong_signatures_shape2774=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2775=== RUN TestExternalSignerErrors/wrong_signature_name2776=== PAUSE TestExternalSignerErrors/wrong_signature_name2777=== CONT TestExternalSignerErrors/exit_at_startup2778=== CONT TestExternalSignerErrors/too_few_signatures2779=== CONT TestExternalSignerErrors/unrequested_key2780=== CONT TestExternalSignerErrors/wrong_signature_name2781=== CONT TestExternalSignerErrors/wrong_signatures_shape2782=== CONT TestExternalSignerErrors/invalid_signature_base642783=== RUN TestSignErrors/nil_key2784=== PAUSE TestSignErrors/nil_key2785=== CONT TestExternalSignerErrors/null_signatures2786=== RUN TestSignErrors/nil_narinfo2787=== PAUSE TestSignErrors/nil_narinfo2788=== RUN TestSignErrors/invalid_narinfo2789=== PAUSE TestSignErrors/invalid_narinfo2790=== RUN TestSignErrors/canceled2791=== PAUSE TestSignErrors/canceled2792=== CONT TestSignErrors/nil_key2793=== CONT TestExternalSignerErrors/program_error2794=== CONT TestExternalSignerErrors/wrong_signature_length2795=== CONT TestExternalSignerErrors/exit_on_request2796=== CONT TestSignErrors/canceled2797=== CONT TestSignErrors/invalid_narinfo2798=== CONT TestSignErrors/nil_narinfo2799--- PASS: TestSignErrors (0.00s)2800 --- PASS: TestSignErrors/nil_key (0.00s)2801 --- PASS: TestSignErrors/canceled (0.00s)2802 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2803 --- PASS: TestSignErrors/nil_narinfo (0.00s)2804=== CONT TestExternalSignerErrors/wrong_id2805=== CONT TestExternalSignerErrors/invalid_JSON2806=== CONT TestExternalSignerErrors/missing_signatures2807--- PASS: TestSignBatch (0.00s)2808=== CONT TestExternalSignerErrors/missing_signature_name2809=== CONT TestExternalSignerErrors/wrong_shape2810--- PASS: TestSign (0.00s)2811=== CONT TestExternalSignerErrors/null2812--- PASS: TestParseSigningKey (0.00s)2813 --- PASS: TestParseSigningKey/wrong_length (0.00s)2814 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2815 --- PASS: TestParseSigningKey/no_colon (0.00s)2816 --- PASS: TestParseSigningKey/empty_name (0.00s)2817 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2818 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2819--- PASS: TestExternalSignerClose (0.01s)2820--- PASS: TestExternalSignerWrongPublicKey (0.01s)2821--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2822--- PASS: TestExternalSignerErrors (0.00s)2823 --- PASS: TestExternalSignerErrors/program_error (0.01s)2824 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2825 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2826 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2827 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2828 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2829 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2830 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2831 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2832 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2833 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2834 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2835 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2836 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2837 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2838 --- PASS: TestExternalSignerErrors/null (0.01s)2839--- PASS: TestExternalSigner (0.02s)2840--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)2841--- PASS: TestExternalSignerCancellation (0.02s)2842PASS2843Running OpenBao signer tests...2844=== RUN TestSign2845=== PAUSE TestSign2846=== RUN TestSignErrors2847=== PAUSE TestSignErrors2848=== RUN TestServe2849=== PAUSE TestServe2850=== RUN TestServeRejectsGarbage2851=== PAUSE TestServeRejectsGarbage2852=== CONT TestSign2853=== CONT TestSignErrors2854=== RUN TestSignErrors/http_error2855=== PAUSE TestSignErrors/http_error2856=== CONT TestServe2857=== CONT TestServeRejectsGarbage2858--- PASS: TestServeRejectsGarbage (0.00s)2859=== RUN TestSignErrors/invalid_json2860=== PAUSE TestSignErrors/invalid_json2861=== RUN TestSignErrors/no_prefix2862=== PAUSE TestSignErrors/no_prefix2863=== RUN TestSignErrors/invalid_base642864=== PAUSE TestSignErrors/invalid_base642865=== CONT TestSignErrors/http_error2866--- PASS: TestServe (0.00s)2867=== CONT TestSignErrors/no_prefix2868=== CONT TestSignErrors/invalid_json2869=== CONT TestSignErrors/invalid_base642870--- PASS: TestSign (0.05s)2871--- PASS: TestSignErrors (0.00s)2872 --- PASS: TestSignErrors/invalid_json (0.05s)2873 --- PASS: TestSignErrors/invalid_base64 (0.05s)2874 --- PASS: TestSignErrors/no_prefix (0.05s)2875 --- PASS: TestSignErrors/http_error (0.05s)2876PASS