niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #465
· raw
1tribuchet: building on jamie2Running 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_ReturnsAfterDroppedBody20=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestDoWithRetry_BodyReplayedViaGetBody117=== CONT TestDumpPathWriterError118=== CONT TestParsePathInfoJSON119=== RUN TestParsePathInfoJSON/Nix_format120=== PAUSE TestParsePathInfoJSON/Nix_format121=== RUN TestParsePathInfoJSON/Lix_format122=== PAUSE TestParsePathInfoJSON/Lix_format123=== RUN TestParsePathInfoJSON/empty_input124=== PAUSE TestParsePathInfoJSON/empty_input125=== RUN TestParsePathInfoJSON/whitespace_only126=== PAUSE TestParsePathInfoJSON/whitespace_only127=== RUN TestParsePathInfoJSON/invalid_JSON128=== PAUSE TestParsePathInfoJSON/invalid_JSON129=== CONT TestParsePathInfoJSONMultiplePaths130=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths131=== CONT TestFileTokenMissing132=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths133=== CONT TestResolveStorePath134=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer135=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths136=== CONT TestEncodeNixBase321372026/11/06 07:18:15 WARN Rate limiter enabled after throttle name=server-test rate=5138=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1392026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35247140=== CONT TestRateLimiterFeedback141=== CONT TestPathInfoCACompatibility142=== CONT TestPathInfoHashCompatibility143=== CONT TestGetStorePathHash144=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun145=== CONT TestFilterOversizedClosures146=== CONT TestConvertHashToNix32147=== CONT TestCaseHackSuffix148=== CONT TestSetClientTLS1492026/11/06 07:18:15 WARN Rate limiter enabled after throttle name=server-test rate=5150=== CONT TestScriptTokenEmptyCommand151=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica152=== CONT TestRegisterUploadedObjectReusesConnections153=== CONT TestScriptTokenScriptFails154=== CONT TestFileTokenEmpty155=== CONT TestEncodeNixBase32WithRealHash156--- PASS: TestFileTokenMissing (0.00s)157=== CONT TestStreamPushIsolatesFailures158=== RUN TestRateLimiterFeedback/429_enables_limiter159=== CONT TestFileTokenReadsAndCaches160=== CONT TestScriptTokenBadJSON161--- PASS: TestEncodeNixBase32WithRealHash (0.00s)162=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths163=== RUN TestPathInfoCACompatibility/null_ca_field164=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)165=== RUN TestGetStorePathHash/valid_store_path166=== RUN TestFilterOversizedClosures/no_limit_keeps_everything167=== RUN TestEncodeNixBase32/test_string_hash168--- PASS: TestDoServerRequestAttachesToken (0.00s)169=== PAUSE TestRateLimiterFeedback/429_enables_limiter170=== RUN TestRateLimiterFeedback/503_enables_limiter171--- PASS: TestScriptTokenEmptyCommand (0.00s)1722026/11/06 07:18:15 WARN Rate limiter backed off name=server-test rate=5173=== PAUSE TestPathInfoCACompatibility/null_ca_field174=== CONT TestStreamPushStopsWhenCanceled175--- PASS: TestResolveStorePath (0.00s)176--- PASS: TestFileTokenEmpty (0.00s)177--- PASS: TestFileTokenReadsAndCaches (0.00s)178=== RUN TestPathInfoCACompatibility/old_string_format_-_text179=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text180=== PAUSE TestEncodeNixBase32/test_string_hash181--- PASS: TestScriptTokenScriptFails (0.01s)1822026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:35247183=== CONT TestScriptTokenEmptyToken184=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything185=== CONT TestStaticToken186--- PASS: TestStaticToken (0.00s)187=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped188=== CONT TestScriptTokenCachesUntilRefresh189=== PAUSE TestRateLimiterFeedback/503_enables_limiter190--- PASS: TestStreamPushStopsWhenCanceled (0.00s)191=== CONT TestStreamPushReportsSkippedPaths192=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter193=== CONT TestClientSignaturesByStorePath194=== PAUSE TestGetStorePathHash/valid_store_path195=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive196=== RUN TestEncodeNixBase32/empty_input197=== CONT TestStreamPushReportsSignatures198=== RUN TestConvertHashToNix32/SRI_format_to_Nix32199=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped200=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32201=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)202=== CONT TestSetClientTLSErrors203=== RUN TestFilterOversizedClosures/all_closures_skipped204=== RUN TestConvertHashToNix32/already_Nix32_format205--- PASS: TestScriptTokenBadJSON (0.01s)206--- PASS: TestStreamPushReportsSkippedPaths (0.00s)207--- PASS: TestClientSignaturesByStorePath (0.00s)208=== PAUSE TestEncodeNixBase32/empty_input209--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)210=== CONT TestStreamPushGivesUpOnDeadServer211=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive212=== CONT TestShellSplitErrors213--- PASS: TestShellSplitErrors (0.00s)214=== CONT TestSetClientTLSDoesNotMutateDefaultTransport215=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry216=== CONT TestScriptTokenNoExpiryRerunsEveryCall2172026/11/06 07:18:15 ERROR Upload failed error="bad path" count=22182026/11/06 07:18:15 ERROR Upload failed error="connection refused" count=20219=== PAUSE TestFilterOversizedClosures/all_closures_skipped2202026/11/06 07:18:15 ERROR Server seems unavailable, giving up on batch untried=17221=== PAUSE TestConvertHashToNix32/already_Nix32_format222--- PASS: TestStreamPushIsolatesFailures (0.02s)223=== CONT TestStreamPushRequestLine224=== CONT TestStreamPushBatchesUnderLoad2252026/11/06 07:18:15 ERROR Upload failed error=boom count=1226=== CONT TestSupersededNARStillUploadsListing227=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter228--- PASS: TestStreamPushReportsSignatures (0.01s)229--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)230=== CONT TestDumpPathSingleFile2312026/11/06 07:18:15 INFO Garbage collection started2322026/11/06 07:18:15 INFO Garbage collection started233=== CONT TestStreamPushReportsEveryPath234=== RUN TestGetStorePathHash/basename_without_hyphen_should_error235--- PASS: TestStreamPushReportsEveryPath (0.00s)236=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error237=== CONT TestDumpPathMatchesNix238--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)2392026/11/06 07:18:15 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=0240=== CONT TestDoWithRetry_FinalResponseBodyReadable241--- PASS: TestScriptTokenEmptyToken (0.01s)242=== CONT TestPartSizeForNAR2432026/11/06 07:18:15 ERROR Upload failed error=boom count=12442026/11/06 07:18:15 WARN Rate limiter enabled after throttle name=server-test rate=52452026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:39875246=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon247=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon248=== RUN TestPathInfoCACompatibility/new_structured_format_-_text249=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text250=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false251=== RUN TestConvertHashToNix32/invalid_format252=== RUN TestSupersededNARStillUploadsListing/small_NAR253=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter2542026/11/06 07:18:15 WARN Garbage collection finished on another replica. Its statistics are not available here255=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter256=== RUN TestSetClientTLSErrors/missing_cert_file257=== PAUSE TestSetClientTLSErrors/missing_cert_file258=== RUN TestSetClientTLSErrors/missing_key_file2592026/11/06 07:18:15 WARN Rate limiter backed off name=server-test rate=5260=== RUN TestPartSizeForNAR/zero_stays_at_minimum261--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)262=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI263=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method264=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum265=== RUN TestPartSizeForNAR/small_stays_at_minimum266=== PAUSE TestPartSizeForNAR/small_stays_at_minimum267=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum268=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum269=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts270=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts271=== RUN TestPartSizeForNAR/1_TiB272=== PAUSE TestPartSizeForNAR/1_TiB273=== RUN TestPartSizeForNAR/5_TiB_S3_max_object274=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object275=== PAUSE TestSupersededNARStillUploadsListing/small_NAR276=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false277=== PAUSE TestConvertHashToNix32/invalid_format278=== CONT TestShellSplit279--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)280=== RUN TestSupersededNARStillUploadsListing/dump_cut_short281--- PASS: TestShellSplit (0.00s)282=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short2832026/11/06 07:18:15 WARN Rate limiter enabled after throttle name=s3-test rate=5284=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails2852026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:32961286=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails287=== RUN TestSetClientTLS/rejects_connection_without_client_cert288=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert289--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)290=== CONT TestRetryTimeoutOutlastsMaxRetries291=== CONT TestUploadMultipart_SupersededByPeer292=== RUN TestUploadMultipart_SupersededByPeer/exists293=== PAUSE TestUploadMultipart_SupersededByPeer/exists294=== RUN TestUploadMultipart_SupersededByPeer/missing295=== PAUSE TestUploadMultipart_SupersededByPeer/missing296=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method297=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI298=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512299=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512300=== RUN TestPartSizeForNAR/capped_at_5_GiB301=== CONT TestParsePathInfoJSON/invalid_JSON302=== PAUSE TestPartSizeForNAR/capped_at_5_GiB303=== CONT TestUploadMultipart_ReturnsAfterDroppedBody304=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths305=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths306=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error307=== CONT TestParsePathInfoJSON/Nix_format3082026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:41399309=== CONT TestUploadMultipart_PartsInParallel310--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)311=== CONT TestEncodeNixBase32/test_string_hash312=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA313=== PAUSE TestSetClientTLSErrors/missing_key_file314=== CONT TestParsePathInfoJSON/whitespace_only315=== CONT TestParsePathInfoJSON/empty_input316=== CONT TestParsePathInfoJSON/Lix_format317=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true318=== CONT TestEncodeNixBase32/empty_input319=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped320=== CONT TestFilterOversizedClosures/no_limit_keeps_everything3212026/11/06 07:18:15 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=2000322=== CONT TestRateLimiterFeedback/429_enables_limiter323=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter324--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)325=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3262026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:41399327--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)328 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)329 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)3302026/11/06 07:18:15 WARN Rate limiter enabled after throttle name=server-test rate=5331=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error332--- PASS: TestEncodeNixBase32 (0.02s)333 --- PASS: TestEncodeNixBase32/empty_input (0.00s)334 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)335=== CONT TestRateLimiterFeedback/503_enables_limiter336=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA337=== CONT TestFilterOversizedClosures/all_closures_skipped3382026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:38051339=== CONT TestConvertHashToNix32/SRI_format_to_Nix323402026/11/06 07:18:15 WARN Rate limiter enabled after throttle name=server-test rate=5341=== CONT TestConvertHashToNix32/already_Nix32_format3422026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:44695343=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error344=== RUN TestSetClientTLS/preserves_debug_logging_transport345=== CONT TestConvertHashToNix32/invalid_format3462026/11/06 07:18:15 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=50347=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true348--- PASS: TestParsePathInfoJSON (0.00s)349 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)350 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)351 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)352 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)353 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)354--- PASS: TestFilterOversizedClosures (0.02s)355 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)356 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)357 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)358=== CONT TestSupersededNARStillUploadsListing/small_NAR359=== CONT TestSupersededNARStillUploadsListing/dump_cut_short360=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails361=== CONT TestUploadMultipart_SupersededByPeer/exists362=== CONT TestUploadMultipart_SupersededByPeer/missing363=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error3642026/11/06 07:18:15 WARN Rate limiter backed off name=server-test rate=5365=== PAUSE TestSetClientTLS/preserves_debug_logging_transport366=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive3672026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:41399368=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3692026/11/06 07:18:15 WARN Rate limiter backed off name=server-test rate=5370=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method371=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512372=== CONT TestPartSizeForNAR/zero_stays_at_minimum3732026/11/06 07:18:15 INFO Uploading abc-hello (1.0GB)374=== CONT TestPartSizeForNAR/1_TiB3752026/11/06 07:18:15 INFO Uploading abc-hello (1.0GB)376--- PASS: TestConvertHashToNix32 (0.02s)377 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)378 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)379 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)380=== CONT TestPathInfoCACompatibility/null_ca_field381=== CONT TestPathInfoCACompatibility/new_structured_format_-_text382=== CONT TestPathInfoCACompatibility/old_string_format_-_text383=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI384=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon385=== CONT TestPartSizeForNAR/capped_at_5_GiB386--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.08s)387--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.07s)388=== RUN TestSetClientTLSErrors/missing_ca_file389=== PAUSE TestSetClientTLSErrors/missing_ca_file390=== RUN TestSetClientTLSErrors/invalid_ca_file391=== PAUSE TestSetClientTLSErrors/invalid_ca_file392=== CONT TestPartSizeForNAR/5_TiB_S3_max_object393=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts394=== CONT TestPartSizeForNAR/small_stays_at_minimum3952026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:41399396=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum397=== CONT TestGetStorePathHash/valid_store_path398=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error399=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false400=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA401=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error402--- PASS: TestRateLimiterFeedback (0.03s)403 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.06s)404 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.06s)405 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)406 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.20s)407=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true408=== CONT TestGetStorePathHash/basename_without_hyphen_should_error409--- PASS: TestDumpPathSingleFile (0.09s)410=== CONT TestSetClientTLS/preserves_debug_logging_transport411=== CONT TestSetClientTLS/rejects_connection_without_client_cert412=== CONT TestSetClientTLSErrors/missing_cert_file413--- PASS: TestPathInfoCACompatibility (0.03s)414 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)415 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.14s)416 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)417 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)418 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)419--- PASS: TestStreamPushBatchesUnderLoad (0.02s)420 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)421 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)422=== CONT TestSetClientTLSErrors/invalid_ca_file423=== CONT TestSetClientTLSErrors/missing_ca_file424=== CONT TestSetClientTLSErrors/missing_key_file4252026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:41399426--- PASS: TestPathInfoHashCompatibility (0.03s)427 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)428 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.14s)429 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)430 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)431--- PASS: TestUploadMultipart_SupersededByPeer (0.13s)432 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)433 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)434--- PASS: TestCaseHackSuffix (0.23s)435--- PASS: TestGetStorePathHash (0.10s)436 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)437 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)438 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)439 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)440--- PASS: TestPartSizeForNAR (0.01s)441 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)442 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)443 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)444 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)445 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)446 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)447 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)448--- PASS: TestSetClientTLSErrors (0.22s)449 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)450 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)451 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)452 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)4532026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:413994542026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:413994552026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:413994562026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:413994572026/11/06 07:18:15 http: TLS handshake error from 127.0.0.1:53020: remote error: tls: bad certificate458--- PASS: TestStreamPushRequestLine (0.23s)459--- PASS: TestSetClientTLS (0.09s)460 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)461 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)462 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4632026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:413994642026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:413994652026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:413994662026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:413994672026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:413994682026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:41399469--- PASS: TestRegisterUploadedObjectReusesConnections (0.25s)470--- PASS: TestDumpPathWriterError (0.25s)4712026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:413994722026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:413994732026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:413994742026/11/06 07:18:15 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:41399475--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.23s)4762026/11/06 07:18:15 INFO Uploading abc-hello (1.0GB)477--- PASS: TestDumpPathMatchesNix (0.27s)4782026/11/06 07:18:15 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:32963/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:32963/part/24792026/11/06 07:18:15 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"480--- PASS: TestSupersededNARStillUploadsListing (0.01s)481 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.14s)482 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.14s)483 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.69s)484--- PASS: TestUploadMultipart_PartsInParallel (0.81s)4852026/11/06 07:18:16 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:42115/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:42115/api/uploads/complete4862026/11/06 07:18:16 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4872026/11/06 07:18:16 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:42115/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:42115/api/uploads/complete4882026/11/06 07:18:16 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4892026/11/06 07:18:16 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:42115/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:42115/api/uploads/complete4902026/11/06 07:18:16 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"491--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)493PASS494Running server tests...495The files belonging to this database system will be owned by user "nixbld".496This user must also own the server process.497498The database cluster will be initialized with locale "C".499The default database encoding has accordingly been set to "SQL_ASCII".500The default text search configuration will be set to "english".501502Data page checksums are enabled.503504creating directory /build/postgres992557002/data ... ok505creating subdirectories ... ok506selecting dynamic shared memory implementation ... posix507selecting default "max_connections" ... 100508selecting default "shared_buffers" ... 128MB509selecting default time zone ... UTC510creating configuration files ... ok511running bootstrap script ... ok512performing post-bootstrap initialization ... ok513syncing data to disk ... ok514515initdb: warning: enabling "trust" authentication for local connections516initdb: 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.517518Success. You can now start the database server using:519520 pg_ctl -D /build/postgres992557002/data -l logfile start521522/build/postgres992557002:5432 - no response5232026-11-06 07:18:17.126 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5242026-11-06 07:18:17.126 UTC [129] LOG: listening on Unix socket "/build/postgres992557002/.s.PGSQL.5432"5252026-11-06 07:18:17.130 UTC [136] LOG: database system was shut down at 2026-11-06 07:18:16 UTC5262026-11-06 07:18:17.134 UTC [129] LOG: database system is ready to accept connections527/build/postgres992557002:5432 - accepting connections528=== RUN TestService_AuthMiddleware529=== PAUSE TestService_AuthMiddleware530=== RUN TestService_AuthMiddleware_MTLSProxyHeader531=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader532=== RUN TestService_AuthMiddleware_MTLSBoundSubjects533=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects534=== RUN TestService_ReadAuthMiddleware535=== PAUSE TestService_ReadAuthMiddleware536=== RUN TestService_AuthMiddleware_OIDC537=== PAUSE TestService_AuthMiddleware_OIDC538=== RUN TestService_RequireScope_OIDC539=== PAUSE TestService_RequireScope_OIDC540=== RUN TestService_ReadScope_PublicByDefault541=== PAUSE TestService_ReadScope_PublicByDefault542=== RUN TestCacheConfigHandler543=== PAUSE TestCacheConfigHandler544=== RUN TestCacheStatsHandler545=== PAUSE TestCacheStatsHandler546=== RUN TestClientCADerivations547=== PAUSE TestClientCADerivations548=== RUN TestClientErrorHandling549=== PAUSE TestClientErrorHandling550=== RUN TestClientIntegration551=== PAUSE TestClientIntegration552=== RUN TestClientMultipleUploads553=== PAUSE TestClientMultipleUploads554=== RUN TestClientWithDependencies555=== PAUSE TestClientWithDependencies556=== RUN TestClientSharedPathCommittedMidPush557=== PAUSE TestClientSharedPathCommittedMidPush558=== RUN TestPinProtectsFromGC559=== PAUSE TestPinProtectsFromGC560=== RUN TestClientPushesUseOnePush561=== PAUSE TestClientPushesUseOnePush562=== RUN TestClientFallsBackToClosures563=== PAUSE TestClientFallsBackToClosures564=== RUN TestDeleteClosuresRacingPins565=== PAUSE TestDeleteClosuresRacingPins566=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock567=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock568=== RUN TestResolveDBConnectionString569=== PAUSE TestResolveDBConnectionString570=== RUN TestConnectWaitsForAPeerMigration571=== PAUSE TestConnectWaitsForAPeerMigration572=== RUN TestLeadElectsOneAndHandsOver573=== PAUSE TestLeadElectsOneAndHandsOver574=== RUN TestLeadIncumbentWinsAfterRestart5752026/11/06 07:18:17 INFO lead: acquired remote=192.0.2.1:12345762026/11/06 07:18:18 INFO lead: released remote=192.0.2.1:12345772026/11/06 07:18:18 INFO lead: acquired remote=192.0.2.1:12345782026/11/06 07:18:19 INFO lead: released remote=192.0.2.1:1234579--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)580=== RUN TestLeadIncumbentAnnouncesAtOnce581=== PAUSE TestLeadIncumbentAnnouncesAtOnce582=== RUN TestLeadEndsOnShutdown583=== PAUSE TestLeadEndsOnShutdown584=== RUN TestLeadEndsWhenItsConnectionHangs5852026/11/06 07:18:19 INFO lead: acquired remote=192.0.2.1:12345862026-11-06 07:18:21.024 UTC [574] FATAL: terminating connection due to administrator command5872026/11/06 07:18:21 INFO lead: acquired remote=192.0.2.1:12345882026/11/06 07:18:22 WARN lead: lock connection lost error="timeout: context deadline exceeded"5892026/11/06 07:18:22 INFO lead: released remote=192.0.2.1:12345902026/11/06 07:18:22 INFO lead: released remote=192.0.2.1:1234591--- PASS: TestLeadEndsWhenItsConnectionHangs (2.90s)592=== RUN TestGCAdvisoryLockBlocksConcurrentRun593=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun594=== RUN TestGCBugBareHashReferences595=== PAUSE TestGCBugBareHashReferences596=== RUN TestGCMetrics597=== PAUSE TestGCMetrics598=== RUN TestPushDedupSurvivesConcurrentGC599=== PAUSE TestPushDedupSurvivesConcurrentGC600=== RUN TestDeduplicatedObjectsRecordedAsPending601=== PAUSE TestDeduplicatedObjectsRecordedAsPending602=== RUN TestGCSweepSkipsPendingObjects603=== PAUSE TestGCSweepSkipsPendingObjects604=== RUN TestTombstonedObjectOfferedWithoutWaiting605=== PAUSE TestTombstonedObjectOfferedWithoutWaiting606=== RUN TestGCSweepDeliversEachKeyOnce607=== PAUSE TestGCSweepDeliversEachKeyOnce608=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection609=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection610=== RUN TestForceGCDuringPushOffersSweptObject611=== PAUSE TestForceGCDuringPushOffersSweptObject612=== RUN TestFailedS3DeleteKeepsTombstone613=== PAUSE TestFailedS3DeleteKeepsTombstone614=== RUN TestSweepSkipsRowsLockedByPush615=== PAUSE TestSweepSkipsRowsLockedByPush616=== RUN TestRegisterCompletedObjectNeedsPendingRow617=== PAUSE TestRegisterCompletedObjectNeedsPendingRow618=== RUN TestGetExistingObjectsLocksRows619=== PAUSE TestGetExistingObjectsLocksRows620=== RUN TestSweepRechecksPendingAfterLocking621=== PAUSE TestSweepRechecksPendingAfterLocking622=== RUN TestPushWaitsForSweepHoldingRow623=== PAUSE TestPushWaitsForSweepHoldingRow624=== RUN TestCommitRacingPendingCleanupKeepsObjects625=== PAUSE TestCommitRacingPendingCleanupKeepsObjects626=== RUN TestGCEndsOnShutdown627=== PAUSE TestGCEndsOnShutdown628=== RUN TestGCTaskStore_StartNew629=== PAUSE TestGCTaskStore_StartNew630=== RUN TestGCTaskStore_DeduplicateSameParams631=== PAUSE TestGCTaskStore_DeduplicateSameParams632=== RUN TestGCTaskStore_ConflictDifferentParams633=== PAUSE TestGCTaskStore_ConflictDifferentParams634=== RUN TestGCTaskStore_GetEmpty635=== PAUSE TestGCTaskStore_GetEmpty636=== RUN TestGCTaskStore_GetReturnsLatest637=== PAUSE TestGCTaskStore_GetReturnsLatest638=== RUN TestGCTaskStore_CompletedAllowsNewTask639=== PAUSE TestGCTaskStore_CompletedAllowsNewTask640=== RUN TestGCTaskStore_PhaseUpdates641=== PAUSE TestGCTaskStore_PhaseUpdates642=== RUN TestGCTaskStore_Fail643=== PAUSE TestGCTaskStore_Fail644=== RUN TestGracefulShutdownDrainsInflight645=== PAUSE TestGracefulShutdownDrainsInflight646=== RUN TestService_healthCheckHandler647=== PAUSE TestService_healthCheckHandler648=== RUN TestService_readinessHandler649=== PAUSE TestService_readinessHandler650=== RUN TestGenerateLandingPage651=== PAUSE TestGenerateLandingPage652=== RUN TestCacheConfigHandlerMaxNarSize653=== PAUSE TestCacheConfigHandlerMaxNarSize654=== RUN TestCreatePendingClosureRejectsOversizedNAR655=== PAUSE TestCreatePendingClosureRejectsOversizedNAR656=== RUN TestNARDeduplicationMetadataUploadBug657=== PAUSE TestNARDeduplicationMetadataUploadBug658=== RUN TestMetricsInventory659=== PAUSE TestMetricsInventory660=== RUN TestMetricsCommit661=== PAUSE TestMetricsCommit662=== RUN TestService_NativeMTLS663=== PAUSE TestService_NativeMTLS664=== RUN TestServerTLSConfig665=== PAUSE TestServerTLSConfig666=== RUN TestMultipartCleanup667=== PAUSE TestMultipartCleanup668=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded669=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded670=== RUN TestPendingCleanupUsesOneCutoff671=== PAUSE TestPendingCleanupUsesOneCutoff672=== RUN TestObjectStatsTrigger673=== PAUSE TestObjectStatsTrigger674=== RUN TestObjectStatsUpdatedOncePerCommit675=== PAUSE TestObjectStatsUpdatedOncePerCommit676=== RUN TestOrphanedObjectsGC677=== PAUSE TestOrphanedObjectsGC678=== RUN TestOrphanedObjectsGCStressTest679=== PAUSE TestOrphanedObjectsGCStressTest680=== RUN TestCreatePin_ReservedPins681=== PAUSE TestCreatePin_ReservedPins682=== RUN TestPresentReportsOnlyClosureRoots683=== PAUSE TestPresentReportsOnlyClosureRoots684=== RUN TestPresentRefreshesOnlyStaleClosures685=== PAUSE TestPresentRefreshesOnlyStaleClosures686=== RUN TestPresentNotReportedWhileGCDeletesClosure687=== PAUSE TestPresentNotReportedWhileGCDeletesClosure688=== RUN TestParseSingleRange689=== PAUSE TestParseSingleRange690=== RUN TestProxyHeadersOnlyTrustedOnSocket6912026/11/06 07:18:22 INFO Starting HTTP server address=proxy.sock6922026/11/06 07:18:22 INFO Starting HTTP server address=127.0.0.1:422516932026/11/06 07:18:22 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6942026/11/06 07:18:22 INFO Shutdown signal received, draining in-flight requests timeout=10s695--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)696=== RUN TestIsValidCachePath697=== PAUSE TestIsValidCachePath698=== RUN TestReadProxyNarinfo699=== PAUSE TestReadProxyNarinfo700=== RUN TestReadProxyNarinfoAlreadyDecompressed701=== PAUSE TestReadProxyNarinfoAlreadyDecompressed702=== RUN TestReadProxyContentNegotiation703=== PAUSE TestReadProxyContentNegotiation704=== RUN TestReadProxyNarStreaming705=== PAUSE TestReadProxyNarStreaming706=== RUN TestReadProxy404707=== PAUSE TestReadProxy404708=== RUN TestReadProxyInvalidPath709=== PAUSE TestReadProxyInvalidPath710=== RUN TestReadProxyHead711=== PAUSE TestReadProxyHead712=== RUN TestReadProxyOutlastsServerWriteTimeout713=== PAUSE TestReadProxyOutlastsServerWriteTimeout714=== RUN TestReadProxyConditionalGet715=== PAUSE TestReadProxyConditionalGet716=== RUN TestReadProxyRootRedirectsToIndexHTML717=== PAUSE TestReadProxyRootRedirectsToIndexHTML718=== RUN TestReadProxyDisabled719=== PAUSE TestReadProxyDisabled720=== RUN TestReadRedirectNar721=== PAUSE TestReadRedirectNar722=== RUN TestReadRedirectKeepsNarinfoProxied723=== PAUSE TestReadRedirectKeepsNarinfoProxied724=== RUN TestReadProxyRangeRequest725=== PAUSE TestReadProxyRangeRequest726=== RUN TestReadRedirectUsesPublicS3URL727=== PAUSE TestReadRedirectUsesPublicS3URL728=== RUN TestPush_OverlappingRootsStoreOneRowPerKey729=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey730=== RUN TestPush_CompleteCommitsEveryRoot731=== PAUSE TestPush_CompleteCommitsEveryRoot732=== RUN TestPush_RepeatedRootCommitsOnce733=== PAUSE TestPush_RepeatedRootCommitsOnce734=== RUN TestPush_CompleteWaitsForCleanupOfThePush735=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush736=== RUN TestPush_RootsAreLockedInByteOrder737=== PAUSE TestPush_RootsAreLockedInByteOrder738=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit739=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit740=== RUN TestPush_RejectsBadRequests741=== PAUSE TestPush_RejectsBadRequests742=== RUN TestPush_SignsNarinfosOfItsPendingObjects743=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects744=== RUN TestRedundantMultipartUpload745=== PAUSE TestRedundantMultipartUpload746=== RUN TestCompleteMultipartUpload_ErrorButObjectExists747=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists748=== RUN TestCompletedNarNotReofferedAcrossClosures749=== PAUSE TestCompletedNarNotReofferedAcrossClosures750=== RUN TestPresignedUploadRegisteredBeforeCommit751=== PAUSE TestPresignedUploadRegisteredBeforeCommit752=== RUN TestService_Rustfstest753=== PAUSE TestService_Rustfstest754=== RUN TestParseSize755=== PAUSE TestParseSize756=== RUN TestSkippedUploadsHandler757=== PAUSE TestSkippedUploadsHandler758=== RUN TestSystemdListenerNotActivated759--- PASS: TestSystemdListenerNotActivated (0.00s)760=== RUN TestWatchdogBeatsWhenHealthy761--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)762=== RUN TestWatchdogSkipsWhenUnhealthy7632026/11/06 07:18:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/11/06 07:18:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/11/06 07:18:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/11/06 07:18:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/11/06 07:18:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/11/06 07:18:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/11/06 07:18:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/11/06 07:18:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/11/06 07:18:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/11/06 07:18:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"773--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)774=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle775=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle776=== RUN TestProxyWriteTimeout777=== PAUSE TestProxyWriteTimeout778=== RUN TestPendingClosureWriteTimeout779=== PAUSE TestPendingClosureWriteTimeout780=== RUN TestIsValidUploadKey781=== PAUSE TestIsValidUploadKey782=== RUN TestUploadHandlersRejectInvalidKeys783=== PAUSE TestUploadHandlersRejectInvalidKeys784=== RUN TestUploadHandlersRejectOversizedBody785=== PAUSE TestUploadHandlersRejectOversizedBody786=== RUN TestService_cleanupPendingClosuresHandler787=== PAUSE TestService_cleanupPendingClosuresHandler788=== RUN TestService_createPendingClosureHandler789=== PAUSE TestService_createPendingClosureHandler790=== RUN TestService_verifyS3Integrity791=== PAUSE TestService_verifyS3Integrity792=== RUN TestService_verifyS3ReuploadsStaleNarinfo793=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo794=== RUN TestCompleteMultipartUnregistered795=== PAUSE TestCompleteMultipartUnregistered796=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT797=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT798=== CONT TestService_AuthMiddleware799=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle800=== CONT TestPendingCleanupUsesOneCutoff801=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection802=== CONT TestReadProxyDisabled803=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT804=== CONT TestCompleteMultipartUnregistered805=== CONT TestService_verifyS3ReuploadsStaleNarinfo806=== CONT TestService_verifyS3Integrity807=== CONT TestService_createPendingClosureHandler808=== CONT TestService_cleanupPendingClosuresHandler809=== CONT TestUploadHandlersRejectOversizedBody810=== CONT TestUploadHandlersRejectInvalidKeys811=== CONT TestIsValidUploadKey812=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info813=== RUN TestIsValidUploadKey/narinfo814=== PAUSE TestIsValidUploadKey/narinfo815=== CONT TestProxyWriteTimeout816=== CONT TestSkippedUploadsHandler817=== CONT TestParseSize818=== CONT TestService_Rustfstest819=== CONT TestPresignedUploadRegisteredBeforeCommit820=== CONT TestCompletedNarNotReofferedAcrossClosures821=== CONT TestCompleteMultipartUpload_ErrorButObjectExists822=== CONT TestRedundantMultipartUpload823=== CONT TestObjectStatsTrigger824=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed8252026/11/06 07:18:22 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000826=== CONT TestPendingClosureWriteTimeout827=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info828=== RUN TestIsValidUploadKey/nar_zst829=== PAUSE TestIsValidUploadKey/nar_zst830=== RUN TestIsValidUploadKey/nar_xz831=== PAUSE TestIsValidUploadKey/nar_xz832=== RUN TestIsValidUploadKey/nar_plain833=== PAUSE TestIsValidUploadKey/nar_plain834=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal835=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal836=== RUN TestPendingClosureWriteTimeout/empty837=== PAUSE TestPendingClosureWriteTimeout/empty838--- PASS: TestParseSize (0.00s)839=== CONT TestPush_SignsNarinfosOfItsPendingObjects840=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed841=== RUN TestProxyWriteTimeout/narinfo842=== RUN TestIsValidUploadKey/listing843=== PAUSE TestIsValidUploadKey/listing844=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key845=== RUN TestPendingClosureWriteTimeout/400_objects846=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed847=== PAUSE TestProxyWriteTimeout/narinfo848=== RUN TestIsValidUploadKey/build_log849=== RUN TestProxyWriteTimeout/1_GiB_nar850--- PASS: TestSkippedUploadsHandler (0.01s)851=== CONT TestPush_RejectsBadRequests852=== PAUSE TestPendingClosureWriteTimeout/400_objects853=== RUN TestPendingClosureWriteTimeout/670k_objects854=== PAUSE TestPendingClosureWriteTimeout/670k_objects855=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key856=== PAUSE TestProxyWriteTimeout/1_GiB_nar857=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed858=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost859=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline860=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key861=== RUN TestProxyWriteTimeout/10_GiB_nar862=== PAUSE TestIsValidUploadKey/build_log863=== RUN TestIsValidUploadKey/build_log_home-manager_file864=== PAUSE TestIsValidUploadKey/build_log_home-manager_file865=== RUN TestIsValidUploadKey/build_log_plus_in_name866=== PAUSE TestIsValidUploadKey/build_log_plus_in_name867=== RUN TestIsValidUploadKey/build_log_question_mark868=== PAUSE TestIsValidUploadKey/build_log_question_mark869=== RUN TestIsValidUploadKey/build_log_equals870=== PAUSE TestIsValidUploadKey/build_log_equals871=== RUN TestIsValidUploadKey/realisation872=== PAUSE TestIsValidUploadKey/realisation873=== RUN TestIsValidUploadKey/realisation_plus_in_output874=== PAUSE TestIsValidUploadKey/realisation_plus_in_output875=== RUN TestIsValidUploadKey/nix-cache-info876=== PAUSE TestIsValidUploadKey/nix-cache-info877=== PAUSE TestProxyWriteTimeout/10_GiB_nar878=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost879=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline880=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key881=== RUN TestIsValidUploadKey/index.html882=== CONT TestPush_RootsAreLockedInByteOrder883=== PAUSE TestIsValidUploadKey/index.html884=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed885=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed886=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit887=== RUN TestProxyWriteTimeout/unknown_size888=== PAUSE TestProxyWriteTimeout/unknown_size889=== RUN TestIsValidUploadKey/narinfo_key,_nar_type890=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type891=== RUN TestIsValidUploadKey/nar_key,_narinfo_type892=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed893=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed894=== CONT TestPush_CompleteWaitsForCleanupOfThePush895=== CONT TestPush_RepeatedRootCommitsOnce896=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type897=== RUN TestIsValidUploadKey/listing_key,_narinfo_type898=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type899=== RUN TestIsValidUploadKey/traversal900=== PAUSE TestIsValidUploadKey/traversal901=== RUN TestIsValidUploadKey/traversal_nar902=== PAUSE TestIsValidUploadKey/traversal_nar903=== RUN TestIsValidUploadKey/absolute904=== PAUSE TestIsValidUploadKey/absolute905=== RUN TestIsValidUploadKey/empty_key906=== PAUSE TestIsValidUploadKey/empty_key907=== RUN TestIsValidUploadKey/unknown_type908=== PAUSE TestIsValidUploadKey/unknown_type909=== CONT TestPush_CompleteCommitsEveryRoot910=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure911=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure912=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart913=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart914=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts915=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts916=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9172026/11/06 07:18:23 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"918--- PASS: TestService_AuthMiddleware (0.51s)919=== CONT TestReadRedirectUsesPublicS3URL9202026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9212026/11/06 07:18:23 INFO Received cleanup request method=DELETE path=/api/pending_closures9222026/11/06 07:18:23 INFO Aborted multipart uploads count=0 kept=09232026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9242026/11/06 07:18:23 INFO Received cleanup request method=DELETE path=/api/pending_closures9252026/11/06 07:18:23 INFO Aborted multipart uploads count=1 kept=09262026/11/06 07:18:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete927--- PASS: TestReadProxyDisabled (0.57s)928=== CONT TestReadProxyRangeRequest9292026-11-06 07:18:23.332 UTC [647] ERROR: Closure does not exist: id=19302026-11-06 07:18:23.332 UTC [647] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9312026-11-06 07:18:23.332 UTC [647] STATEMENT: -- name: CommitPendingClosure :one932 SELECT commit_pending_closure($1::bigint)::bigint933 934--- PASS: TestService_cleanupPendingClosuresHandler (0.57s)935=== CONT TestReadRedirectKeepsNarinfoProxied9362026/11/06 07:18:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9372026/11/06 07:18:23 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst938--- PASS: TestCompleteMultipartUnregistered (0.59s)939=== CONT TestReadRedirectNar9402026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9412026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9422026/11/06 07:18:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9432026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9442026/11/06 07:18:23 INFO Received cleanup request method=DELETE path=/api/pending_closures9452026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9462026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9472026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures948=== RUN TestPush_RejectsBadRequests/no_roots949=== PAUSE TestPush_RejectsBadRequests/no_roots950=== RUN TestPush_RejectsBadRequests/no_objects951=== PAUSE TestPush_RejectsBadRequests/no_objects952=== RUN TestPush_RejectsBadRequests/bad_root953=== PAUSE TestPush_RejectsBadRequests/bad_root954=== RUN TestPush_RejectsBadRequests/root_not_in_objects955=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects956=== CONT TestGCTaskStore_PhaseUpdates957--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)958=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded959--- PASS: TestObjectStatsTrigger (0.72s)960=== CONT TestMultipartCleanup9612026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9622026/11/06 07:18:23 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9632026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures964--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.75s)965=== CONT TestServerTLSConfig966=== RUN TestServerTLSConfig/no_client_CA967=== PAUSE TestServerTLSConfig/no_client_CA968=== RUN TestServerTLSConfig/missing_CA_file969=== PAUSE TestServerTLSConfig/missing_CA_file970=== RUN TestServerTLSConfig/not_a_PEM_file971=== PAUSE TestServerTLSConfig/not_a_PEM_file972=== CONT TestService_NativeMTLS9732026/11/06 07:18:23 INFO Received push request method=POST path=/api/pushes974--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.62s)975=== CONT TestMetricsCommit9762026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9772026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9782026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9792026/11/06 07:18:23 INFO Received push request method=POST path=/api/pushes9802026/11/06 07:18:23 INFO Received complete push request method=POST path=/api/pushes/1/complete9812026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures9822026/11/06 07:18:23 INFO Completed push id=1 objects=4 duration=7.563925ms983--- PASS: TestPush_RepeatedRootCommitsOnce (0.78s)984=== CONT TestMetricsInventory985--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.86s)986=== CONT TestNARDeduplicationMetadataUploadBug9872026/11/06 07:18:23 INFO Received push request method=POST path=/api/pushes9882026/11/06 07:18:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9892026/11/06 07:18:23 INFO Signed narinfos id=1 count=19902026/11/06 07:18:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9912026/11/06 07:18:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9922026/11/06 07:18:23 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9932026/11/06 07:18:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9942026/11/06 07:18:23 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9952026/11/06 07:18:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9962026/11/06 07:18:23 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19972026/11/06 07:18:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9982026/11/06 07:18:23 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo999--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.89s)1000=== CONT TestCreatePendingClosureRejectsOversizedNAR10012026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures1002--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1003=== CONT TestCacheConfigHandlerMaxNarSize1004--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1005=== CONT TestGenerateLandingPage1006--- PASS: TestGenerateLandingPage (0.00s)1007=== CONT TestService_readinessHandler10082026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures10092026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures10102026/11/06 07:18:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10112026/11/06 07:18:23 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLmQzYmRkY2JiLTU0NmItNGZmOC1hODhiLWY3NWVhMjRhMzY1ZngxNzkzOTQ5NTAzNjgzNzc5OTMx1012--- PASS: TestService_Rustfstest (0.95s)1013=== CONT TestService_healthCheckHandler10142026/11/06 07:18:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLmQzYmRkY2JiLTU0NmItNGZmOC1hODhiLWY3NWVhMjRhMzY1ZngxNzkzOTQ5NTAzNjgzNzc5OTMx parts=11015--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.97s)1016=== CONT TestGracefulShutdownDrainsInflight10172026/11/06 07:18:23 INFO Starting HTTP server address=127.0.0.1:3578310182026/11/06 07:18:23 INFO Shutdown signal received, draining in-flight requests timeout=10s10192026/11/06 07:18:23 INFO Received push request method=POST path=/api/pushes10202026/11/06 07:18:23 INFO Received push request method=POST path=/api/pushes10212026-11-06 07:18:23.789 UTC [721] ERROR: could not obtain lock on row in relation "closures"10222026-11-06 07:18:23.789 UTC [721] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10232026-11-06 07:18:23.789 UTC [721] ERROR: could not obtain lock on row in relation "closures"10242026-11-06 07:18:23.789 UTC [721] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10252026-11-06 07:18:23.789 UTC [721] ERROR: could not obtain lock on row in relation "closures"10262026-11-06 07:18:23.789 UTC [721] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10272026-11-06 07:18:23.789 UTC [721] ERROR: could not obtain lock on row in relation "closures"10282026-11-06 07:18:23.789 UTC [721] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10292026-11-06 07:18:23.790 UTC [721] ERROR: could not obtain lock on row in relation "closures"10302026-11-06 07:18:23.790 UTC [721] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1031--- PASS: TestPush_RootsAreLockedInByteOrder (0.96s)1032=== CONT TestGCTaskStore_Fail1033--- PASS: TestGCTaskStore_Fail (0.00s)1034=== CONT TestCommitRacingPendingCleanupKeepsObjects10352026/11/06 07:18:23 INFO Received complete push request method=POST path=/api/pushes/1/complete1036--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1037=== CONT TestGCTaskStore_CompletedAllowsNewTask1038--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1039=== CONT TestGCTaskStore_GetReturnsLatest1040--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1041=== CONT TestGCTaskStore_GetEmpty1042--- PASS: TestGCTaskStore_GetEmpty (0.00s)1043=== CONT TestGCTaskStore_ConflictDifferentParams1044--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1045=== CONT TestGCTaskStore_DeduplicateSameParams1046--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1047=== CONT TestGCTaskStore_StartNew1048--- PASS: TestGCTaskStore_StartNew (0.00s)1049=== CONT TestGCEndsOnShutdown1050=== RUN TestGCEndsOnShutdown/before_the_run1051=== PAUSE TestGCEndsOnShutdown/before_the_run1052=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1053=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1054=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1055=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1056=== CONT TestReadProxyNarinfo10572026/11/06 07:18:23 INFO Completed push id=1 objects=6 duration=24.314435ms10582026/11/06 07:18:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1059--- PASS: TestPush_CompleteCommitsEveryRoot (0.98s)1060=== CONT TestReadProxyRootRedirectsToIndexHTML10612026/11/06 07:18:23 INFO Received push request method=POST path=/api/pushes10622026/11/06 07:18:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10632026/11/06 07:18:23 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLmNmNjhlZDI0LTRkNzEtNDU3Zi1hZmJjLTAzYWQzNjljZTcwN3gxNzkzOTQ5NTAzNDA2NjA4MTcw parts=1010642026/11/06 07:18:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10652026/11/06 07:18:23 INFO Completed upload id=1 objects=2 duration=3.926137ms10662026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures10672026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures10682026/11/06 07:18:23 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLjRhY2I2YWNjLTkxNDItNDQzYy05MTNiLWYyZTVlZjFjYjhkOHgxNzkzOTQ5NTAzNDMyODQ5OTU0 parts=1010692026/11/06 07:18:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10702026/11/06 07:18:23 INFO Received push request method=POST path=/api/pushes10712026/11/06 07:18:23 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10722026/11/06 07:18:23 WARN Found objects in DB but missing from S3, will re-upload count=11073--- PASS: TestService_verifyS3Integrity (1.10s)1074=== CONT TestReadProxyConditionalGet10752026/11/06 07:18:23 INFO Completed upload id=1 objects=2 duration=2.933278ms10762026/11/06 07:18:23 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010772026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures10782026/11/06 07:18:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures10792026/11/06 07:18:23 INFO Aborted multipart uploads count=0 kept=010802026/11/06 07:18:23 INFO Received complete push request method=POST path=/api/pushes/1/complete10812026/11/06 07:18:23 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=010822026/11/06 07:18:23 INFO Completed push id=1 objects=4 duration=9.333724ms10832026/11/06 07:18:23 INFO Received push request method=POST path=/api/pushes10842026/11/06 07:18:23 INFO Vacuumed table table=pending_closures1085--- PASS: TestReadRedirectUsesPublicS3URL (0.63s)1086=== CONT TestReadProxyOutlastsServerWriteTimeout1087--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.15s)1088=== CONT TestReadProxyHead10892026/11/06 07:18:23 INFO Vacuumed table table=pending_objects10902026/11/06 07:18:23 INFO Vacuumed table table=multipart_uploads1091--- PASS: TestReadRedirectKeepsNarinfoProxied (0.58s)1092=== CONT TestReadProxyInvalidPath10932026/11/06 07:18:23 INFO Vacuumed table table=closures10942026/11/06 07:18:23 INFO Vacuumed table table=objects1095--- PASS: TestReadProxyRangeRequest (0.61s)1096=== CONT TestReadProxy4041097--- PASS: TestReadRedirectNar (0.61s)1098=== CONT TestReadProxyNarStreaming10992026/11/06 07:18:23 INFO Aborted multipart uploads count=0 kept=011002026/11/06 07:18:23 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001101--- PASS: TestService_createPendingClosureHandler (1.21s)1102=== CONT TestReadProxyNarinfoAlreadyDecompressed11032026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures11042026/11/06 07:18:23 WARN Force mode enabled - objects will be deleted immediately without grace period11052026/11/06 07:18:23 INFO Received uploads request method=POST path=/api/pending_closures1106--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.55s)11072026/11/06 07:18:24 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=01108=== CONT TestPresentReportsOnlyClosureRoots11092026/11/06 07:18:24 INFO Vacuumed table table=pending_closures11102026/11/06 07:18:24 INFO Vacuumed table table=pending_objects11112026/11/06 07:18:24 INFO Vacuumed table table=multipart_uploads11122026/11/06 07:18:24 INFO Vacuumed table table=closures11132026/11/06 07:18:24 INFO Vacuumed table table=objects11142026/11/06 07:18:24 INFO Received complete push request method=POST path=/api/pushes/2/complete11152026/11/06 07:18:24 INFO Completed push id=2 objects=4 duration=3.618658ms1116--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.18s)1117=== CONT TestIsValidCachePath1118=== RUN TestIsValidCachePath/narinfo1119=== PAUSE TestIsValidCachePath/narinfo1120=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars11212026/11/06 07:18:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1122=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1123=== RUN TestIsValidCachePath/nar_zst1124=== PAUSE TestIsValidCachePath/nar_zst1125=== RUN TestIsValidCachePath/nar_xz1126=== PAUSE TestIsValidCachePath/nar_xz1127=== RUN TestIsValidCachePath/nar_bz21128=== PAUSE TestIsValidCachePath/nar_bz21129=== RUN TestIsValidCachePath/nar_uncompressed1130=== PAUSE TestIsValidCachePath/nar_uncompressed1131=== RUN TestIsValidCachePath/ls1132=== PAUSE TestIsValidCachePath/ls1133=== RUN TestIsValidCachePath/log1134=== PAUSE TestIsValidCachePath/log1135=== RUN TestIsValidCachePath/realisation1136=== PAUSE TestIsValidCachePath/realisation1137=== RUN TestIsValidCachePath/nix-cache-info1138=== PAUSE TestIsValidCachePath/nix-cache-info1139=== RUN TestIsValidCachePath/index.html1140=== PAUSE TestIsValidCachePath/index.html1141=== RUN TestIsValidCachePath/traversal_parent1142=== PAUSE TestIsValidCachePath/traversal_parent1143=== RUN TestIsValidCachePath/traversal_in_middle1144=== PAUSE TestIsValidCachePath/traversal_in_middle1145=== RUN TestIsValidCachePath/invalid_char_e1146=== PAUSE TestIsValidCachePath/invalid_char_e1147=== RUN TestIsValidCachePath/invalid_char_u1148=== PAUSE TestIsValidCachePath/invalid_char_u1149=== RUN TestIsValidCachePath/random_path1150=== PAUSE TestIsValidCachePath/random_path1151=== RUN TestIsValidCachePath/empty1152=== PAUSE TestIsValidCachePath/empty1153=== RUN TestIsValidCachePath/leading_slash1154=== PAUSE TestIsValidCachePath/leading_slash1155=== RUN TestIsValidCachePath/wrong_extension1156=== PAUSE TestIsValidCachePath/wrong_extension1157=== RUN TestIsValidCachePath/short_hash1158=== PAUSE TestIsValidCachePath/short_hash1159=== CONT TestParseSingleRange1160=== RUN TestParseSingleRange/none1161=== PAUSE TestParseSingleRange/none1162=== RUN TestParseSingleRange/unknown_unit1163=== PAUSE TestParseSingleRange/unknown_unit1164=== RUN TestParseSingleRange/multi-range_ignored1165=== PAUSE TestParseSingleRange/multi-range_ignored1166=== RUN TestParseSingleRange/malformed_no_dash1167=== PAUSE TestParseSingleRange/malformed_no_dash1168=== RUN TestParseSingleRange/malformed_both_empty1169=== PAUSE TestParseSingleRange/malformed_both_empty1170=== RUN TestParseSingleRange/malformed_end_before_start1171=== PAUSE TestParseSingleRange/malformed_end_before_start1172=== RUN TestParseSingleRange/closed1173=== PAUSE TestParseSingleRange/closed1174=== RUN TestParseSingleRange/open-ended1175=== PAUSE TestParseSingleRange/open-ended1176=== RUN TestParseSingleRange/end_clamped_to_size1177=== PAUSE TestParseSingleRange/end_clamped_to_size1178=== RUN TestParseSingleRange/suffix1179=== PAUSE TestParseSingleRange/suffix1180=== RUN TestParseSingleRange/suffix_exceeds_size1181=== PAUSE TestParseSingleRange/suffix_exceeds_size11822026/11/06 07:18:24 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1183=== RUN TestParseSingleRange/single_byte1184=== PAUSE TestParseSingleRange/single_byte11852026/11/06 07:18:24 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1186=== RUN TestParseSingleRange/start_past_EOF1187=== PAUSE TestParseSingleRange/start_past_EOF1188=== RUN TestParseSingleRange/start_far_past_EOF1189=== PAUSE TestParseSingleRange/start_far_past_EOF1190--- PASS: TestService_NativeMTLS (0.51s)1191=== CONT TestPresentNotReportedWhileGCDeletesClosure1192=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1193=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1194=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1195=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1196=== CONT TestPresentRefreshesOnlyStaleClosures1197=== CONT TestOrphanedObjectsGCStressTest11982026/11/06 07:18:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11992026/11/06 07:18:24 INFO Received push request method=POST path=/api/pushes12002026/11/06 07:18:24 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLjc1OWMyN2U2LWMzZmYtNDU3MC04Y2UwLTc3MDMwM2ZiOGVjMXgxNzkzOTQ5NTAzNTcyNzk3NTU4 parts=1212012026/11/06 07:18:24 INFO Received uploads request method=POST path=/api/pending_closures12022026/11/06 07:18:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLmNmNDlmMzIzLTRhNWYtNGYwNi04ODhkLTlhZDRjODgyYmIxNXgxNzkzOTQ5NTAzNTQ1MDkxNDQ1 parts=1212032026/11/06 07:18:24 INFO Received uploads request method=POST path=/api/pending_closures1204--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.29s)1205=== CONT TestCreatePin_ReservedPins12062026/11/06 07:18:24 INFO Received uploads request method=POST path=/api/pending_closures12072026/11/06 07:18:24 INFO Received complete push request method=POST path=/api/pushes/1/complete12082026/11/06 07:18:24 INFO Completed push id=1 objects=4 duration=9.977494ms12092026/11/06 07:18:24 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12102026/11/06 07:18:24 INFO Completed upload id=2 objects=2 duration=1.772839ms1211--- PASS: TestMetricsCommit (0.57s)1212=== CONT TestClientFallsBackToClosures1213--- PASS: TestMetricsInventory (0.49s)1214=== CONT TestGCSweepDeliversEachKeyOnce12152026/11/06 07:18:24 INFO Received cleanup request method=DELETE path=/api/pending_closures12162026/11/06 07:18:24 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket33/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12172026/11/06 07:18:24 INFO Aborted multipart uploads count=0 kept=112182026/11/06 07:18:24 INFO Received cleanup request method=DELETE path=/api/pending_closures12192026/11/06 07:18:24 INFO Aborted multipart uploads count=1 kept=012202026/11/06 07:18:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34283/oidc12212026/11/06 07:18:24 WARN readiness check failed error="closed pool"1222--- PASS: TestService_readinessHandler (0.48s)1223=== CONT TestTombstonedObjectOfferedWithoutWaiting1224--- PASS: TestMultipartCleanup (0.65s)1225=== CONT TestGCSweepSkipsPendingObjects1226=== NAME TestNARDeduplicationMetadataUploadBug1227 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3934137649/001/store/32qg1a3y6bgi3d4krmb2xvgkbabz4yp9-file1.txt12282026-11-06 07:18:24.157 UTC [747] ERROR: Push does not exist: id=112292026-11-06 07:18:24.157 UTC [747] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE12302026-11-06 07:18:24.157 UTC [747] STATEMENT: SELECT commit_push($1)1231--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.32s)1232=== CONT TestDeduplicatedObjectsRecordedAsPending1233--- PASS: TestService_healthCheckHandler (0.44s)1234=== CONT TestPushDedupSurvivesConcurrentGC1235--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.42s)1236=== CONT TestGCMetrics12372026/11/06 07:18:24 INFO Aborted multipart uploads count=0 kept=012382026/11/06 07:18:24 WARN Force mode enabled - objects will be deleted immediately without grace period12392026/11/06 07:18:24 INFO Received push request method=POST path=/api/pushes12402026/11/06 07:18:24 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=012412026/11/06 07:18:24 INFO Vacuumed table table=pending_closures12422026/11/06 07:18:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12432026/11/06 07:18:24 INFO Uploading 32qg1a3y6bgi3d4krmb2xvgkbabz4yp9-file1.txt (160B)12442026/11/06 07:18:24 INFO Vacuumed table table=pending_objects12452026/11/06 07:18:24 INFO Vacuumed table table=multipart_uploads12462026/11/06 07:18:24 INFO Vacuumed table table=closures12472026/11/06 07:18:24 INFO Vacuumed table table=objects12482026/11/06 07:18:24 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12492026/11/06 07:18:24 WARN Failed to register uploaded object key=32qg1a3y6bgi3d4krmb2xvgkbabz4yp9.ls error="server returned 404: 404 page not found\n"12502026/11/06 07:18:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12512026/11/06 07:18:24 INFO Signed narinfos id=1 count=112522026/11/06 07:18:24 INFO Uploading 1 narinfos1253--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.48s)1254=== CONT TestGCBugBareHashReferences12552026/11/06 07:18:24 INFO Received complete push request method=POST path=/api/pushes/1/complete12562026/11/06 07:18:24 WARN Failed to register uploaded object key=32qg1a3y6bgi3d4krmb2xvgkbabz4yp9.narinfo error="server returned 404: 404 page not found\n"1257--- PASS: TestReadProxyConditionalGet (0.43s)1258=== CONT TestGCAdvisoryLockBlocksConcurrentRun12592026/11/06 07:18:24 INFO Completed push id=1 objects=3 duration=9.076874ms12602026/11/06 07:18:24 INFO Upload complete. (93ms)1261=== NAME TestNARDeduplicationMetadataUploadBug1262 metadata_upload_test.go:54: Retrieved narinfo from S3:1263 StorePath: /build/TestNARDeduplicationMetadataUploadBug3934137649/001/store/32qg1a3y6bgi3d4krmb2xvgkbabz4yp9-file1.txt1264 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1265 Compression: zstd1266 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1267 NarSize: 1601268 References: 1269 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1270 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1271 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1272 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12732026/11/06 07:18:24 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1274--- PASS: TestReadProxyNarinfo (0.49s)1275=== CONT TestReadProxyContentNegotiation1276=== NAME TestNARDeduplicationMetadataUploadBug1277 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3934137649/001/store/mgdri36f1xim4ms2hzmfi5pv6dd01lmx-file2.txt1278--- PASS: TestReadProxyHead (0.44s)1279=== CONT TestLeadEndsOnShutdown1280--- PASS: TestReadProxyInvalidPath (0.45s)1281=== CONT TestLeadIncumbentAnnouncesAtOnce12822026/11/06 07:18:24 INFO Received push request method=POST path=/api/pushes12832026/11/06 07:18:24 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12842026/11/06 07:18:24 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12852026/11/06 07:18:24 WARN Failed to register uploaded object key=mgdri36f1xim4ms2hzmfi5pv6dd01lmx.ls error="server returned 404: 404 page not found\n"12862026/11/06 07:18:24 INFO Signed narinfos id=2 count=112872026/11/06 07:18:24 INFO Uploading 1 narinfos12882026/11/06 07:18:24 INFO Received complete push request method=POST path=/api/pushes/2/complete12892026/11/06 07:18:24 WARN Failed to register uploaded object key=mgdri36f1xim4ms2hzmfi5pv6dd01lmx.narinfo error="server returned 404: 404 page not found\n"12902026/11/06 07:18:24 INFO Completed push id=2 objects=3 duration=2.887229ms12912026/11/06 07:18:24 INFO Upload complete. (61ms)1292=== NAME TestNARDeduplicationMetadataUploadBug1293 metadata_upload_test.go:76: Retrieved narinfo from S3:1294 StorePath: /build/TestNARDeduplicationMetadataUploadBug3934137649/001/store/mgdri36f1xim4ms2hzmfi5pv6dd01lmx-file2.txt1295 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1296 Compression: zstd1297 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1298 NarSize: 1601299 References: 1300 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1301 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1302 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1303 {"version":1,"root":{"type":"regular","size":44}}1304--- PASS: TestReadProxyNarStreaming (0.49s)1305=== CONT TestLeadElectsOneAndHandsOver1306--- PASS: TestNARDeduplicationMetadataUploadBug (0.83s)1307=== CONT TestClientCADerivations1308--- PASS: TestReadProxy404 (0.53s)1309=== CONT TestConnectWaitsForAPeerMigration1310--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.50s)1311=== CONT TestResolveDBConnectionString1312=== RUN TestResolveDBConnectionString/flag_wins1313=== PAUSE TestResolveDBConnectionString/flag_wins1314=== RUN TestResolveDBConnectionString/file_when_flag_empty1315=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1316=== RUN TestResolveDBConnectionString/missing_file_is_an_error1317=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1318=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1319=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1320=== RUN TestResolveDBConnectionString/nothing_configured1321=== PAUSE TestResolveDBConnectionString/nothing_configured1322=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1323--- PASS: TestPresentReportsOnlyClosureRoots (0.53s)1324=== CONT TestDeleteClosuresRacingPins1325--- PASS: TestPresentRefreshesOnlyStaleClosures (0.53s)1326=== CONT TestClientPushesUseOnePush13272026/11/06 07:18:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13282026/11/06 07:18:24 INFO Aborted multipart uploads count=0 kept=013292026/11/06 07:18:24 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLjYzZGI5ODgzLThhMGItNDU2Ni1hYjhmLTNhYWZiZjFhNTQ3OHgxNzkzOTQ5NTA0MDczMzkzODAz error="Get \"http://127.0.0.1:1/bucket16/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13302026/11/06 07:18:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLmQ1NGNhNGFiLWE2Y2EtNDNkNC05YzZkLTk1ODdjZGY5ZmNmYXgxNzkzOTQ5NTA0MDYzODc5MzQ5 parts=1213312026/11/06 07:18:24 INFO Received cleanup request method=DELETE path=/api/pending_closures13322026/11/06 07:18:24 WARN Force mode enabled - objects will be deleted immediately without grace period13332026/11/06 07:18:24 INFO Aborted multipart uploads count=1 kept=01334--- PASS: TestRedundantMultipartUpload (1.88s)1335=== CONT TestClientWithDependencies13362026/11/06 07:18:24 INFO Received uploads request method=POST path=/api/pending_closures13372026/11/06 07:18:24 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=013382026/11/06 07:18:24 INFO Vacuumed table table=pending_closures13392026/11/06 07:18:24 INFO Vacuumed table table=pending_objects13402026/11/06 07:18:24 INFO Vacuumed table table=multipart_uploads13412026/11/06 07:18:24 INFO Vacuumed table table=closures13422026/11/06 07:18:24 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13432026/11/06 07:18:24 WARN Refused reserved pin name=worker-x86_64-linux13442026/11/06 07:18:24 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13452026/11/06 07:18:24 INFO Received create pin request method=POST path=/api/pins/my-app13462026/11/06 07:18:24 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13472026/11/06 07:18:24 INFO Vacuumed table table=objects1348--- PASS: TestCreatePin_ReservedPins (0.62s)1349=== CONT TestPinProtectsFromGC1350--- PASS: TestGCSweepDeliversEachKeyOnce (0.57s)1351=== CONT TestClientMultipleUploads13522026/11/06 07:18:24 INFO Aborted multipart uploads count=0 kept=013532026/11/06 07:18:24 WARN Force mode enabled - objects will be deleted immediately without grace period13542026/11/06 07:18:24 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=013552026/11/06 07:18:24 INFO Vacuumed table table=pending_closures13562026/11/06 07:18:24 INFO Vacuumed table table=pending_objects13572026/11/06 07:18:24 INFO Vacuumed table table=multipart_uploads13582026/11/06 07:18:24 INFO Vacuumed table table=closures13592026/11/06 07:18:24 INFO Vacuumed table table=objects13602026/11/06 07:18:24 INFO Received uploads request method=POST path=/api/pending_closures1361--- PASS: TestGCSweepSkipsPendingObjects (0.57s)1362=== CONT TestClientSharedPathCommittedMidPush1363--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.58s)1364=== CONT TestClientIntegration13652026/11/06 07:18:24 INFO Received uploads request method=POST path=/api/pending_closures13662026/11/06 07:18:24 INFO Received uploads request method=POST path=/api/pending_closures1367--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.61s)1368=== CONT TestClientErrorHandling1369=== RUN TestClientErrorHandling/InvalidStorePath1370=== PAUSE TestClientErrorHandling/InvalidStorePath1371=== RUN TestClientErrorHandling/InvalidAuthToken1372=== PAUSE TestClientErrorHandling/InvalidAuthToken1373=== RUN TestClientErrorHandling/ServerNotAvailable1374=== PAUSE TestClientErrorHandling/ServerNotAvailable1375=== CONT TestService_RequireScope_OIDC13762026/11/06 07:18:24 INFO Aborted multipart uploads count=0 kept=013772026/11/06 07:18:24 WARN Force mode enabled - objects will be deleted immediately without grace period13782026/11/06 07:18:24 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=013792026/11/06 07:18:24 INFO Vacuumed table table=pending_closures13802026/11/06 07:18:24 INFO Vacuumed table table=pending_objects13812026/11/06 07:18:24 INFO Vacuumed table table=multipart_uploads13822026/11/06 07:18:24 INFO Vacuumed table table=closures13832026/11/06 07:18:24 INFO Vacuumed table table=objects13842026/11/06 07:18:24 INFO Received uploads request method=POST path=/api/pending_closures1385--- PASS: TestGCMetrics (0.55s)1386=== CONT TestCacheStatsHandler13872026/11/06 07:18:24 INFO Received uploads request method=POST path=/api/pending_closures13882026/11/06 07:18:24 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13892026/11/06 07:18:24 INFO Uploading s84v088picj67xz1711mc5j61fc9k30b-shared-dep (136B)13902026/11/06 07:18:24 INFO Uploading bvzx4pa8n39brawv2zh0fn4ncnf6vvcp-a (216B)13912026/11/06 07:18:24 WARN Failed to register uploaded object key=6wabw4xr8abzxz0awgz4vlyl1waarccm.ls error="server returned 404: 404 page not found\n"13922026/11/06 07:18:24 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13932026/11/06 07:18:24 WARN Failed to register uploaded object key=nar/1n24sbrag8m2g6gn8gcvcl04m3m5lr23jh1jhbgmibv64765qrg2.nar.zst error="server returned 404: 404 page not found\n"13942026/11/06 07:18:24 WARN Failed to register uploaded object key=s84v088picj67xz1711mc5j61fc9k30b.ls error="server returned 404: 404 page not found\n"13952026/11/06 07:18:24 WARN Failed to register uploaded object key=bvzx4pa8n39brawv2zh0fn4ncnf6vvcp.ls error="server returned 404: 404 page not found\n"13962026/11/06 07:18:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13972026/11/06 07:18:24 INFO Signed narinfos id=1 count=213982026/11/06 07:18:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13992026/11/06 07:18:24 INFO Signed narinfos id=2 count=214002026/11/06 07:18:24 INFO Uploading 4 narinfos14012026/11/06 07:18:24 WARN Failed to register uploaded object key=s84v088picj67xz1711mc5j61fc9k30b.narinfo error="server returned 404: 404 page not found\n"14022026/11/06 07:18:24 WARN Failed to register uploaded object key=bvzx4pa8n39brawv2zh0fn4ncnf6vvcp.narinfo error="server returned 404: 404 page not found\n"14032026/11/06 07:18:24 WARN Failed to register uploaded object key=6wabw4xr8abzxz0awgz4vlyl1waarccm.narinfo error="server returned 404: 404 page not found\n"14042026/11/06 07:18:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14052026/11/06 07:18:24 WARN Failed to register uploaded object key=s84v088picj67xz1711mc5j61fc9k30b.narinfo error="server returned 404: 404 page not found\n"14062026/11/06 07:18:24 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"1407--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.53s)1408=== CONT TestCacheConfigHandler1409=== RUN TestCacheConfigHandler/full_config,_no_issuer1410=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1411=== RUN TestCacheConfigHandler/no_cache_url_configured1412=== PAUSE TestCacheConfigHandler/no_cache_url_configured1413=== RUN TestCacheConfigHandler/no_signing_keys1414=== PAUSE TestCacheConfigHandler/no_signing_keys1415=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1416=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1417=== CONT TestRegisterCompletedObjectNeedsPendingRow14182026/11/06 07:18:24 INFO Aborted multipart uploads count=0 kept=014192026/11/06 07:18:24 INFO Completed upload id=1 objects=6 duration=9.388324ms14202026/11/06 07:18:24 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14212026/11/06 07:18:24 INFO Completed upload id=2 objects=6 duration=1.770629ms14222026/11/06 07:18:24 INFO Upload complete. (75ms)1423=== NAME TestClientFallsBackToClosures1424 client_pushes_test.go:112: Retrieved narinfo from S3:1425 StorePath: /build/TestClientFallsBackToClosures2778095248/001/store/s84v088picj67xz1711mc5j61fc9k30b-shared-dep1426 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1427 Compression: zstd1428 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821429 NarSize: 1361430 References: 1431 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14322026/11/06 07:18:24 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=01433 client_pushes_test.go:112: Retrieved narinfo from S3:1434 StorePath: /build/TestClientFallsBackToClosures2778095248/001/store/bvzx4pa8n39brawv2zh0fn4ncnf6vvcp-a1435 URL: nar/1n24sbrag8m2g6gn8gcvcl04m3m5lr23jh1jhbgmibv64765qrg2.nar.zst1436 Compression: zstd1437 NarHash: sha256:1n24sbrag8m2g6gn8gcvcl04m3m5lr23jh1jhbgmibv64765qrg21438 NarSize: 2161439 References: /build/TestClientFallsBackToClosures2778095248/001/store/s84v088picj67xz1711mc5j61fc9k30b-shared-dep1440 CA: text:sha256:195976bzx389pqda4pw9pr3fci9bb0zyfbxrdmmij2daj8k6r9061441 client_pushes_test.go:112: Retrieved narinfo from S3:1442 StorePath: /build/TestClientFallsBackToClosures2778095248/001/store/6wabw4xr8abzxz0awgz4vlyl1waarccm-b1443 URL: nar/1n24sbrag8m2g6gn8gcvcl04m3m5lr23jh1jhbgmibv64765qrg2.nar.zst1444 Compression: zstd1445 NarHash: sha256:1n24sbrag8m2g6gn8gcvcl04m3m5lr23jh1jhbgmibv64765qrg21446 NarSize: 2161447 References: /build/TestClientFallsBackToClosures2778095248/001/store/s84v088picj67xz1711mc5j61fc9k30b-shared-dep1448 CA: text:sha256:195976bzx389pqda4pw9pr3fci9bb0zyfbxrdmmij2daj8k6r90614492026/11/06 07:18:24 INFO Vacuumed table table=pending_closures14502026/11/06 07:18:24 INFO Vacuumed table table=pending_objects1451--- PASS: TestClientFallsBackToClosures (0.74s)1452=== CONT TestService_ReadScope_PublicByDefault14532026/11/06 07:18:24 INFO Vacuumed table table=multipart_uploads14542026/11/06 07:18:24 INFO Vacuumed table table=closures14552026/11/06 07:18:24 INFO Vacuumed table table=objects14562026/11/06 07:18:24 INFO Aborted multipart uploads count=0 kept=014572026/11/06 07:18:24 WARN Force mode enabled - objects will be deleted immediately without grace period14582026/11/06 07:18:24 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=014592026/11/06 07:18:24 INFO Vacuumed table table=pending_closures14602026/11/06 07:18:24 INFO lead: acquired remote=192.0.2.1:123414612026/11/06 07:18:24 INFO Vacuumed table table=pending_objects14622026/11/06 07:18:24 INFO Vacuumed table table=multipart_uploads14632026/11/06 07:18:24 INFO Vacuumed table table=closures14642026/11/06 07:18:24 INFO Vacuumed table table=objects1465--- PASS: TestPushDedupSurvivesConcurrentGC (0.72s)1466=== CONT TestPushWaitsForSweepHoldingRow14672026/11/06 07:18:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41545/oidc1468--- PASS: TestReadProxyContentNegotiation (0.58s)1469=== CONT TestFailedS3DeleteKeepsTombstone14702026/11/06 07:18:24 INFO lead: acquired remote=192.0.2.1:123414712026/11/06 07:18:24 INFO lead: released remote=192.0.2.1:12341472--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.52s)1473=== CONT TestSweepRechecksPendingAfterLocking14742026/11/06 07:18:24 INFO lead: acquired remote=192.0.2.1:12341475--- PASS: TestGCBugBareHashReferences (0.74s)1476=== CONT TestSweepSkipsRowsLockedByPush1477=== NAME TestClientCADerivations1478 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations938837108/001/store/3hjniz8zz95agkrmr4sq2bs5ivf7hx2f-ca-test1479 client_ca_test.go:139: Found 1 dependencies (including self)1480=== NAME TestClientMultipleUploads1481 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads1761046940/001/store/y6lcyvbq5bfn7ahxzrhdb56nxiw55lhv-test-file-0.txt1482=== NAME TestClientWithDependencies1483 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies230537866/001/store/ahpk8y6vgkz5wfzhbz3r161bzyg7y5l7-test-script1484=== NAME TestPinProtectsFromGC1485 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3555801338/001/store/j7h3knhqp5hpd1nxqjl0d3z278lvb0a3-pinned-file.txt1486 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3555801338/001/store/ypgwsmikjrhgdzcq5q8aaxnkhxvy5fpd-unpinned-file.txt14872026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes14882026/11/06 07:18:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1489=== NAME TestClientMultipleUploads14902026/11/06 07:18:25 INFO Uploading 3hjniz8zz95agkrmr4sq2bs5ivf7hx2f-ca-test (144B)1491 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads1761046940/001/store/z37pih4idglx36dilk75dmzdknghrb69-test-file-1.txt1492=== NAME TestClientWithDependencies1493 client_integration_test.go:662: Found 1 dependencies (including self)1494--- PASS: TestCacheStatsHandler (0.37s)1495=== CONT TestGetExistingObjectsLocksRows1496--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.70s)1497=== CONT TestObjectStatsUpdatedOncePerCommit14982026/11/06 07:18:25 WARN Failed to register uploaded object key=log/k4sfpb3wbjp7aw5g8a6rk70k64kmlsps-ca-test.drv error="server returned 404: 404 page not found\n"14992026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15002026/11/06 07:18:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15012026/11/06 07:18:25 WARN Failed to register uploaded object key=3hjniz8zz95agkrmr4sq2bs5ivf7hx2f.ls error="server returned 404: 404 page not found\n"15022026/11/06 07:18:25 INFO Signed narinfos id=1 count=115032026/11/06 07:18:25 INFO Uploading 1 narinfos15042026/11/06 07:18:25 INFO Received complete push request method=POST path=/api/pushes/1/complete15052026/11/06 07:18:25 WARN Failed to register uploaded object key=3hjniz8zz95agkrmr4sq2bs5ivf7hx2f.narinfo error="server returned 404: 404 page not found\n"1506=== NAME TestClientIntegration1507 client_integration_test.go:291: Created store path: /build/TestClientIntegration4162681196/002/store/vvh01r6y7gzk7jc9w6psm4p05wk5c1gr-test-file.txt15082026/11/06 07:18:25 INFO Completed push id=1 objects=4 duration=5.094666ms15092026/11/06 07:18:25 INFO Upload complete. (91ms)1510--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.36s)1511=== CONT TestOrphanedObjectsGC1512=== NAME TestClientCADerivations1513 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations938837108/001/store/3hjniz8zz95agkrmr4sq2bs5ivf7hx2f-ca-test1514 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1515 Compression: zstd1516 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1517 NarSize: 1441518 References: 1519 Deriver: /build/TestClientCADerivations938837108/001/store/k4sfpb3wbjp7aw5g8a6rk70k64kmlsps-ca-test.drv1520 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1521 client_ca_test.go:185: Checking for realisation files in S3...1522 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1523 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15242026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes1525=== NAME TestClientMultipleUploads1526 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads1761046940/001/store/qbm5421w1v5anvzjdwkq5r6dirkiysdm-test-file-2.txt15272026/11/06 07:18:25 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15282026/11/06 07:18:25 INFO Uploading m3h64b49hyzbpijm00ym89hzah4aw1l2-shared-dep (136B)15292026/11/06 07:18:25 INFO Uploading fq54vy3wgxsanxv5cygy0gyian4hm65z-a (208B)15302026/11/06 07:18:25 WARN Failed to register uploaded object key=s67wyrbdxnh0897k6vmb3h5793glbig9.ls error="server returned 404: 404 page not found\n"15312026/11/06 07:18:25 WARN Failed to register uploaded object key=fq54vy3wgxsanxv5cygy0gyian4hm65z.ls error="server returned 404: 404 page not found\n"15322026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15332026/11/06 07:18:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15342026/11/06 07:18:25 WARN Failed to register uploaded object key=m3h64b49hyzbpijm00ym89hzah4aw1l2.ls error="server returned 404: 404 page not found\n"15352026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/10i24fkcafbj296cy97bmf0d4cdkqr4l5imakn9z0mr2njqs7jw0.nar.zst error="server returned 404: 404 page not found\n"15362026/11/06 07:18:25 INFO Signed narinfos id=1 count=315372026/11/06 07:18:25 INFO Uploading 3 narinfos1538--- PASS: TestService_ReadScope_PublicByDefault (0.37s)1539=== CONT TestService_ReadAuthMiddleware15402026/11/06 07:18:25 WARN Failed to register uploaded object key=m3h64b49hyzbpijm00ym89hzah4aw1l2.narinfo error="server returned 404: 404 page not found\n"15412026/11/06 07:18:25 WARN Failed to register uploaded object key=s67wyrbdxnh0897k6vmb3h5793glbig9.narinfo error="server returned 404: 404 page not found\n"15422026/11/06 07:18:25 INFO Received complete push request method=POST path=/api/pushes/1/complete15432026/11/06 07:18:25 WARN Failed to register uploaded object key=fq54vy3wgxsanxv5cygy0gyian4hm65z.narinfo error="server returned 404: 404 page not found\n"15442026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes15452026/11/06 07:18:25 INFO Completed push id=1 objects=8 duration=11.831772ms15462026/11/06 07:18:25 INFO Upload complete. (65ms)1547=== NAME TestClientPushesUseOnePush1548 client_pushes_test.go:97: Retrieved narinfo from S3:1549 StorePath: /build/TestClientPushesUseOnePush939697591/001/store/m3h64b49hyzbpijm00ym89hzah4aw1l2-shared-dep1550 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1551 Compression: zstd1552 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821553 NarSize: 1361554 References: 1555 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15562026/11/06 07:18:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15572026/11/06 07:18:25 INFO Uploading j7h3knhqp5hpd1nxqjl0d3z278lvb0a3-pinned-file.txt (128B)1558 client_pushes_test.go:97: Retrieved narinfo from S3:1559 StorePath: /build/TestClientPushesUseOnePush939697591/001/store/fq54vy3wgxsanxv5cygy0gyian4hm65z-a1560 URL: nar/10i24fkcafbj296cy97bmf0d4cdkqr4l5imakn9z0mr2njqs7jw0.nar.zst1561 Compression: zstd1562 NarHash: sha256:10i24fkcafbj296cy97bmf0d4cdkqr4l5imakn9z0mr2njqs7jw01563 NarSize: 2081564 References: /build/TestClientPushesUseOnePush939697591/001/store/m3h64b49hyzbpijm00ym89hzah4aw1l2-shared-dep1565 CA: text:sha256:08ng7w7vdj90lbrhk0qx8h5mmalzhak565aa4p4yhf985fimy2xl15662026/11/06 07:18:25 INFO Received uploads request method=POST path=/api/pending_closures1567 client_pushes_test.go:97: Retrieved narinfo from S3:1568 StorePath: /build/TestClientPushesUseOnePush939697591/001/store/s67wyrbdxnh0897k6vmb3h5793glbig9-b1569 URL: nar/10i24fkcafbj296cy97bmf0d4cdkqr4l5imakn9z0mr2njqs7jw0.nar.zst1570 Compression: zstd1571 NarHash: sha256:10i24fkcafbj296cy97bmf0d4cdkqr4l5imakn9z0mr2njqs7jw01572 NarSize: 2081573 References: /build/TestClientPushesUseOnePush939697591/001/store/m3h64b49hyzbpijm00ym89hzah4aw1l2-shared-dep1574 CA: text:sha256:08ng7w7vdj90lbrhk0qx8h5mmalzhak565aa4p4yhf985fimy2xl15752026/11/06 07:18:25 WARN Failed to register uploaded object key=j7h3knhqp5hpd1nxqjl0d3z278lvb0a3.ls error="server returned 404: 404 page not found\n"15762026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15772026/11/06 07:18:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15782026/11/06 07:18:25 INFO Signed narinfos id=1 count=115792026/11/06 07:18:25 INFO Uploading 1 narinfos15802026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes1581--- PASS: TestClientPushesUseOnePush (0.68s)1582=== CONT TestForceGCDuringPushOffersSweptObject1583=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1584=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1585=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1586=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1587=== CONT TestService_AuthMiddleware_OIDC15882026/11/06 07:18:25 INFO Received complete push request method=POST path=/api/pushes/1/complete15892026/11/06 07:18:25 WARN Failed to register uploaded object key=j7h3knhqp5hpd1nxqjl0d3z278lvb0a3.narinfo error="server returned 404: 404 page not found\n"15902026/11/06 07:18:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15912026/11/06 07:18:25 INFO Uploading ahpk8y6vgkz5wfzhbz3r161bzyg7y5l7-test-script (136B)15922026/11/06 07:18:25 WARN Failed to register uploaded object key=ahpk8y6vgkz5wfzhbz3r161bzyg7y5l7.ls error="server returned 404: 404 page not found\n"15932026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15942026/11/06 07:18:25 WARN Failed to register uploaded object key=log/xqpm8yl7q9d3jimhpf8xvc4hsx78qs2q-test-script.drv error="server returned 404: 404 page not found\n"15952026/11/06 07:18:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15962026/11/06 07:18:25 INFO Signed narinfos id=1 count=115972026/11/06 07:18:25 INFO Uploading 1 narinfos15982026/11/06 07:18:25 INFO Completed push id=1 objects=3 duration=9.915254ms15992026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes16002026/11/06 07:18:25 INFO Upload complete. (72ms)16012026/11/06 07:18:25 INFO Received complete push request method=POST path=/api/pushes/1/complete16022026/11/06 07:18:25 WARN Failed to register uploaded object key=ahpk8y6vgkz5wfzhbz3r161bzyg7y5l7.narinfo error="server returned 404: 404 page not found\n"16032026/11/06 07:18:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16042026/11/06 07:18:25 INFO Uploading vvh01r6y7gzk7jc9w6psm4p05wk5c1gr-test-file.txt (152B)16052026/11/06 07:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45909/oidc16062026/11/06 07:18:25 INFO Completed push id=1 objects=4 duration=4.754077ms16072026/11/06 07:18:25 INFO Upload complete. (57ms)1608=== NAME TestClientWithDependencies1609 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies230537866/001/store) requires matching store prefix16102026/11/06 07:18:25 WARN Failed to register uploaded object key=vvh01r6y7gzk7jc9w6psm4p05wk5c1gr.ls error="server returned 404: 404 page not found\n"16112026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16122026/11/06 07:18:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16132026/11/06 07:18:25 INFO Signed narinfos id=1 count=116142026/11/06 07:18:25 INFO Uploading 1 narinfos1615--- PASS: TestClientWithDependencies (0.62s)1616=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16172026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes16182026/11/06 07:18:25 INFO Received complete push request method=POST path=/api/pushes/1/complete16192026/11/06 07:18:25 WARN Failed to register uploaded object key=vvh01r6y7gzk7jc9w6psm4p05wk5c1gr.narinfo error="server returned 404: 404 page not found\n"1620=== RUN TestService_RequireScope_OIDC/builder_may_write1621=== PAUSE TestService_RequireScope_OIDC/builder_may_write1622=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1623=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1624=== RUN TestService_RequireScope_OIDC/ops_may_admin1625=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1626=== RUN TestService_RequireScope_OIDC/ops_may_not_write1627=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1628=== RUN TestService_RequireScope_OIDC/reader_may_not_write1629=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1630=== RUN TestService_RequireScope_OIDC/static_token_may_admin1631=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1632=== RUN TestService_RequireScope_OIDC/static_token_may_write1633=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1634=== RUN TestService_RequireScope_OIDC/reader_may_read1635=== PAUSE TestService_RequireScope_OIDC/reader_may_read1636=== RUN TestService_RequireScope_OIDC/writer_implies_read1637=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1638=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1639=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1640=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1641=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1642=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1643=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1644=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1645=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1646=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1647=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1648=== CONT TestService_AuthMiddleware_MTLSProxyHeader16492026/11/06 07:18:25 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16502026/11/06 07:18:25 INFO Uploading mvwr5karmwc3v080amjx60p6s30xrsp3-top (224B)16512026/11/06 07:18:25 INFO Uploading i3lq73pznb6ish34vsxlh8qnrphpddv8-shared-dep (136B)16522026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes16532026/11/06 07:18:25 INFO Completed push id=1 objects=3 duration=9.726534ms16542026/11/06 07:18:25 INFO Upload complete. (68ms)16552026/11/06 07:18:25 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16562026/11/06 07:18:25 INFO Uploading qbm5421w1v5anvzjdwkq5r6dirkiysdm-test-file-2.txt (160B)16572026/11/06 07:18:25 INFO Uploading z37pih4idglx36dilk75dmzdknghrb69-test-file-1.txt (160B)16582026/11/06 07:18:25 WARN Failed to register uploaded object key=i3lq73pznb6ish34vsxlh8qnrphpddv8.ls error="server returned 404: 404 page not found\n"16592026/11/06 07:18:25 INFO Uploading y6lcyvbq5bfn7ahxzrhdb56nxiw55lhv-test-file-0.txt (160B)16602026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16612026/11/06 07:18:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16622026/11/06 07:18:25 WARN Failed to register uploaded object key=mvwr5karmwc3v080amjx60p6s30xrsp3.ls error="server returned 404: 404 page not found\n"16632026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/0k0l69hib7kblnr8iqyw10yfiqryp3ysydm9wy9bipjvp0pzscij.nar.zst error="server returned 404: 404 page not found\n"16642026/11/06 07:18:25 INFO Signed narinfos id=1 count=216652026/11/06 07:18:25 INFO Uploading 2 narinfos16662026/11/06 07:18:25 WARN Failed to register uploaded object key=qbm5421w1v5anvzjdwkq5r6dirkiysdm.ls error="server returned 404: 404 page not found\n"16672026/11/06 07:18:25 WARN Failed to register uploaded object key=z37pih4idglx36dilk75dmzdknghrb69.ls error="server returned 404: 404 page not found\n"16682026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16692026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16702026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16712026/11/06 07:18:25 INFO Received uploads request method=POST path=/api/pending_closures16722026/11/06 07:18:25 WARN Failed to register uploaded object key=i3lq73pznb6ish34vsxlh8qnrphpddv8.narinfo error="server returned 404: 404 page not found\n"16732026/11/06 07:18:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16742026/11/06 07:18:25 WARN Failed to register uploaded object key=y6lcyvbq5bfn7ahxzrhdb56nxiw55lhv.ls error="server returned 404: 404 page not found\n"16752026/11/06 07:18:25 INFO Signed narinfos id=1 count=316762026/11/06 07:18:25 INFO Uploading 3 narinfos16772026/11/06 07:18:25 INFO Received complete push request method=POST path=/api/pushes/1/complete16782026/11/06 07:18:25 WARN Failed to register uploaded object key=mvwr5karmwc3v080amjx60p6s30xrsp3.narinfo error="server returned 404: 404 page not found\n"16792026/11/06 07:18:25 WARN Failed to register uploaded object key=z37pih4idglx36dilk75dmzdknghrb69.narinfo error="server returned 404: 404 page not found\n"16802026/11/06 07:18:25 WARN Failed to register uploaded object key=y6lcyvbq5bfn7ahxzrhdb56nxiw55lhv.narinfo error="server returned 404: 404 page not found\n"16812026/11/06 07:18:25 INFO Received complete push request method=POST path=/api/pushes/1/complete16822026/11/06 07:18:25 WARN Failed to register uploaded object key=qbm5421w1v5anvzjdwkq5r6dirkiysdm.narinfo error="server returned 404: 404 page not found\n"16832026/11/06 07:18:25 INFO Completed push id=1 objects=6 duration=13.317902ms16842026/11/06 07:18:25 INFO Upload complete. (76ms)1685=== NAME TestClientSharedPathCommittedMidPush16862026/11/06 07:18:25 INFO Completed push id=1 objects=9 duration=9.869864ms1687 client_integration_test.go:727: Retrieved narinfo from S3:1688 StorePath: /build/TestClientSharedPathCommittedMidPush691020347/001/store/i3lq73pznb6ish34vsxlh8qnrphpddv8-shared-dep1689 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1690 Compression: zstd16912026/11/06 07:18:25 INFO Upload complete. (67ms)1692 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821693 NarSize: 1361694 References: 1695 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1696=== NAME TestClientMultipleUploads1697 client_integration_test.go:416: Uploaded 3 paths in 104.002026ms1698=== NAME TestClientSharedPathCommittedMidPush1699 client_integration_test.go:727: Retrieved narinfo from S3:1700 StorePath: /build/TestClientSharedPathCommittedMidPush691020347/001/store/mvwr5karmwc3v080amjx60p6s30xrsp3-top1701 URL: nar/0k0l69hib7kblnr8iqyw10yfiqryp3ysydm9wy9bipjvp0pzscij.nar.zst1702 Compression: zstd1703 NarHash: sha256:0k0l69hib7kblnr8iqyw10yfiqryp3ysydm9wy9bipjvp0pzscij1704 NarSize: 2241705 References: /build/TestClientSharedPathCommittedMidPush691020347/001/store/i3lq73pznb6ish34vsxlh8qnrphpddv8-shared-dep1706 CA: text:sha256:17bj7qgw3ggr6jrsb8x0j5j72grgwvhpw6dws0k0gca41r1yhfyx17072026/11/06 07:18:25 INFO All 1 paths already cached17082026/11/06 07:18:25 INFO Aborted multipart uploads count=0 kept=01709=== NAME TestClientIntegration1710 client_integration_test.go:317: Retrieved narinfo from S3:1711 StorePath: /build/TestClientIntegration4162681196/002/store/vvh01r6y7gzk7jc9w6psm4p05wk5c1gr-test-file.txt1712 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1713 Compression: zstd1714 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11715 NarSize: 1521716 References: 1717 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11718--- PASS: TestClientSharedPathCommittedMidPush (0.60s)1719=== CONT TestPendingClosureWriteTimeout/empty1720=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1721=== NAME TestClientIntegration1722 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1723 client_integration_test.go:318: Decompressed .ls content (64 bytes):1724 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1725--- PASS: TestClientMultipleUploads (0.63s)1726=== CONT TestPendingClosureWriteTimeout/670k_objects1727=== CONT TestPendingClosureWriteTimeout/400_objects1728=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17292026/11/06 07:18:25 INFO Received uploads request method=POST path=/1730=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17312026/11/06 07:18:25 INFO Received complete multipart upload request method=POST path=/1732=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17332026/11/06 07:18:25 INFO Received request for more parts method=POST path=/1734=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17352026/11/06 07:18:25 INFO Received uploads request method=POST path=/1736--- PASS: TestUploadHandlersRejectInvalidKeys (0.07s)1737 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1738 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1739 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1740 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1741=== CONT TestProxyWriteTimeout/narinfo1742=== CONT TestProxyWriteTimeout/1_GiB_nar1743=== CONT TestProxyWriteTimeout/unknown_size1744=== CONT TestProxyWriteTimeout/10_GiB_nar1745--- PASS: TestProxyWriteTimeout (0.07s)1746 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1747 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1748 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1749 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1750=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed17512026/11/06 07:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period17522026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes17532026/11/06 07:18:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17542026/11/06 07:18:25 INFO Uploading ypgwsmikjrhgdzcq5q8aaxnkhxvy5fpd-unpinned-file.txt (128B)17552026/11/06 07:18:25 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."17562026/11/06 07:18:25 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1757--- PASS: TestFailedS3DeleteKeepsTombstone (0.44s)1758=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed17592026/11/06 07:18:25 WARN Failed to register uploaded object key=ypgwsmikjrhgdzcq5q8aaxnkhxvy5fpd.ls error="server returned 404: 404 page not found\n"17602026/11/06 07:18:25 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17612026/11/06 07:18:25 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17622026/11/06 07:18:25 INFO Signed narinfos id=2 count=117632026/11/06 07:18:25 INFO Uploading 1 narinfos17642026/11/06 07:18:25 INFO Aborted multipart uploads count=0 kept=017652026/11/06 07:18:25 INFO Received complete push request method=POST path=/api/pushes/2/complete17662026/11/06 07:18:25 WARN Failed to register uploaded object key=ypgwsmikjrhgdzcq5q8aaxnkhxvy5fpd.narinfo error="server returned 404: 404 page not found\n"17672026/11/06 07:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period17682026/11/06 07:18:25 INFO Completed push id=2 objects=3 duration=3.740637ms17692026/11/06 07:18:25 INFO Upload complete. (54ms)17702026/11/06 07:18:25 INFO Aborted multipart uploads count=0 kept=017712026/11/06 07:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period17722026/11/06 07:18:25 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=017732026/11/06 07:18:25 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=017742026/11/06 07:18:25 INFO Vacuumed table table=pending_closures17752026/11/06 07:18:25 INFO Vacuumed table table=pending_objects17762026/11/06 07:18:25 INFO Vacuumed table table=multipart_uploads17772026/11/06 07:18:25 INFO Vacuumed table table=closures17782026/11/06 07:18:25 INFO Vacuumed table table=pending_closures17792026/11/06 07:18:25 INFO Vacuumed table table=objects17802026/11/06 07:18:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures17812026/11/06 07:18:25 INFO Garbage collection started17822026/11/06 07:18:25 INFO Vacuumed table table=pending_objects17832026/11/06 07:18:25 INFO Vacuumed table table=multipart_uploads17842026/11/06 07:18:25 INFO Vacuumed table table=closures17852026/11/06 07:18:25 INFO Aborted multipart uploads count=0 kept=01786--- PASS: TestGetExistingObjectsLocksRows (0.21s)1787=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost17882026/11/06 07:18:25 INFO Vacuumed table table=objects1789--- PASS: TestSweepRechecksPendingAfterLocking (0.49s)1790=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed17912026/11/06 07:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period17922026/11/06 07:18:25 INFO Aborted multipart uploads count=0 kept=01793=== NAME TestClientCADerivations1794 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1795 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1796 error: binary cache 's3://bucket67?endpoint=http://localhost:40747®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations938837108/001/store'1797 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117982026/11/06 07:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period1799--- PASS: TestClientCADerivations (0.95s)1800=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed18012026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes18022026/11/06 07:18:25 INFO Object in database but missing from S3 key=vvh01r6y7gzk7jc9w6psm4p05wk5c1gr.ls18032026/11/06 07:18:25 WARN Found objects in DB but missing from S3, will re-upload count=118042026/11/06 07:18:25 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18052026/11/06 07:18:25 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=018062026/11/06 07:18:25 INFO Vacuumed table table=pending_closures18072026/11/06 07:18:25 INFO Vacuumed table table=pending_objects18082026/11/06 07:18:25 INFO Vacuumed table table=multipart_uploads18092026/11/06 07:18:25 INFO Vacuumed table table=closures18102026/11/06 07:18:25 INFO Received complete push request method=POST path=/api/pushes/2/complete18112026/11/06 07:18:25 WARN Failed to register uploaded object key=vvh01r6y7gzk7jc9w6psm4p05wk5c1gr.ls error="server returned 404: 404 page not found\n"18122026/11/06 07:18:25 INFO Completed push id=2 objects=3 duration=13.083512ms18132026/11/06 07:18:25 INFO Upload complete. (57ms)18142026/11/06 07:18:25 INFO Vacuumed table table=objects1815=== NAME TestClientIntegration1816 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1817 client_integration_test.go:335: Decompressed .ls content (49 bytes):1818 {"version":1,"root":{"type":"regular","size":39}}1819--- PASS: TestSweepSkipsRowsLockedByPush (0.41s)1820=== CONT TestIsValidUploadKey/narinfo1821=== CONT TestIsValidUploadKey/realisation_plus_in_output1822=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1823=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1824=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1825=== CONT TestIsValidUploadKey/index.html1826=== CONT TestIsValidUploadKey/nix-cache-info1827=== CONT TestIsValidUploadKey/build_log_home-manager_file1828=== CONT TestIsValidUploadKey/realisation1829=== CONT TestIsValidUploadKey/build_log_equals1830=== CONT TestIsValidUploadKey/build_log_question_mark1831=== CONT TestIsValidUploadKey/build_log_plus_in_name1832=== CONT TestIsValidUploadKey/empty_key1833=== CONT TestIsValidUploadKey/unknown_type1834=== CONT TestIsValidUploadKey/nar_plain1835=== CONT TestIsValidUploadKey/build_log1836=== CONT TestIsValidUploadKey/listing1837=== CONT TestIsValidUploadKey/absolute1838=== CONT TestIsValidUploadKey/nar_xz1839=== CONT TestIsValidUploadKey/nar_zst1840=== CONT TestIsValidUploadKey/traversal_nar1841=== CONT TestIsValidUploadKey/traversal1842--- PASS: TestIsValidUploadKey (0.08s)1843 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1844 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1845 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1846 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1847 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1848 --- PASS: TestIsValidUploadKey/index.html (0.00s)1849 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1850 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1851 --- PASS: TestIsValidUploadKey/realisation (0.00s)1852 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1853 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1854 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1855 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1856 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1857 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1858 --- PASS: TestIsValidUploadKey/build_log (0.00s)1859 --- PASS: TestIsValidUploadKey/listing (0.00s)1860 --- PASS: TestIsValidUploadKey/absolute (0.00s)1861 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1862 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1863 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1864 --- PASS: TestIsValidUploadKey/traversal (0.00s)1865--- PASS: TestObjectStatsUpdatedOncePerCommit (0.26s)1866=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18672026/11/06 07:18:25 INFO Received uploads request method=POST path=/1868=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18692026/11/06 07:18:25 INFO Received request for more parts method=POST path=/18702026/11/06 07:18:25 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=018712026/11/06 07:18:25 INFO Vacuumed table table=pending_closures1872--- PASS: TestService_ReadAuthMiddleware (0.23s)1873=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18742026/11/06 07:18:25 INFO Received complete multipart upload request method=POST path=/18752026/11/06 07:18:25 INFO Vacuumed table table=pending_objects18762026/11/06 07:18:25 INFO Vacuumed table table=multipart_uploads18772026/11/06 07:18:25 INFO Vacuumed table table=closures18782026/11/06 07:18:25 INFO Vacuumed table table=objects1879=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1880=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1881=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1882=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1883=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1884=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1885=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1886=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1887=== CONT TestPush_RejectsBadRequests/no_roots18882026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes1889=== CONT TestPush_RejectsBadRequests/bad_root18902026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes1891=== CONT TestPush_RejectsBadRequests/root_not_in_objects18922026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes1893=== CONT TestPush_RejectsBadRequests/no_objects18942026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes1895=== CONT TestServerTLSConfig/no_client_CA1896--- PASS: TestPush_RejectsBadRequests (0.68s)1897 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1898 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1899 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1900 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1901=== CONT TestServerTLSConfig/not_a_PEM_file1902=== CONT TestServerTLSConfig/missing_CA_file1903=== CONT TestGCEndsOnShutdown/before_the_run1904--- PASS: TestServerTLSConfig (0.00s)1905 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1906 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1907 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)19082026/11/06 07:18:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19092026/11/06 07:18:25 WARN mTLS auth: bound subjects configured but subject DN unavailable19102026/11/06 07:18:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1911--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.22s)1912=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1913=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1914=== CONT TestIsValidCachePath/narinfo1915=== CONT TestIsValidCachePath/index.html1916=== CONT TestIsValidCachePath/short_hash1917=== CONT TestIsValidCachePath/wrong_extension1918=== CONT TestIsValidCachePath/leading_slash1919=== CONT TestIsValidCachePath/empty1920=== CONT TestIsValidCachePath/random_path1921=== CONT TestIsValidCachePath/nar_uncompressed1922=== CONT TestIsValidCachePath/invalid_char_u1923=== CONT TestIsValidCachePath/nix-cache-info1924=== CONT TestIsValidCachePath/invalid_char_e1925=== CONT TestIsValidCachePath/realisation1926=== CONT TestIsValidCachePath/traversal_in_middle1927=== CONT TestIsValidCachePath/log1928=== CONT TestIsValidCachePath/traversal_parent1929=== CONT TestIsValidCachePath/ls1930=== CONT TestIsValidCachePath/nar_bz21931=== CONT TestIsValidCachePath/nar_xz1932=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1933=== CONT TestIsValidCachePath/nar_zst1934--- PASS: TestIsValidCachePath (0.00s)1935 --- PASS: TestIsValidCachePath/narinfo (0.00s)1936 --- PASS: TestIsValidCachePath/index.html (0.00s)1937 --- PASS: TestIsValidCachePath/short_hash (0.00s)1938 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1939 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1940 --- PASS: TestIsValidCachePath/empty (0.00s)1941 --- PASS: TestIsValidCachePath/random_path (0.00s)1942 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1943 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1944 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1945 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1946 --- PASS: TestIsValidCachePath/realisation (0.00s)1947 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1948 --- PASS: TestIsValidCachePath/log (0.00s)1949 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1950 --- PASS: TestIsValidCachePath/ls (0.00s)1951 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1952 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1953 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1954 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1955=== CONT TestParseSingleRange/none1956=== CONT TestParseSingleRange/end_clamped_to_size1957=== CONT TestParseSingleRange/start_far_past_EOF1958=== CONT TestParseSingleRange/start_past_EOF1959=== CONT TestParseSingleRange/malformed_both_empty1960=== CONT TestParseSingleRange/open-ended1961=== CONT TestParseSingleRange/closed1962=== CONT TestParseSingleRange/malformed_end_before_start1963=== CONT TestParseSingleRange/single_byte1964=== CONT TestParseSingleRange/suffix_exceeds_size1965=== CONT TestParseSingleRange/multi-range_ignored1966=== CONT TestParseSingleRange/malformed_no_dash1967=== CONT TestParseSingleRange/suffix1968=== CONT TestParseSingleRange/unknown_unit1969--- PASS: TestParseSingleRange (0.00s)1970 --- PASS: TestParseSingleRange/none (0.00s)1971 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1972 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1973 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1974 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1975 --- PASS: TestParseSingleRange/open-ended (0.00s)1976 --- PASS: TestParseSingleRange/closed (0.00s)1977 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1978 --- PASS: TestParseSingleRange/single_byte (0.00s)1979 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1980 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1981 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1982 --- PASS: TestParseSingleRange/suffix (0.00s)1983 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1984=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1985--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.25s)1986=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh19872026/11/06 07:18:25 INFO Received push request method=POST path=/api/pushes19882026/11/06 07:18:25 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19892026/11/06 07:18:25 INFO Received complete push request method=POST path=/api/pushes/3/complete19902026/11/06 07:18:25 WARN Failed to register uploaded object key=vvh01r6y7gzk7jc9w6psm4p05wk5c1gr.ls error="server returned 404: 404 page not found\n"19912026/11/06 07:18:25 INFO Completed push id=3 objects=3 duration=2.862788ms19922026/11/06 07:18:25 INFO Upload complete. (44ms)1993=== NAME TestClientIntegration1994 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1995 client_integration_test.go:352: Decompressed .ls content (49 bytes):1996 {"version":1,"root":{"type":"regular","size":39}}1997 client_integration_test.go:363: Testing garbage collection...19982026/11/06 07:18:25 INFO Received uploads request method=POST path=/api/pending_closures19992026/11/06 07:18:25 INFO Received uploads request method=POST path=/api/pending_closures20002026/11/06 07:18:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures20012026/11/06 07:18:25 INFO Garbage collection started20022026/11/06 07:18:25 INFO Aborted multipart uploads count=0 kept=020032026/11/06 07:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period20042026/11/06 07:18:25 INFO Received uploads request method=POST path=/api/pending_closures20052026/11/06 07:18:25 INFO Received uploads request method=POST path=/api/pending_closures20062026/11/06 07:18:25 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=020072026/11/06 07:18:25 INFO Vacuumed table table=pending_closures20082026/11/06 07:18:25 INFO Vacuumed table table=pending_objects20092026/11/06 07:18:25 INFO Vacuumed table table=multipart_uploads20102026/11/06 07:18:25 INFO Vacuumed table table=closures20112026/11/06 07:18:25 INFO Vacuumed table table=objects20122026/11/06 07:18:25 INFO Received uploads request method=POST path=/api/pending_closures20132026/11/06 07:18:25 INFO Received uploads request method=POST path=/api/pending_closures2014=== CONT TestResolveDBConnectionString/flag_wins2015=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2016=== CONT TestResolveDBConnectionString/nothing_configured2017=== CONT TestResolveDBConnectionString/missing_file_is_an_error2018=== CONT TestResolveDBConnectionString/file_when_flag_empty2019=== CONT TestClientErrorHandling/InvalidStorePath2020--- PASS: TestResolveDBConnectionString (0.00s)2021 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2022 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2023 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2024 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2025 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2026--- PASS: TestPushWaitsForSweepHoldingRow (0.91s)2027=== CONT TestClientErrorHandling/ServerNotAvailable20282026/11/06 07:18:25 INFO Aborted multipart uploads count=0 kept=02029=== NAME TestOrphanedObjectsGC2030 orphaned_objects_gc_test.go:287: GC Test Summary:2031 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A2032 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B2033 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)2034 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)2035 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects2036--- PASS: TestOrphanedObjectsGC (0.63s)2037=== CONT TestClientErrorHandling/InvalidAuthToken20382026/11/06 07:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period20392026/11/06 07:18:25 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:40747/bucket98/?delete=\": context canceled"2040=== CONT TestCacheConfigHandler/full_config,_no_issuer2041=== CONT TestCacheConfigHandler/no_signing_keys2042=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2043=== CONT TestCacheConfigHandler/no_cache_url_configured2044--- PASS: TestCacheConfigHandler (0.00s)2045 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2046 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2047 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2048 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2049=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows20502026/11/06 07:18:25 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/present20512026/11/06 07:18:25 INFO lead: released remote=192.0.2.1:12342052--- PASS: TestLeadEndsOnShutdown (1.57s)2053=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check20542026/11/06 07:18:25 INFO Aborted multipart uploads count=0 kept=020552026/11/06 07:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period2056--- PASS: TestDeleteClosuresRacingPins (1.42s)2057=== CONT TestService_RequireScope_OIDC/builder_may_write2058=== CONT TestService_RequireScope_OIDC/reader_may_read2059=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2060=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20612026/11/06 07:18:25 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]2062=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2063=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2064=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2065=== CONT TestService_RequireScope_OIDC/writer_implies_read2066=== CONT TestService_RequireScope_OIDC/reader_may_not_write2067=== CONT TestService_RequireScope_OIDC/static_token_may_write2068=== CONT TestService_RequireScope_OIDC/static_token_may_admin2069=== CONT TestService_RequireScope_OIDC/ops_may_admin2070=== CONT TestService_RequireScope_OIDC/ops_may_not_write2071=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2072=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2073--- PASS: TestService_RequireScope_OIDC (0.51s)2074 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2075 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2076 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2077 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2078 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2079 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2080 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2081 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2082 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2083 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2084 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2085 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2086 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2087 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2088--- PASS: TestGCEndsOnShutdown (0.00s)2089 --- PASS: TestGCEndsOnShutdown/before_the_run (0.30s)2090 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.33s)2091 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.46s)2092=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20932026/11/06 07:18:25 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]2094=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2095=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured20962026/11/06 07:18:25 WARN Authentication failed token_preview=eyJhbGciOi...mNo6L1wGwg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2097--- PASS: TestService_AuthMiddleware_OIDC (0.23s)2098 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2099 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2100 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2101 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)21022026/11/06 07:18:25 WARN Request failed, retrying attempt=2 backoff=219.773622ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21032026/11/06 07:18:26 INFO Received uploads request method=POST path=/api/pending_closures21042026/11/06 07:18:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21052026/11/06 07:18:26 INFO Aborted multipart uploads count=0 kept=021062026/11/06 07:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period21072026/11/06 07:18:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21082026/11/06 07:18:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLjY3MzE0N2RiLTJiMWUtNDExYy04YjNjLTcxYTg0NGI4NDQwY3gxNzkzOTQ5NTA1NTY3NDIyNTEy parts=1021092026/11/06 07:18:26 INFO Received uploads request method=POST path=/api/pending_closures21102026/11/06 07:18:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21112026/11/06 07:18:26 INFO Completed upload id=1 objects=3 duration=3.041198ms21122026/11/06 07:18:26 INFO Received uploads request method=POST path=/api/pending_closures21132026/11/06 07:18:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLmFmOGIyNmQwLTliMjYtNGY3Yy04Njc2LWIyYjE2ZmQ5NmIzN3gxNzkzOTQ5NTA1NjU0OTI3NDY4 parts=1021142026/11/06 07:18:26 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=021152026/11/06 07:18:26 INFO Vacuumed table table=pending_closures21162026/11/06 07:18:26 INFO Aborted multipart uploads count=0 kept=021172026/11/06 07:18:26 INFO Vacuumed table table=pending_objects21182026/11/06 07:18:26 INFO Vacuumed table table=multipart_uploads21192026/11/06 07:18:26 INFO Vacuumed table table=closures21202026/11/06 07:18:26 INFO Vacuumed table table=objects21212026/11/06 07:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period21222026/11/06 07:18:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21232026/11/06 07:18:26 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=021242026/11/06 07:18:26 INFO Vacuumed table table=pending_closures21252026/11/06 07:18:26 INFO Completed upload id=1 objects=3 duration=3.025948ms21262026/11/06 07:18:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21272026/11/06 07:18:26 INFO Vacuumed table table=pending_objects21282026/11/06 07:18:26 INFO Vacuumed table table=multipart_uploads21292026/11/06 07:18:26 INFO Vacuumed table table=closures21302026/11/06 07:18:26 INFO Vacuumed table table=objects21312026/11/06 07:18:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2132--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2133 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.19s)2134 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.28s)21352026/11/06 07:18:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLjU2MmQ0NTlkLTgzY2QtNDA2MS1iZTQ4LTJkN2VkMmU0M2U1MngxNzkzOTQ5NTA1NjgzMjU1NTIx parts=1021362026/11/06 07:18:26 INFO lead: released remote=192.0.2.1:123421372026/11/06 07:18:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21382026/11/06 07:18:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21392026/11/06 07:18:26 INFO Completed upload id=1 objects=3 duration=3.546378ms21402026/11/06 07:18:26 INFO Received uploads request method=POST path=/api/pending_closures21412026/11/06 07:18:26 INFO Received uploads request method=POST path=/api/pending_closures21422026/11/06 07:18:26 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21432026/11/06 07:18:26 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21442026/11/06 07:18:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLmRmNDhjNDFlLTY3MGUtNGU4MC04NjFlLTdiYzk5Nzk1MTYxM3gxNzkzOTQ5NTA1NzEyODc4OTcz parts=1021452026/11/06 07:18:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21462026/11/06 07:18:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21472026/11/06 07:18:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21482026/11/06 07:18:26 INFO Completed upload id=1 objects=3 duration=3.704327ms21492026/11/06 07:18:26 INFO Received uploads request method=POST path=/api/pending_closures2150--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2151 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2152 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2153 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.72s)21542026/11/06 07:18:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLmVkYTkyYzE1LTg2MjQtNDVhMC1hMDVkLTUxZjNiZDg3Zjk5YngxNzkzOTQ5NTA1NzQ0Mjk0ODI0 parts=1021552026/11/06 07:18:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21562026/11/06 07:18:26 INFO Completed upload id=1 objects=3 duration=3.778278ms21572026/11/06 07:18:26 INFO lead: acquired remote=192.0.2.1:123421582026/11/06 07:18:26 INFO Received uploads request method=POST path=/api/pending_closures21592026/11/06 07:18:26 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21602026/11/06 07:18:26 WARN Found objects in DB but missing from S3, will re-upload count=121612026/11/06 07:18:26 WARN Request failed, retrying attempt=3 backoff=434.037467ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2162--- PASS: TestPendingClosureWriteTimeout (0.07s)2163 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2164 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2165 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2166 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.03s)2167--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2168 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.84s)2169 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.88s)2170=== NAME TestOrphanedObjectsGCStressTest2171 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains21722026/11/06 07:18:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2173 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion21742026/11/06 07:18:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLjA1MDQ2NTAzLWM0YTctNGEwOS05OGE3LWYzNTYxYjlkMzRlMHgxNzkzOTQ5NTA2MDg1NzM5ODM2 parts=1021752026/11/06 07:18:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21762026/11/06 07:18:26 INFO Completed upload id=2 objects=3 duration=1.308379ms21772026/11/06 07:18:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21782026/11/06 07:18:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=MjVlOGNjM2UtOThmMS00ZTFmLTkzMWEtZTI3YTJjMDUzYTdkLjQyODdlYTUyLTljZWItNDM1MC05ZDI2LWYzNjRiZmQ1MzdmNngxNzkzOTQ5NTA2MTIzMzE5MjAz parts=1021792026/11/06 07:18:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21802026/11/06 07:18:26 INFO Completed upload id=2 objects=3 duration=1.360589ms21812026/11/06 07:18:26 INFO Received uploads request method=POST path=/api/pending_closures21822026/11/06 07:18:26 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21832026/11/06 07:18:26 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo21842026/11/06 07:18:26 INFO Received uploads request method=POST path=/api/pending_closures21852026/11/06 07:18:26 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst21862026/11/06 07:18:26 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2187--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.08s)2188 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (0.82s)2189 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.77s)2190 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.79s)2191 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.17s)2192 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.16s)21932026/11/06 07:18:26 WARN Request failed, retrying attempt=4 backoff=775.460002ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21942026/11/06 07:18:27 INFO lead: released remote=192.0.2.1:12342195--- PASS: TestLeadElectsOneAndHandsOver (2.77s)21962026/11/06 07:18:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021972026/11/06 07:18:27 INFO Received create pin request method=POST path=/api/pins/myapp21982026/11/06 07:18:27 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3555801338/001/store/j7h3knhqp5hpd1nxqjl0d3z278lvb0a3-pinned-file.txt narinfo_key=j7h3knhqp5hpd1nxqjl0d3z278lvb0a3.narinfo21992026/11/06 07:18:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures22002026/11/06 07:18:27 INFO Garbage collection started22012026/11/06 07:18:27 INFO Aborted multipart uploads count=0 kept=022022026/11/06 07:18:27 WARN Force mode enabled - objects will be deleted immediately without grace period22032026/11/06 07:18:27 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022042026/11/06 07:18:27 INFO Vacuumed table table=pending_closures22052026/11/06 07:18:27 INFO Vacuumed table table=pending_objects22062026/11/06 07:18:27 INFO Vacuumed table table=multipart_uploads22072026/11/06 07:18:27 INFO Vacuumed table table=closures22082026/11/06 07:18:27 INFO Vacuumed table table=objects22092026/11/06 07:18:27 WARN Request failed, retrying attempt=5 backoff=1.506600418s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22102026/11/06 07:18:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02211=== NAME TestClientIntegration2212 client_integration_test.go:370: Objects in database after GC:2213 client_integration_test.go:370: Successfully deleted all objects with GC --force2214--- PASS: TestClientIntegration (2.86s)2215=== NAME TestOrphanedObjectsGCStressTest2216 orphaned_objects_gc_test.go:503: Stress test completed successfully:2217 orphaned_objects_gc_test.go:504: - Active objects preserved: 202218 orphaned_objects_gc_test.go:505: - Objects deleted: 2102219 orphaned_objects_gc_test.go:506: - Total GC'd: 2102220--- PASS: TestOrphanedObjectsGCStressTest (3.69s)22212026/11/06 07:18:27 WARN Rate limiter enabled after throttle name=s3-test rate=522222026/11/06 07:18:27 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2223=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2224 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102225 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002226--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.97s)2227--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.64s)22282026/11/06 07:18:28 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-config22292026/11/06 07:18:29 WARN Request failed, retrying attempt=2 backoff=196.619249ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22302026/11/06 07:18:29 WARN Request failed, retrying attempt=3 backoff=393.92422ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2231=== NAME TestPinProtectsFromGC2232 client_integration_test.go:887: Pin successfully protected closure from garbage collection2233--- PASS: TestPinProtectsFromGC (4.73s)22342026/11/06 07:18:29 INFO Aborted multipart uploads count=1 kept=022352026/11/06 07:18:29 INFO Received cleanup request method=DELETE path=/api/pending_closures22362026/11/06 07:18:29 INFO Aborted multipart uploads count=1 kept=02237--- PASS: TestPendingCleanupUsesOneCutoff (6.66s)2238--- PASS: TestConnectWaitsForAPeerMigration (5.18s)22392026/11/06 07:18:29 WARN Request failed, retrying attempt=4 backoff=737.459145ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22402026/11/06 07:18:30 WARN Request failed, retrying attempt=5 backoff=1.643636769s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22412026/11/06 07:18:32 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"22422026/11/06 07:18:32 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-config22432026/11/06 07:18:32 WARN Request failed, retrying attempt=2 backoff=215.076475ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22442026/11/06 07:18:32 WARN Request failed, retrying attempt=3 backoff=389.412173ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22452026/11/06 07:18:32 WARN Request failed, retrying attempt=4 backoff=852.286627ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22462026/11/06 07:18:33 WARN Request failed, retrying attempt=5 backoff=1.453190167s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22472026/11/06 07:18:35 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_closures22482026/11/06 07:18:35 WARN Request failed, retrying attempt=2 backoff=202.438039ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22492026/11/06 07:18:35 WARN Request failed, retrying attempt=3 backoff=387.614845ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22502026/11/06 07:18:35 WARN Request failed, retrying attempt=4 backoff=829.244067ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22512026/11/06 07:18:36 WARN Request failed, retrying attempt=5 backoff=1.736217148s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2252--- PASS: TestClientErrorHandling (0.00s)2253 --- PASS: TestClientErrorHandling/InvalidStorePath (0.19s)2254 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.32s)2255 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.55s)2256PASS2257{"timestamp":"2026-11-06T07:18:38.340824535Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60704","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(389)"}2258{"timestamp":"2026-11-06T07:18:38.340834325Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60420","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(390)"}2259{"timestamp":"2026-11-06T07:18:38.340886165Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60720","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(386)"}2260{"timestamp":"2026-11-06T07:18:38.341412765Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60694","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(391)"}22612026-11-06 07:18:38.678 UTC [129] LOG: received smart shutdown request22622026-11-06 07:18:38.684 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122632026-11-06 07:18:38.690 UTC [134] LOG: shutting down22642026-11-06 07:18:38.690 UTC [134] LOG: checkpoint starting: shutdown immediate22652026-11-06 07:18:39.873 UTC [134] LOG: checkpoint complete: wrote 11093 buffers (67.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.270 s, sync=0.861 s, total=1.184 s; sync files=35725, longest=0.100 s, average=0.001 s; distance=516989 kB, estimate=516989 kB; lsn=0/21045268, redo lsn=0/2104526822662026-11-06 07:18:39.933 UTC [129] LOG: database system is shut down2267Running OIDC tests...2268=== RUN TestAudienceForIssuer2269=== PAUSE TestAudienceForIssuer2270=== RUN TestGlobMatch2271=== PAUSE TestGlobMatch2272=== RUN TestValidateToken_ValidToken2273=== PAUSE TestValidateToken_ValidToken2274=== RUN TestValidateToken_WrongAudience2275=== PAUSE TestValidateToken_WrongAudience2276=== RUN TestValidateToken_Expired2277=== PAUSE TestValidateToken_Expired2278=== RUN TestValidateToken_BoundClaimsMismatch2279=== PAUSE TestValidateToken_BoundClaimsMismatch2280=== RUN TestValidateToken_BoundSubjectMismatch2281=== PAUSE TestValidateToken_BoundSubjectMismatch2282=== RUN TestValidateToken_MultipleProviders2283=== PAUSE TestValidateToken_MultipleProviders2284=== RUN TestValidateToken_NoMatchingProvider2285=== PAUSE TestValidateToken_NoMatchingProvider2286=== RUN TestValidateToken_KubernetesServiceAccount2287=== PAUSE TestValidateToken_KubernetesServiceAccount2288=== RUN TestNewValidator_KubernetesRequiresCA2289=== PAUSE TestNewValidator_KubernetesRequiresCA2290=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2291=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2292=== RUN TestPins_ReservedForMatchingRule2293=== PAUSE TestPins_ReservedForMatchingRule2294=== RUN TestPins_TopLevelShorthand2295=== PAUSE TestPins_TopLevelShorthand2296=== RUN TestPins_ConfigValidation2297=== PAUSE TestPins_ConfigValidation2298=== RUN TestScopes_LegacyProviderDefaultsToWrite2299=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2300=== RUN TestScopes_Rules2301=== PAUSE TestScopes_Rules2302=== RUN TestScopes_ConfigValidation2303=== PAUSE TestScopes_ConfigValidation2304=== CONT TestAudienceForIssuer2305--- PASS: TestAudienceForIssuer (0.00s)2306=== CONT TestScopes_LegacyProviderDefaultsToWrite2307=== CONT TestPins_ConfigValidation2308=== CONT TestValidateToken_NoMatchingProvider2309=== CONT TestValidateToken_MultipleProviders2310=== CONT TestValidateToken_BoundSubjectMismatch2311--- PASS: TestPins_ConfigValidation (0.00s)2312=== CONT TestValidateToken_BoundClaimsMismatch2313=== CONT TestValidateToken_Expired2314=== CONT TestValidateToken_WrongAudience2315=== CONT TestValidateToken_ValidToken2316=== CONT TestGlobMatch2317=== CONT TestScopes_ConfigValidation2318=== CONT TestPins_ReservedForMatchingRule2319=== CONT TestPins_TopLevelShorthand2320=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2321--- PASS: TestScopes_ConfigValidation (0.00s)2322=== CONT TestNewValidator_KubernetesRequiresCA2323=== CONT TestValidateToken_KubernetesServiceAccount2324=== CONT TestScopes_Rules2325=== RUN TestGlobMatch/foo_foo2326=== PAUSE TestGlobMatch/foo_foo2327=== RUN TestGlobMatch/foo_bar2328=== PAUSE TestGlobMatch/foo_bar2329=== RUN TestGlobMatch/*_2330=== PAUSE TestGlobMatch/*_2331=== RUN TestGlobMatch/*_anything2332=== PAUSE TestGlobMatch/*_anything2333=== RUN TestGlobMatch/foo*_foo2334=== PAUSE TestGlobMatch/foo*_foo2335=== RUN TestGlobMatch/foo*_foobar2336=== PAUSE TestGlobMatch/foo*_foobar2337=== RUN TestGlobMatch/foo*_bar2338=== PAUSE TestGlobMatch/foo*_bar2339=== RUN TestGlobMatch/*bar_bar2340=== PAUSE TestGlobMatch/*bar_bar2341=== RUN TestGlobMatch/*bar_foobar2342=== PAUSE TestGlobMatch/*bar_foobar2343=== RUN TestGlobMatch/*bar_foo2344=== PAUSE TestGlobMatch/*bar_foo2345=== RUN TestGlobMatch/foo*bar_foobar2346=== PAUSE TestGlobMatch/foo*bar_foobar2347=== RUN TestGlobMatch/foo*bar_foo123bar2348=== PAUSE TestGlobMatch/foo*bar_foo123bar2349=== RUN TestGlobMatch/foo*bar_foobarbaz2350=== PAUSE TestGlobMatch/foo*bar_foobarbaz2351=== RUN TestGlobMatch/*/*_foo/bar2352=== PAUSE TestGlobMatch/*/*_foo/bar2353=== RUN TestGlobMatch/*/*_foo2354=== PAUSE TestGlobMatch/*/*_foo2355=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2356=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2357=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02358=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02359=== RUN TestGlobMatch/refs/*/main_refs/heads/main2360=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2361=== RUN TestGlobMatch/fo?_foo2362=== PAUSE TestGlobMatch/fo?_foo2363=== RUN TestGlobMatch/fo?_fo2364=== PAUSE TestGlobMatch/fo?_fo2365=== RUN TestGlobMatch/fo?_fooo2366=== PAUSE TestGlobMatch/fo?_fooo2367=== RUN TestGlobMatch/?oo_foo2368=== PAUSE TestGlobMatch/?oo_foo2369=== RUN TestGlobMatch/?oo_boo2370=== PAUSE TestGlobMatch/?oo_boo2371=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2372=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2373=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2374=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2375=== CONT TestGlobMatch/foo_foo2376=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2377=== CONT TestGlobMatch/foo*_foobar2378=== CONT TestGlobMatch/fo?_foo2379=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2380=== CONT TestGlobMatch/foo*_bar2381=== CONT TestGlobMatch/?oo_foo2382=== CONT TestGlobMatch/fo?_fooo2383=== CONT TestGlobMatch/fo?_fo2384=== CONT TestGlobMatch/foo*bar_foo123bar2385=== CONT TestGlobMatch/foo*bar_foobar2386=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02387=== CONT TestGlobMatch/*bar_foo2388=== CONT TestGlobMatch/*bar_foobar2389=== CONT TestGlobMatch/*bar_bar2390=== CONT TestGlobMatch/*_anything2391=== CONT TestGlobMatch/foo*_foo2392=== CONT TestGlobMatch/foo*bar_foobarbaz2393=== CONT TestGlobMatch/?oo_boo2394=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2395=== CONT TestGlobMatch/refs/*/main_refs/heads/main2396=== CONT TestGlobMatch/*/*_foo/bar2397=== CONT TestGlobMatch/foo_bar2398=== CONT TestGlobMatch/*_2399=== CONT TestGlobMatch/*/*_foo2400--- PASS: TestGlobMatch (0.01s)2401 --- PASS: TestGlobMatch/foo_foo (0.00s)2402 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2403 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2404 --- PASS: TestGlobMatch/fo?_foo (0.00s)2405 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2406 --- PASS: TestGlobMatch/foo*_bar (0.00s)2407 --- PASS: TestGlobMatch/?oo_foo (0.00s)2408 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2409 --- PASS: TestGlobMatch/fo?_fo (0.00s)2410 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2411 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2412 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2413 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2414 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2415 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2416 --- PASS: TestGlobMatch/*bar_foo (0.00s)2417 --- PASS: TestGlobMatch/foo_bar (0.00s)2418 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2419 --- PASS: TestGlobMatch/*bar_bar (0.00s)2420 --- PASS: TestGlobMatch/*_ (0.00s)2421 --- PASS: TestGlobMatch/*_anything (0.00s)2422 --- PASS: TestGlobMatch/foo*_foo (0.00s)2423 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2424 --- PASS: TestGlobMatch/?oo_boo (0.00s)2425 --- PASS: TestGlobMatch/*/*_foo (0.00s)24262026/11/06 07:18:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34887/oidc2427--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)24282026/11/06 07:18:42 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232429--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)24302026/11/06 07:18:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36249/oidc24312026/11/06 07:18:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36211/oidc2432--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)24332026/11/06 07:18:42 http: TLS handshake error from 127.0.0.1:46100: remote error: tls: bad certificate2434--- PASS: TestNewValidator_KubernetesRequiresCA (0.05s)2435--- PASS: TestScopes_Rules (0.05s)24362026/11/06 07:18:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36755/oidc24372026/11/06 07:18:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42575/oidc2438--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)24392026/11/06 07:18:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41183/oidc2440--- PASS: TestValidateToken_WrongAudience (0.06s)2441--- PASS: TestPins_ReservedForMatchingRule (0.06s)24422026/11/06 07:18:42 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:463432443--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)24442026/11/06 07:18:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39395/oidc24452026/11/06 07:18:42 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37877/oidc2446--- PASS: TestValidateToken_Expired (0.10s)2447--- PASS: TestValidateToken_NoMatchingProvider (0.10s)24482026/11/06 07:18:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44491/oidc2449--- PASS: TestPins_TopLevelShorthand (0.15s)24502026/11/06 07:18:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41629/oidc2451--- PASS: TestValidateToken_ValidToken (0.16s)24522026/11/06 07:18:42 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34777/oidc24532026/11/06 07:18:42 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42081/oidc2454--- PASS: TestValidateToken_MultipleProviders (0.18s)2455PASS2456Running hook tests...2457=== RUN TestSendPathsEmpty2458=== PAUSE TestSendPathsEmpty2459=== RUN TestQueueEnqueueAndFetch2460=== PAUSE TestQueueEnqueueAndFetch2461=== RUN TestQueueDeduplication2462=== PAUSE TestQueueDeduplication2463=== RUN TestQueueRemove2464=== PAUSE TestQueueRemove2465=== RUN TestQueueFetchBatchLimit2466=== PAUSE TestQueueFetchBatchLimit2467=== RUN TestQueueRetryMovesToBack2468=== PAUSE TestQueueRetryMovesToBack2469=== RUN TestQueueFetchRemoveLifecycle2470=== PAUSE TestQueueFetchRemoveLifecycle2471=== RUN TestQueueConcurrentWriters2472=== PAUSE TestQueueConcurrentWriters2473=== RUN TestQueueRemoveLargeClosure2474=== PAUSE TestQueueRemoveLargeClosure2475=== RUN TestServerClientIntegration2476--- PASS: TestServerClientIntegration (0.00s)2477=== RUN TestServerQueueError24782026/11/06 07:18:42 ERROR Failed to queue paths error="permission denied" count=12479--- PASS: TestServerQueueError (0.00s)2480=== RUN TestGetListenerSocketActivation2481 server_test.go:218: === RUN TestGetListenerSocketActivation2482 --- PASS: TestGetListenerSocketActivation (0.00s)2483 PASS2484 2485--- PASS: TestGetListenerSocketActivation (0.01s)2486=== RUN TestServerStalledClientDoesNotBlockShutdown2487=== PAUSE TestServerStalledClientDoesNotBlockShutdown2488=== RUN TestServerBacksOffOnAcceptErrors2489=== PAUSE TestServerBacksOffOnAcceptErrors2490=== RUN TestDrainIsolatesPoisonPath2491=== PAUSE TestDrainIsolatesPoisonPath2492=== RUN TestRunNotBlockedByPoisonHead2493=== PAUSE TestRunNotBlockedByPoisonHead2494=== RUN TestDrainGivesUpWhenServerDown2495=== PAUSE TestDrainGivesUpWhenServerDown2496=== RUN TestFailedPathPrunedByLaterClosure2497=== PAUSE TestFailedPathPrunedByLaterClosure2498=== RUN TestWorkerUploadsAndRemoves2499=== PAUSE TestWorkerUploadsAndRemoves2500=== RUN TestWorkerSkipsGCdPaths2501=== PAUSE TestWorkerSkipsGCdPaths2502=== RUN TestWorkerPrunesClosureDeps2503=== PAUSE TestWorkerPrunesClosureDeps2504=== RUN TestDrainTimeout2505=== PAUSE TestDrainTimeout2506=== RUN TestWorkerRemoveFailureIsNotProgress2507=== PAUSE TestWorkerRemoveFailureIsNotProgress2508=== RUN TestWorkerKeepsPathItCannotStat2509=== PAUSE TestWorkerKeepsPathItCannotStat2510=== CONT TestSendPathsEmpty2511=== CONT TestRunNotBlockedByPoisonHead2512--- PASS: TestSendPathsEmpty (0.00s)2513=== CONT TestDrainIsolatesPoisonPath2514=== CONT TestServerBacksOffOnAcceptErrors25152026/11/06 07:18:42 ERROR Accept failed error="too many open files"2516=== CONT TestServerStalledClientDoesNotBlockShutdown2517=== CONT TestQueueRemoveLargeClosure2518=== CONT TestWorkerPrunesClosureDeps2519=== CONT TestQueueConcurrentWriters2520=== CONT TestWorkerKeepsPathItCannotStat2521=== CONT TestQueueFetchRemoveLifecycle2522=== CONT TestQueueRetryMovesToBack2523=== CONT TestQueueFetchBatchLimit2524=== CONT TestQueueRemove2525=== CONT TestDrainTimeout2526=== CONT TestQueueDeduplication2527=== CONT TestWorkerUploadsAndRemoves2528=== CONT TestQueueEnqueueAndFetch2529=== CONT TestWorkerRemoveFailureIsNotProgress2530=== CONT TestWorkerSkipsGCdPaths2531=== CONT TestFailedPathPrunedByLaterClosure2532=== CONT TestDrainGivesUpWhenServerDown25332026/11/06 07:18:42 ERROR Accept failed error="too many open files"25342026/11/06 07:18:42 INFO Uploading batch count=425352026/11/06 07:18:42 ERROR Upload failed error="upload failed" count=425362026/11/06 07:18:42 INFO Upload queue status pending=225372026/11/06 07:18:42 INFO Upload queue status pending=325382026/11/06 07:18:42 INFO Uploading batch count=125392026/11/06 07:18:42 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3500312266/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3500312266/002/locked/aaa: permission denied"25402026/11/06 07:18:42 INFO Uploading batch count=125412026/11/06 07:18:42 ERROR Upload failed error="upload failed" count=125422026/11/06 07:18:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3799753744/002/bbb25432026/11/06 07:18:42 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3500312266/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3500312266/002/locked/aaa: permission denied"25442026/11/06 07:18:42 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3500312266/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3500312266/002/locked/aaa: permission denied"25452026/11/06 07:18:42 INFO Uploading batch count=22546--- PASS: TestQueueFetchBatchLimit (0.01s)25472026/11/06 07:18:42 INFO Upload queue status pending=225482026/11/06 07:18:42 INFO Uploading batch count=22549--- PASS: TestQueueRetryMovesToBack (0.01s)25502026/11/06 07:18:42 INFO Uploading batch count=125512026/11/06 07:18:42 ERROR Upload failed error="upload failed" count=125522026/11/06 07:18:42 ERROR Drain finished with paths left in queue remaining=125532026/11/06 07:18:42 INFO Uploading batch count=225542026/11/06 07:18:42 ERROR Upload failed error="upload failed" count=225552026/11/06 07:18:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3956353610/002/a25562026/11/06 07:18:42 INFO Upload queue status pending=22557--- PASS: TestQueueFetchRemoveLifecycle (0.01s)25582026/11/06 07:18:42 INFO Uploading batch count=125592026/11/06 07:18:42 ERROR Upload failed error="upload failed" count=125602026/11/06 07:18:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2609755339/002/nonexistent2561--- PASS: TestQueueRemove (0.01s)25622026/11/06 07:18:42 INFO Uploading batch count=125632026/11/06 07:18:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3956353610/002/b25642026/11/06 07:18:42 INFO Uploading batch count=125652026/11/06 07:18:42 ERROR Upload failed error="upload failed" count=125662026/11/06 07:18:42 INFO Uploading batch count=125672026/11/06 07:18:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1002129272/002/nonexistent25682026/11/06 07:18:42 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125692026/11/06 07:18:42 INFO Uploading batch count=22570--- PASS: TestQueueEnqueueAndFetch (0.01s)25712026/11/06 07:18:42 ERROR Upload failed error="upload failed" count=22572--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)25732026/11/06 07:18:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3956353610/002/c25742026/11/06 07:18:42 ERROR Accept failed error="too many open files"25752026/11/06 07:18:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1002129272/002/nonexistent25762026/11/06 07:18:42 INFO Uploading batch count=125772026/11/06 07:18:42 ERROR Upload failed error="upload failed" count=125782026/11/06 07:18:42 INFO Uploading batch count=125792026/11/06 07:18:42 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12580--- PASS: TestQueueDeduplication (0.01s)25812026/11/06 07:18:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1002129272/002/nonexistent25822026/11/06 07:18:42 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125832026/11/06 07:18:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3956353610/002/d25842026/11/06 07:18:42 ERROR Drain finished with paths left in queue remaining=125852026/11/06 07:18:42 ERROR Drain finished with paths left in queue remaining=125862026/11/06 07:18:42 INFO Uploading batch count=225872026/11/06 07:18:42 ERROR Upload failed error="upload failed" count=225882026/11/06 07:18:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3956353610/002/e2589--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)25902026/11/06 07:18:42 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3956353610/002/f2591--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2592--- PASS: TestDrainIsolatesPoisonPath (0.02s)25932026/11/06 07:18:42 ERROR Drain finished with paths left in queue remaining=102594--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2595--- PASS: TestWorkerPrunesClosureDeps (0.03s)2596--- PASS: TestWorkerUploadsAndRemoves (0.03s)2597--- PASS: TestWorkerSkipsGCdPaths (0.03s)25982026/11/06 07:18:42 ERROR Accept failed error="too many open files"2599--- PASS: TestQueueRemoveLargeClosure (0.05s)26002026/11/06 07:18:42 ERROR Accept failed error="too many open files"26012026/11/06 07:18:42 ERROR Accept failed error="too many open files"26022026/11/06 07:18:42 ERROR Failed to decode request error="read unix /build/hook3647692465/test.sock->@: i/o timeout"26032026/11/06 07:18:42 ERROR Failed to write response error="write unix /build/hook3647692465/test.sock->@: i/o timeout"2604--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)2605--- PASS: TestQueueConcurrentWriters (0.21s)26062026/11/06 07:18:42 ERROR Upload failed error="context deadline exceeded" count=226072026/11/06 07:18:42 ERROR Drain finished with paths left in queue remaining=42608--- PASS: TestDrainTimeout (0.21s)26092026/11/06 07:18:42 ERROR Accept failed error="too many open files"26102026/11/06 07:18:43 ERROR Accept failed error="too many open files"2611--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26122026/11/06 07:18:43 INFO Uploading batch count=126132026/11/06 07:18:43 INFO Uploading batch count=126142026/11/06 07:18:43 INFO Uploading batch count=126152026/11/06 07:18:43 ERROR Upload failed error="upload failed" count=126162026/11/06 07:18:43 INFO Uploading batch count=126172026/11/06 07:18:43 ERROR Upload failed error="upload failed" count=126182026/11/06 07:18:43 INFO Uploading batch count=126192026/11/06 07:18:43 ERROR Upload failed error="upload failed" count=126202026/11/06 07:18:43 INFO Uploading batch count=126212026/11/06 07:18:43 ERROR Upload failed error="upload failed" count=126222026/11/06 07:18:43 ERROR Drain finished with paths left in queue remaining=12623--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2624PASS2625Running signing tests...2626=== RUN TestExternalSigner2627=== PAUSE TestExternalSigner2628=== RUN TestExternalSignerWrongPublicKey2629=== PAUSE TestExternalSignerWrongPublicKey2630=== RUN TestExternalSignerErrors2631=== PAUSE TestExternalSignerErrors2632=== RUN TestExternalSignerRestartsAfterCrash2633=== PAUSE TestExternalSignerRestartsAfterCrash2634=== RUN TestExternalSignerProgramErrorKeepsProcess2635=== PAUSE TestExternalSignerProgramErrorKeepsProcess2636=== RUN TestExternalSignerClose2637=== PAUSE TestExternalSignerClose2638=== RUN TestExternalSignerRejectsInvalidPublicKey2639=== PAUSE TestExternalSignerRejectsInvalidPublicKey2640=== RUN TestExternalSignerCancellation2641=== PAUSE TestExternalSignerCancellation2642=== RUN TestGenerateFingerprint2643=== PAUSE TestGenerateFingerprint2644=== RUN TestParseSigningKey2645=== PAUSE TestParseSigningKey2646=== RUN TestSign2647=== PAUSE TestSign2648=== RUN TestSignBatch2649=== PAUSE TestSignBatch2650=== RUN TestNilKeyPublicKey2651=== PAUSE TestNilKeyPublicKey2652=== RUN TestSignErrors2653=== PAUSE TestSignErrors2654=== CONT TestExternalSigner2655=== CONT TestExternalSignerProgramErrorKeepsProcess2656=== CONT TestGenerateFingerprint2657=== RUN TestGenerateFingerprint/basic_with_references2658=== PAUSE TestGenerateFingerprint/basic_with_references2659=== RUN TestGenerateFingerprint/no_references2660=== CONT TestExternalSignerErrors2661=== CONT TestSignErrors2662=== RUN TestExternalSignerErrors/wrong_shape2663=== CONT TestNilKeyPublicKey2664=== CONT TestSignBatch2665=== CONT TestSign2666=== CONT TestParseSigningKey2667=== CONT TestExternalSignerRestartsAfterCrash2668=== CONT TestExternalSignerWrongPublicKey2669=== CONT TestExternalSignerRejectsInvalidPublicKey2670=== CONT TestExternalSignerClose2671=== CONT TestExternalSignerCancellation2672=== PAUSE TestGenerateFingerprint/no_references2673=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2674=== RUN TestExternalSignerRejectsInvalidPublicKey/#002675=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002676=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2677=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2678=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2679=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2680=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2681=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2682=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2683=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2684=== CONT TestExternalSignerRejectsInvalidPublicKey/#002685=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2686=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2687=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2688=== RUN TestParseSigningKey/valid_32-byte_key2689=== PAUSE TestParseSigningKey/valid_32-byte_key2690=== PAUSE TestExternalSignerErrors/wrong_shape2691=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2692--- PASS: TestNilKeyPublicKey (0.00s)2693=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2694--- PASS: TestSignBatch (0.00s)2695=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2696=== RUN TestSignErrors/nil_key2697=== PAUSE TestSignErrors/nil_key2698=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2699=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2700=== RUN TestExternalSignerErrors/unrequested_key2701=== PAUSE TestExternalSignerErrors/unrequested_key2702=== RUN TestExternalSignerErrors/wrong_signature_name2703=== PAUSE TestExternalSignerErrors/wrong_signature_name2704=== RUN TestExternalSignerErrors/exit_at_startup2705=== PAUSE TestExternalSignerErrors/exit_at_startup2706=== RUN TestExternalSignerErrors/wrong_id2707=== PAUSE TestExternalSignerErrors/wrong_id2708=== RUN TestExternalSignerErrors/null_signatures2709=== PAUSE TestExternalSignerErrors/null_signatures2710=== RUN TestExternalSignerErrors/missing_signature_name2711=== PAUSE TestExternalSignerErrors/missing_signature_name2712=== RUN TestExternalSignerErrors/wrong_signature_length2713=== PAUSE TestExternalSignerErrors/wrong_signature_length2714=== RUN TestExternalSignerErrors/exit_on_request2715=== PAUSE TestExternalSignerErrors/exit_on_request2716=== RUN TestExternalSignerErrors/missing_signatures2717=== PAUSE TestExternalSignerErrors/missing_signatures2718=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2719--- PASS: TestSign (0.00s)2720=== RUN TestSignErrors/nil_narinfo2721=== RUN TestGenerateFingerprint/invalid_nar_hash_length2722=== RUN TestExternalSignerErrors/too_few_signatures2723=== RUN TestParseSigningKey/no_colon2724=== PAUSE TestParseSigningKey/no_colon2725--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2726 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2727 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2728 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2729 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2730 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2731=== PAUSE TestSignErrors/nil_narinfo2732=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2733=== PAUSE TestExternalSignerErrors/too_few_signatures2734=== RUN TestExternalSignerErrors/invalid_signature_base642735=== PAUSE TestExternalSignerErrors/invalid_signature_base642736=== RUN TestExternalSignerErrors/program_error2737=== RUN TestParseSigningKey/empty_name2738=== RUN TestSignErrors/invalid_narinfo2739=== PAUSE TestSignErrors/invalid_narinfo2740=== RUN TestSignErrors/canceled2741=== PAUSE TestSignErrors/canceled2742=== CONT TestSignErrors/nil_key2743=== CONT TestSignErrors/canceled2744=== RUN TestGenerateFingerprint/invalid_store_path_prefix2745=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2746=== RUN TestGenerateFingerprint/invalid_reference_prefix2747=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2748=== PAUSE TestExternalSignerErrors/program_error2749=== PAUSE TestParseSigningKey/empty_name2750=== RUN TestParseSigningKey/invalid_base642751=== PAUSE TestParseSigningKey/invalid_base642752=== RUN TestParseSigningKey/wrong_length2753=== PAUSE TestParseSigningKey/wrong_length2754=== CONT TestSignErrors/invalid_narinfo2755=== CONT TestSignErrors/nil_narinfo2756--- PASS: TestSignErrors (0.00s)2757 --- PASS: TestSignErrors/nil_key (0.00s)2758 --- PASS: TestSignErrors/canceled (0.00s)2759 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2760 --- PASS: TestSignErrors/nil_narinfo (0.00s)2761=== CONT TestGenerateFingerprint/basic_with_references2762=== CONT TestGenerateFingerprint/invalid_reference_prefix2763=== CONT TestGenerateFingerprint/invalid_store_path_prefix2764=== CONT TestGenerateFingerprint/invalid_nar_hash_length2765=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2766=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2767=== CONT TestGenerateFingerprint/no_references2768--- PASS: TestGenerateFingerprint (0.00s)2769 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2770 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2771 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2772 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2773 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2774 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2775 --- PASS: TestGenerateFingerprint/no_references (0.00s)2776=== RUN TestExternalSignerErrors/invalid_JSON2777=== PAUSE TestExternalSignerErrors/invalid_JSON2778=== CONT TestParseSigningKey/valid_32-byte_key2779=== CONT TestParseSigningKey/wrong_length2780=== CONT TestParseSigningKey/no_colon2781=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2782=== CONT TestParseSigningKey/empty_name2783=== CONT TestParseSigningKey/invalid_base642784--- PASS: TestParseSigningKey (0.00s)2785 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2786 --- PASS: TestParseSigningKey/wrong_length (0.00s)2787 --- PASS: TestParseSigningKey/no_colon (0.00s)2788 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2789 --- PASS: TestParseSigningKey/empty_name (0.00s)2790 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2791=== RUN TestExternalSignerErrors/null2792=== PAUSE TestExternalSignerErrors/null2793=== RUN TestExternalSignerErrors/wrong_signatures_shape2794=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2795=== CONT TestExternalSignerErrors/wrong_shape2796=== CONT TestExternalSignerErrors/wrong_signature_length2797=== CONT TestExternalSignerErrors/too_few_signatures2798=== CONT TestExternalSignerErrors/wrong_signatures_shape2799=== CONT TestExternalSignerErrors/null2800=== CONT TestExternalSignerErrors/program_error2801=== CONT TestExternalSignerErrors/invalid_signature_base642802=== CONT TestExternalSignerErrors/missing_signatures2803=== CONT TestExternalSignerErrors/wrong_id2804=== CONT TestExternalSignerErrors/missing_signature_name2805=== CONT TestExternalSignerErrors/exit_on_request2806=== CONT TestExternalSignerErrors/null_signatures2807=== CONT TestExternalSignerErrors/wrong_signature_name2808=== CONT TestExternalSignerErrors/exit_at_startup2809=== CONT TestExternalSignerErrors/invalid_JSON2810=== CONT TestExternalSignerErrors/unrequested_key2811--- PASS: TestExternalSignerWrongPublicKey (0.00s)2812--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2813--- PASS: TestExternalSignerClose (0.01s)2814--- PASS: TestExternalSigner (0.01s)2815--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2816--- PASS: TestExternalSignerErrors (0.00s)2817 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2818 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2819 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2820 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2821 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2822 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2823 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2824 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2825 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2826 --- PASS: TestExternalSignerErrors/null (0.01s)2827 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2828 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2829 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2830 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2831 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2832 --- PASS: TestExternalSignerErrors/program_error (0.01s)2833--- PASS: TestExternalSignerCancellation (0.02s)2834PASS2835Running OpenBao signer tests...2836=== RUN TestSign2837=== PAUSE TestSign2838=== RUN TestSignErrors2839=== PAUSE TestSignErrors2840=== RUN TestServe2841=== PAUSE TestServe2842=== RUN TestServeRejectsGarbage2843=== PAUSE TestServeRejectsGarbage2844=== CONT TestSign2845=== CONT TestServeRejectsGarbage2846=== CONT TestSignErrors2847=== RUN TestSignErrors/invalid_json2848=== PAUSE TestSignErrors/invalid_json2849--- PASS: TestServeRejectsGarbage (0.00s)2850=== CONT TestServe2851=== RUN TestSignErrors/no_prefix2852=== PAUSE TestSignErrors/no_prefix2853=== RUN TestSignErrors/invalid_base642854--- PASS: TestServe (0.00s)2855=== PAUSE TestSignErrors/invalid_base642856=== RUN TestSignErrors/http_error2857=== PAUSE TestSignErrors/http_error2858=== CONT TestSignErrors/invalid_json2859=== CONT TestSignErrors/invalid_base642860=== CONT TestSignErrors/no_prefix2861=== CONT TestSignErrors/http_error2862--- PASS: TestSign (0.00s)2863--- PASS: TestSignErrors (0.00s)2864 --- PASS: TestSignErrors/invalid_json (0.00s)2865 --- PASS: TestSignErrors/invalid_base64 (0.00s)2866 --- PASS: TestSignErrors/http_error (0.00s)2867 --- PASS: TestSignErrors/no_prefix (0.00s)2868PASS