niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #490
· 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 TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestDumpPathMatchesNix28=== PAUSE TestDumpPathMatchesNix29=== RUN TestDumpPathSingleFile30=== PAUSE TestDumpPathSingleFile31=== RUN TestDumpPathWriterError32=== PAUSE TestDumpPathWriterError33=== RUN TestEncodeNixBase3234=== PAUSE TestEncodeNixBase3235=== RUN TestEncodeNixBase32WithRealHash36=== PAUSE TestEncodeNixBase32WithRealHash37=== RUN TestConvertHashToNix3238=== PAUSE TestConvertHashToNix3239=== RUN TestGetStorePathHash40=== PAUSE TestGetStorePathHash41=== RUN TestPathInfoHashCompatibility42=== PAUSE TestPathInfoHashCompatibility43=== RUN TestParsePathInfoJSON44=== PAUSE TestParsePathInfoJSON45=== RUN TestParsePathInfoJSONMultiplePaths46=== PAUSE TestParsePathInfoJSONMultiplePaths47=== RUN TestPathInfoCACompatibility48=== PAUSE TestPathInfoCACompatibility49=== RUN TestRateLimiterFeedback50=== PAUSE TestRateLimiterFeedback51=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess52=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess53=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer54=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer55=== RUN TestRegisterUploadedObject_OutlivesPush56=== PAUSE TestRegisterUploadedObject_OutlivesPush57=== RUN TestResolveStorePath58=== PAUSE TestResolveStorePath59=== RUN TestDoWithRetry_BodyReplayedViaGetBody60=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody61=== RUN TestRetryTimeoutOutlastsMaxRetries62=== PAUSE TestRetryTimeoutOutlastsMaxRetries63=== RUN TestDoWithRetry_FinalResponseBodyReadable64=== PAUSE TestDoWithRetry_FinalResponseBodyReadable65=== RUN TestShellSplit66=== PAUSE TestShellSplit67=== RUN TestShellSplitErrors68=== PAUSE TestShellSplitErrors69=== RUN TestStreamPushReportsEveryPath70=== PAUSE TestStreamPushReportsEveryPath71=== RUN TestStreamPushBatchesUnderLoad72=== PAUSE TestStreamPushBatchesUnderLoad73=== RUN TestStreamPushIsolatesFailures74=== PAUSE TestStreamPushIsolatesFailures75=== RUN TestStreamPushGivesUpOnDeadServer76=== PAUSE TestStreamPushGivesUpOnDeadServer77=== RUN TestStreamPushRequestLine78=== PAUSE TestStreamPushRequestLine79=== RUN TestStreamPushReportsSignatures80=== PAUSE TestStreamPushReportsSignatures81=== RUN TestStreamPushReportsSkippedPaths82=== PAUSE TestStreamPushReportsSkippedPaths83=== RUN TestClientSignaturesByStorePath84=== PAUSE TestClientSignaturesByStorePath85=== RUN TestStreamPushStopsWhenCanceled86=== PAUSE TestStreamPushStopsWhenCanceled87=== RUN TestSetClientTLS88=== PAUSE TestSetClientTLS89=== RUN TestSetClientTLSDoesNotMutateDefaultTransport90=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport91=== RUN TestSetClientTLSErrors92=== PAUSE TestSetClientTLSErrors93=== RUN TestStaticToken94=== PAUSE TestStaticToken95=== RUN TestFileTokenReadsAndCaches96=== PAUSE TestFileTokenReadsAndCaches97=== RUN TestFileTokenMissing98=== PAUSE TestFileTokenMissing99=== RUN TestFileTokenEmpty100=== PAUSE TestFileTokenEmpty101=== RUN TestScriptTokenNoExpiryRerunsEveryCall102=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall103=== RUN TestScriptTokenCachesUntilRefresh104=== PAUSE TestScriptTokenCachesUntilRefresh105=== RUN TestScriptTokenEmptyToken106=== PAUSE TestScriptTokenEmptyToken107=== RUN TestScriptTokenBadJSON108=== PAUSE TestScriptTokenBadJSON109=== RUN TestScriptTokenScriptFails110=== PAUSE TestScriptTokenScriptFails111=== RUN TestScriptTokenEmptyCommand112=== PAUSE TestScriptTokenEmptyCommand113=== CONT TestDoServerRequestAttachesToken114=== CONT TestRetryTimeoutOutlastsMaxRetries115=== CONT TestSetClientTLS116=== CONT TestFileTokenEmpty117=== CONT TestFileTokenMissing118--- PASS: TestFileTokenEmpty (0.00s)119=== CONT TestParsePathInfoJSONMultiplePaths120=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths121=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths122=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths123=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths124=== CONT TestParsePathInfoJSON125=== RUN TestParsePathInfoJSON/Nix_format126=== PAUSE TestParsePathInfoJSON/Nix_format127=== RUN TestParsePathInfoJSON/Lix_format128=== CONT TestFileTokenReadsAndCaches129=== CONT TestStaticToken130=== CONT TestSetClientTLSErrors131=== CONT TestSetClientTLSDoesNotMutateDefaultTransport132=== CONT TestScriptTokenBadJSON133=== CONT TestScriptTokenEmptyCommand134=== CONT TestScriptTokenScriptFails135=== CONT TestEncodeNixBase32WithRealHash136=== CONT TestDoWithRetry_BodyReplayedViaGetBody137=== CONT TestScriptTokenNoExpiryRerunsEveryCall138=== CONT TestResolveStorePath139=== CONT TestScriptTokenEmptyToken140=== CONT TestRegisterUploadedObject_OutlivesPush141=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer142=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess143=== CONT TestRateLimiterFeedback144=== CONT TestScriptTokenCachesUntilRefresh145=== CONT TestPathInfoCACompatibility146=== CONT TestStreamPushGivesUpOnDeadServer147=== PAUSE TestParsePathInfoJSON/Lix_format148=== RUN TestParsePathInfoJSON/empty_input149=== PAUSE TestParsePathInfoJSON/empty_input150=== RUN TestParsePathInfoJSON/whitespace_only151=== PAUSE TestParsePathInfoJSON/whitespace_only152=== RUN TestParsePathInfoJSON/invalid_JSON153=== PAUSE TestParsePathInfoJSON/invalid_JSON154--- PASS: TestEncodeNixBase32WithRealHash (0.00s)155=== CONT TestPathInfoHashCompatibility156=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)157=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)158=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon160=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI161=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI162=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512163=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512164--- PASS: TestFileTokenMissing (0.00s)165=== CONT TestGetStorePathHash166=== RUN TestGetStorePathHash/valid_store_path167=== PAUSE TestGetStorePathHash/valid_store_path168=== RUN TestGetStorePathHash/basename_without_hyphen_should_error169=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error170=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error171=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error172=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error173=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error174=== CONT TestConvertHashToNix32175=== RUN TestConvertHashToNix32/SRI_format_to_Nix32176=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32177=== RUN TestConvertHashToNix32/already_Nix32_format178=== PAUSE TestConvertHashToNix32/already_Nix32_format179=== RUN TestConvertHashToNix32/invalid_format180=== PAUSE TestConvertHashToNix32/invalid_format181=== CONT TestStreamPushBatchesUnderLoad182=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false183=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false184=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true185=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true186=== CONT TestStreamPushReportsSkippedPaths187=== CONT TestStreamPushReportsEveryPath1882026/11/11 23:34:36 WARN Rate limiter enabled after throttle name=server-test rate=5189--- PASS: TestScriptTokenEmptyCommand (0.00s)190--- PASS: TestResolveStorePath (0.00s)191--- PASS: TestStreamPushReportsSkippedPaths (0.00s)192=== CONT TestDoWithRetry_FinalResponseBodyReadable1932026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:46287194=== RUN TestRateLimiterFeedback/429_enables_limiter195=== CONT TestStreamPushIsolatesFailures196=== CONT TestStreamPushStopsWhenCanceled197=== CONT TestStreamPushRequestLine198=== RUN TestSetClientTLSErrors/missing_cert_file199=== CONT TestStreamPushReportsSignatures200--- PASS: TestScriptTokenScriptFails (0.00s)201--- PASS: TestStaticToken (0.00s)202=== RUN TestPathInfoCACompatibility/null_ca_field203=== CONT TestClientSignaturesByStorePath204=== PAUSE TestSetClientTLSErrors/missing_cert_file205=== CONT TestUploadMultipart_PartsInParallel206=== CONT TestEncodeNixBase32207=== PAUSE TestRateLimiterFeedback/429_enables_limiter208--- PASS: TestStreamPushStopsWhenCanceled (0.00s)209=== PAUSE TestPathInfoCACompatibility/null_ca_field2102026/11/11 23:34:37 ERROR Upload failed error=boom count=1211--- PASS: TestStreamPushReportsEveryPath (0.00s)212=== RUN TestPathInfoCACompatibility/old_string_format_-_text2132026/11/11 23:34:37 ERROR Upload failed error="connection refused" count=20214--- PASS: TestFileTokenReadsAndCaches (0.00s)2152026/11/11 23:34:37 ERROR Server seems unavailable, giving up on batch untried=17216--- PASS: TestClientSignaturesByStorePath (0.00s)217=== CONT TestRegisterUploadedObjectReusesConnections218=== RUN TestSetClientTLSErrors/missing_key_file2192026/11/11 23:34:37 WARN Rate limiter enabled after throttle name=server-test rate=5220=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text2212026/11/11 23:34:37 ERROR Upload failed error="bad path" count=3222=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun223=== CONT TestFilterOversizedClosures224--- PASS: TestScriptTokenBadJSON (0.01s)2252026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:41687226=== PAUSE TestSetClientTLSErrors/missing_key_file227--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)228=== CONT TestDumpPathWriterError2292026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46287230=== RUN TestRateLimiterFeedback/503_enables_limiter2312026/11/11 23:34:37 WARN Rate limiter enabled after throttle name=server-test rate=5232=== PAUSE TestRateLimiterFeedback/503_enables_limiter233=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter234=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter235=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter2362026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:43955237=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter238--- PASS: TestDoServerRequestAttachesToken (0.04s)239=== CONT TestShellSplitErrors240=== RUN TestSetClientTLS/rejects_connection_without_client_cert241=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert242=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA243=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA244=== RUN TestSetClientTLS/preserves_debug_logging_transport245=== PAUSE TestSetClientTLS/preserves_debug_logging_transport246=== RUN TestSetClientTLSErrors/missing_ca_file2472026/11/11 23:34:37 ERROR Upload failed error=boom count=1248=== PAUSE TestSetClientTLSErrors/missing_ca_file249=== RUN TestSetClientTLSErrors/invalid_ca_file250=== PAUSE TestSetClientTLSErrors/invalid_ca_file251=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive252=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive253=== RUN TestPathInfoCACompatibility/new_structured_format_-_text254=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text255=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method256=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method257=== CONT TestDumpPathSingleFile258=== CONT TestShellSplit259=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2602026/11/11 23:34:37 WARN Rate limiter backed off name=server-test rate=5261=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths262=== RUN TestFilterOversizedClosures/no_limit_keeps_everything263=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything264=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped265=== CONT TestParsePathInfoJSON/Nix_format266=== CONT TestConvertHashToNix32/SRI_format_to_Nix32267=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error268=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error269=== CONT TestGetStorePathHash/basename_without_hyphen_should_error270=== CONT TestConvertHashToNix32/invalid_format271=== CONT TestConvertHashToNix32/already_Nix32_format272=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true273=== RUN TestEncodeNixBase32/test_string_hash274=== PAUSE TestEncodeNixBase32/test_string_hash275=== RUN TestEncodeNixBase32/empty_input276=== PAUSE TestEncodeNixBase32/empty_input277--- PASS: TestShellSplitErrors (0.00s)278--- PASS: TestStreamPushReportsSignatures (0.03s)279--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)280--- PASS: TestRegisterUploadedObject_OutlivesPush (0.04s)281--- PASS: TestShellSplit (0.00s)282=== CONT TestParsePathInfoJSON/invalid_JSON283=== CONT TestParsePathInfoJSON/whitespace_only284=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI285=== CONT TestParsePathInfoJSON/empty_input286=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512287=== CONT TestParsePathInfoJSON/Lix_format288=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon2892026/11/11 23:34:37 WARN Rate limiter backed off name=server-test rate=5290=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2912026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:41687292=== CONT TestUploadMultipart_ReturnsAfterDroppedBody2932026/11/11 23:34:37 INFO Garbage collection started294=== CONT TestRateLimiterFeedback/429_enables_limiter295=== CONT TestPartSizeForNAR296=== RUN TestPartSizeForNAR/zero_stays_at_minimum297=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false298=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)299=== CONT TestRateLimiterFeedback/503_enables_limiter300=== CONT TestSetClientTLS/rejects_connection_without_client_cert301=== CONT TestSetClientTLSErrors/missing_cert_file302=== CONT TestCaseHackSuffix303=== CONT TestGetStorePathHash/valid_store_path304=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica305=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped306--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)307--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.03s)308=== CONT TestDumpPathMatchesNix309=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum310=== RUN TestPartSizeForNAR/small_stays_at_minimum311=== PAUSE TestPartSizeForNAR/small_stays_at_minimum312=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum313=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum314=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts315=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts316=== RUN TestPartSizeForNAR/1_TiB317=== PAUSE TestPartSizeForNAR/1_TiB318=== RUN TestPartSizeForNAR/5_TiB_S3_max_object319=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object320=== RUN TestPartSizeForNAR/capped_at_5_GiB321=== CONT TestPathInfoCACompatibility/null_ca_field3222026/11/11 23:34:37 WARN Rate limiter enabled after throttle name=server-test rate=5323=== CONT TestSetClientTLSErrors/missing_ca_file3242026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:423693252026/11/11 23:34:37 WARN Rate limiter enabled after throttle name=server-test rate=5326=== CONT TestSetClientTLSErrors/missing_key_file3272026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:38913328=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3292026/11/11 23:34:37 WARN Rate limiter backed off name=server-test rate=5330=== CONT TestPathInfoCACompatibility/old_string_format_-_text3312026/11/11 23:34:37 WARN Rate limiter backed off name=server-test rate=5332=== CONT TestEncodeNixBase32/test_string_hash333=== PAUSE TestPartSizeForNAR/capped_at_5_GiB334=== CONT TestSetClientTLS/preserves_debug_logging_transport3352026/11/11 23:34:37 INFO Garbage collection started336=== RUN TestFilterOversizedClosures/all_closures_skipped3372026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:46287338=== CONT TestSetClientTLSErrors/invalid_ca_file339=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts340--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)341=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter342=== CONT TestPathInfoCACompatibility/new_structured_format_-_text343=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive344=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry345=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA346=== CONT TestPartSizeForNAR/zero_stays_at_minimum3472026/11/11 23:34:37 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=0348=== CONT TestEncodeNixBase32/empty_input3492026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46287350=== CONT TestPartSizeForNAR/1_TiB351=== PAUSE TestFilterOversizedClosures/all_closures_skipped352=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum353--- PASS: TestStreamPushIsolatesFailures (0.03s)354--- PASS: TestScriptTokenEmptyToken (0.03s)355--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)356 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)357 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)358--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.00s)359--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)360--- PASS: TestParsePathInfoJSON (0.00s)361 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)362 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)363 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)364 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)365 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)366=== CONT TestPartSizeForNAR/small_stays_at_minimum367=== CONT TestPartSizeForNAR/5_TiB_S3_max_object368=== CONT TestPartSizeForNAR/capped_at_5_GiB369=== CONT TestFilterOversizedClosures/no_limit_keeps_everything370=== CONT TestFilterOversizedClosures/all_closures_skipped3712026/11/11 23:34:37 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=50372=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3732026/11/11 23:34:37 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=20003742026/11/11 23:34:37 WARN Garbage collection finished on another replica. Its statistics are not available here375--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)376--- PASS: TestPathInfoCACompatibility (0.03s)377 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)378 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)379 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)380 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)381 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)3822026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:46287383--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)384--- PASS: TestRateLimiterFeedback (0.04s)385 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)386 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)387 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)388 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)389--- PASS: TestEncodeNixBase32 (0.03s)390 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)391 --- PASS: TestEncodeNixBase32/empty_input (0.00s)392--- PASS: TestStreamPushBatchesUnderLoad (0.00s)393 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)394 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)395--- PASS: TestConvertHashToNix32 (0.00s)396 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)397 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)398 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)399--- PASS: TestPathInfoHashCompatibility (0.00s)400 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)401 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)402 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)403 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)404--- PASS: TestGetStorePathHash (0.00s)405 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)406 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)407 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)408 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)4092026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:46287410--- PASS: TestSetClientTLSErrors (0.04s)411 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)412 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)413 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)414 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)4152026/11/11 23:34:37 WARN Rate limiter enabled after throttle name=s3-test rate=5416--- PASS: TestPartSizeForNAR (0.00s)417 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)418 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)419 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)420 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)421 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)422 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)423 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)4242026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:40741425--- PASS: TestFilterOversizedClosures (0.01s)426 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)427 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)428 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)429--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)4302026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:462874312026/11/11 23:34:37 http: TLS handshake error from 127.0.0.1:50966: remote error: tls: bad certificate4322026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:46287433--- PASS: TestSetClientTLS (0.04s)434 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)435 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)436 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)4372026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:46287438--- PASS: TestStreamPushRequestLine (0.05s)4392026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:462874402026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:46287441--- PASS: TestCaseHackSuffix (0.03s)442--- PASS: TestDumpPathSingleFile (0.03s)4432026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:462874442026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:462874452026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:462874462026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:462874472026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:46287448--- PASS: TestRegisterUploadedObjectReusesConnections (0.07s)4492026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:462874502026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:462874512026/11/11 23:34:37 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:46287452--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.09s)453--- PASS: TestDumpPathWriterError (0.09s)4542026/11/11 23:34:37 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46631/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46631/api/uploads/complete4552026/11/11 23:34:37 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4562026/11/11 23:34:37 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46631/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46631/api/uploads/complete4572026/11/11 23:34:37 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4582026/11/11 23:34:37 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46631/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46631/api/uploads/complete4592026/11/11 23:34:37 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"460--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.10s)461--- PASS: TestDumpPathMatchesNix (0.08s)462--- PASS: TestUploadMultipart_PartsInParallel (0.66s)463--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)464PASS465Running server tests...466The files belonging to this database system will be owned by user "nixbld".467This user must also own the server process.468469The database cluster will be initialized with locale "C".470The default database encoding has accordingly been set to "SQL_ASCII".471The default text search configuration will be set to "english".472473Data page checksums are enabled.474475creating directory /build/postgres1087680700/data ... ok476creating subdirectories ... ok477selecting dynamic shared memory implementation ... posix478selecting default "max_connections" ... 100479selecting default "shared_buffers" ... 128MB480selecting default time zone ... UTC481creating configuration files ... ok482running bootstrap script ... ok483performing post-bootstrap initialization ... ok484syncing data to disk ... ok485486initdb: warning: enabling "trust" authentication for local connections487initdb: 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.488489Success. You can now start the database server using:490491 pg_ctl -D /build/postgres1087680700/data -l logfile start492493/build/postgres1087680700:5432 - no response4942026-11-11 23:34:38.830 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4952026-11-11 23:34:38.831 UTC [129] LOG: listening on Unix socket "/build/postgres1087680700/.s.PGSQL.5432"4962026-11-11 23:34:38.836 UTC [136] LOG: database system was shut down at 2026-11-11 23:34:38 UTC4972026-11-11 23:34:38.839 UTC [129] LOG: database system is ready to accept connections498/build/postgres1087680700:5432 - accepting connections499{"timestamp":"2026-11-11T23:34:39.137294867Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"18bc8713-a77d-42aa-967f-45ed0566849d","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(397)"}500=== RUN TestAbortSucceeded501=== PAUSE TestAbortSucceeded502=== RUN TestService_AuthMiddleware503=== PAUSE TestService_AuthMiddleware504=== RUN TestService_AuthMiddleware_MTLSProxyHeader505=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader506=== RUN TestService_AuthMiddleware_MTLSBoundSubjects507=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects508=== RUN TestService_ReadAuthMiddleware509=== PAUSE TestService_ReadAuthMiddleware510=== RUN TestService_AuthMiddleware_OIDC511=== PAUSE TestService_AuthMiddleware_OIDC512=== RUN TestService_RequireScope_OIDC513=== PAUSE TestService_RequireScope_OIDC514=== RUN TestService_ReadScope_PublicByDefault515=== PAUSE TestService_ReadScope_PublicByDefault516=== RUN TestCacheConfigHandler517=== PAUSE TestCacheConfigHandler518=== RUN TestCacheStatsHandler519=== PAUSE TestCacheStatsHandler520=== RUN TestClientCADerivations521=== PAUSE TestClientCADerivations522=== RUN TestClientErrorHandling523=== PAUSE TestClientErrorHandling524=== RUN TestClientIntegration525=== PAUSE TestClientIntegration526=== RUN TestClientMultipleUploads527=== PAUSE TestClientMultipleUploads528=== RUN TestClientWithDependencies529=== PAUSE TestClientWithDependencies530=== RUN TestClientSharedPathCommittedMidPush531=== PAUSE TestClientSharedPathCommittedMidPush532=== RUN TestPinProtectsFromGC533=== PAUSE TestPinProtectsFromGC534=== RUN TestClientPushesUseOnePush535=== PAUSE TestClientPushesUseOnePush536=== RUN TestClientFallsBackToClosures537=== PAUSE TestClientFallsBackToClosures538=== RUN TestDeleteClosuresRacingPins539=== PAUSE TestDeleteClosuresRacingPins540=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock541=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock542=== RUN TestResolveDBConnectionString543=== PAUSE TestResolveDBConnectionString544=== RUN TestConnectWaitsForAPeerMigration545=== PAUSE TestConnectWaitsForAPeerMigration546=== RUN TestLeadElectsOneAndHandsOver547=== PAUSE TestLeadElectsOneAndHandsOver548=== RUN TestLeadIncumbentWinsAfterRestart5492026/11/11 23:34:39 INFO lead: acquired remote=192.0.2.1:1234 generation=15502026/11/11 23:34:39 INFO lead: released remote=192.0.2.1:1234 generation=15512026/11/11 23:34:40 INFO lead: acquired remote=192.0.2.1:1234 generation=25522026/11/11 23:34:41 INFO lead: released remote=192.0.2.1:1234 generation=2553--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)554=== RUN TestLeadUnannouncedStandbyYieldsToIncumbent555=== PAUSE TestLeadUnannouncedStandbyYieldsToIncumbent556=== RUN TestLeadIncumbentAnnouncesAtOnce557=== PAUSE TestLeadIncumbentAnnouncesAtOnce558=== RUN TestLeadGenerationGrowsWithEveryGrant559=== PAUSE TestLeadGenerationGrowsWithEveryGrant560=== RUN TestLeadEndsOnShutdown561=== PAUSE TestLeadEndsOnShutdown562=== RUN TestLeadEndsWhenItsConnectionHangs5632026/11/11 23:34:41 INFO lead: acquired remote=192.0.2.1:1234 generation=15642026-11-11 23:34:42.650 UTC [573] FATAL: terminating connection due to administrator command5652026/11/11 23:34:42 INFO lead: acquired remote=192.0.2.1:1234 generation=25662026/11/11 23:34:43 WARN lead: lock connection lost error="timeout: context deadline exceeded"5672026/11/11 23:34:43 INFO lead: released remote=192.0.2.1:1234 generation=15682026/11/11 23:34:44 INFO lead: released remote=192.0.2.1:1234 generation=2569--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)570=== RUN TestGCAdvisoryLockBlocksConcurrentRun571=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun572=== RUN TestGCBugBareHashReferences573=== PAUSE TestGCBugBareHashReferences574=== RUN TestGCMetrics575=== PAUSE TestGCMetrics576=== RUN TestPushDedupSurvivesConcurrentGC577=== PAUSE TestPushDedupSurvivesConcurrentGC578=== RUN TestDeduplicatedObjectsRecordedAsPending579=== PAUSE TestDeduplicatedObjectsRecordedAsPending580=== RUN TestGCSweepSkipsPendingObjects581=== PAUSE TestGCSweepSkipsPendingObjects582=== RUN TestTombstonedObjectOfferedWithoutWaiting583=== PAUSE TestTombstonedObjectOfferedWithoutWaiting584=== RUN TestGCSweepDeliversEachKeyOnce585=== PAUSE TestGCSweepDeliversEachKeyOnce586=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection587=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection588=== RUN TestForceGCDuringPushOffersSweptObject589=== PAUSE TestForceGCDuringPushOffersSweptObject590=== RUN TestFailedS3DeleteKeepsTombstone591=== PAUSE TestFailedS3DeleteKeepsTombstone592=== RUN TestSweepSkipsRowsLockedByPush593=== PAUSE TestSweepSkipsRowsLockedByPush594=== RUN TestRegisterCompletedObjectNeedsPendingRow595=== PAUSE TestRegisterCompletedObjectNeedsPendingRow596=== RUN TestGetExistingObjectsLocksRows597=== PAUSE TestGetExistingObjectsLocksRows598=== RUN TestSweepRechecksPendingAfterLocking599=== PAUSE TestSweepRechecksPendingAfterLocking600=== RUN TestPushWaitsForSweepHoldingRow601=== PAUSE TestPushWaitsForSweepHoldingRow602=== RUN TestCommitRacingPendingCleanupKeepsObjects603=== PAUSE TestCommitRacingPendingCleanupKeepsObjects604=== RUN TestGCEndsOnShutdown605=== PAUSE TestGCEndsOnShutdown606=== RUN TestGCTaskStore_StartNew607=== PAUSE TestGCTaskStore_StartNew608=== RUN TestGCTaskStore_DeduplicateSameParams609=== PAUSE TestGCTaskStore_DeduplicateSameParams610=== RUN TestGCTaskStore_ConflictDifferentParams611=== PAUSE TestGCTaskStore_ConflictDifferentParams612=== RUN TestGCTaskStore_GetEmpty613=== PAUSE TestGCTaskStore_GetEmpty614=== RUN TestGCTaskStore_GetReturnsLatest615=== PAUSE TestGCTaskStore_GetReturnsLatest616=== RUN TestGCTaskStore_CompletedAllowsNewTask617=== PAUSE TestGCTaskStore_CompletedAllowsNewTask618=== RUN TestGCTaskStore_PhaseUpdates619=== PAUSE TestGCTaskStore_PhaseUpdates620=== RUN TestGCTaskStore_Fail621=== PAUSE TestGCTaskStore_Fail622=== RUN TestGracefulShutdownDrainsInflight623=== PAUSE TestGracefulShutdownDrainsInflight624=== RUN TestService_healthCheckHandler625=== PAUSE TestService_healthCheckHandler626=== RUN TestService_readinessHandler627=== PAUSE TestService_readinessHandler628=== RUN TestGenerateLandingPage629=== PAUSE TestGenerateLandingPage630=== RUN TestEnsureAbortUploadsRule631=== PAUSE TestEnsureAbortUploadsRule632=== RUN TestCacheConfigHandlerMaxNarSize633=== PAUSE TestCacheConfigHandlerMaxNarSize634=== RUN TestCreatePendingClosureRejectsOversizedNAR635=== PAUSE TestCreatePendingClosureRejectsOversizedNAR636=== RUN TestNARDeduplicationMetadataUploadBug637=== PAUSE TestNARDeduplicationMetadataUploadBug638=== RUN TestMetricsInventory639=== PAUSE TestMetricsInventory640=== RUN TestMetricsCommit641=== PAUSE TestMetricsCommit642=== RUN TestService_NativeMTLS643=== PAUSE TestService_NativeMTLS644=== RUN TestServerTLSConfig645=== PAUSE TestServerTLSConfig646=== RUN TestMultipartCleanup647=== PAUSE TestMultipartCleanup648=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded649=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded650=== RUN TestPendingCleanupUsesOneCutoff651=== PAUSE TestPendingCleanupUsesOneCutoff652=== RUN TestObjectStatsTrigger653=== PAUSE TestObjectStatsTrigger654=== RUN TestObjectStatsUpdatedOncePerCommit655=== PAUSE TestObjectStatsUpdatedOncePerCommit656=== RUN TestOrphanedObjectsGC657=== PAUSE TestOrphanedObjectsGC658=== RUN TestOrphanedObjectsGCStressTest659=== PAUSE TestOrphanedObjectsGCStressTest660=== RUN TestCreatePin_ReservedPins661=== PAUSE TestCreatePin_ReservedPins662=== RUN TestPresentReportsOnlyClosureRoots663=== PAUSE TestPresentReportsOnlyClosureRoots664=== RUN TestPresentRefreshesOnlyStaleClosures665=== PAUSE TestPresentRefreshesOnlyStaleClosures666=== RUN TestPresentNotReportedWhileGCDeletesClosure667=== PAUSE TestPresentNotReportedWhileGCDeletesClosure668=== RUN TestParseSingleRange669=== PAUSE TestParseSingleRange670=== RUN TestProxyHeadersOnlyTrustedOnSocket6712026/11/11 23:34:44 INFO Starting HTTP server address=proxy.sock6722026/11/11 23:34:44 INFO Starting HTTP server address=127.0.0.1:443336732026/11/11 23:34:44 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6742026/11/11 23:34:44 INFO Shutdown signal received, draining in-flight requests timeout=10s675--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)676=== RUN TestIsValidCachePath677=== PAUSE TestIsValidCachePath678=== RUN TestReadProxyNarinfo679=== PAUSE TestReadProxyNarinfo680=== RUN TestReadProxyNarinfoAlreadyDecompressed681=== PAUSE TestReadProxyNarinfoAlreadyDecompressed682=== RUN TestReadProxyContentNegotiation683=== PAUSE TestReadProxyContentNegotiation684=== RUN TestReadProxyNarStreaming685=== PAUSE TestReadProxyNarStreaming686=== RUN TestReadProxy404687=== PAUSE TestReadProxy404688=== RUN TestReadProxyInvalidPath689=== PAUSE TestReadProxyInvalidPath690=== RUN TestReadProxyHead691=== PAUSE TestReadProxyHead692=== RUN TestReadProxyOutlastsServerWriteTimeout693=== PAUSE TestReadProxyOutlastsServerWriteTimeout694=== RUN TestReadProxyConditionalGet695=== PAUSE TestReadProxyConditionalGet696=== RUN TestReadProxyRootRedirectsToIndexHTML697=== PAUSE TestReadProxyRootRedirectsToIndexHTML698=== RUN TestReadProxyDisabled699=== PAUSE TestReadProxyDisabled700=== RUN TestReadRedirectNar701=== PAUSE TestReadRedirectNar702=== RUN TestReadRedirectKeepsNarinfoProxied703=== PAUSE TestReadRedirectKeepsNarinfoProxied704=== RUN TestReadProxyRangeRequest705=== PAUSE TestReadProxyRangeRequest706=== RUN TestReadRedirectUsesPublicS3URL707=== PAUSE TestReadRedirectUsesPublicS3URL708=== RUN TestPush_OverlappingRootsStoreOneRowPerKey709=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey710=== RUN TestPush_CompleteCommitsEveryRoot711=== PAUSE TestPush_CompleteCommitsEveryRoot712=== RUN TestPush_RepeatedRootCommitsOnce713=== PAUSE TestPush_RepeatedRootCommitsOnce714=== RUN TestPush_CompleteWaitsForCleanupOfThePush715=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush716=== RUN TestPush_RootsAreLockedInByteOrder717=== PAUSE TestPush_RootsAreLockedInByteOrder718=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit719=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit720=== RUN TestPush_RejectsBadRequests721=== PAUSE TestPush_RejectsBadRequests722=== RUN TestPush_SignsNarinfosOfItsPendingObjects723=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects724=== RUN TestSharedNarBothUploadsComplete725=== PAUSE TestSharedNarBothUploadsComplete726=== RUN TestCompleteMultipartUpload_ErrorButObjectExists727=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists728=== RUN TestCompletedNarNotReofferedAcrossClosures729=== PAUSE TestCompletedNarNotReofferedAcrossClosures730=== RUN TestPresignedUploadRegisteredBeforeCommit731=== PAUSE TestPresignedUploadRegisteredBeforeCommit732=== RUN TestService_Rustfstest733=== PAUSE TestService_Rustfstest734=== RUN TestParseSize735=== PAUSE TestParseSize736=== RUN TestSkippedUploadsHandler737=== PAUSE TestSkippedUploadsHandler738=== RUN TestSystemdListenerNotActivated739--- PASS: TestSystemdListenerNotActivated (0.00s)740=== RUN TestWatchdogBeatsWhenHealthy741--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)742=== RUN TestWatchdogSkipsWhenUnhealthy7432026/11/11 23:34:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7442026/11/11 23:34:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7452026/11/11 23:34:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/11/11 23:34:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/11 23:34:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/11 23:34:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/11 23:34:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/11/11 23:34:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/11/11 23:34:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/11/11 23:34:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"753--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)754=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle755=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle756=== RUN TestProxyWriteTimeout757=== PAUSE TestProxyWriteTimeout758=== RUN TestPendingClosureWriteTimeout759=== PAUSE TestPendingClosureWriteTimeout760=== RUN TestIsValidUploadKey761=== PAUSE TestIsValidUploadKey762=== RUN TestUploadHandlersRejectInvalidKeys763=== PAUSE TestUploadHandlersRejectInvalidKeys764=== RUN TestUploadHandlersRejectOversizedBody765=== PAUSE TestUploadHandlersRejectOversizedBody766=== RUN TestService_cleanupPendingClosuresHandler767=== PAUSE TestService_cleanupPendingClosuresHandler768=== RUN TestService_createPendingClosureHandler769=== PAUSE TestService_createPendingClosureHandler770=== RUN TestService_verifyS3Integrity771=== PAUSE TestService_verifyS3Integrity772=== RUN TestService_verifyS3ReuploadsStaleNarinfo773=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo774=== RUN TestCompleteMultipartUnregistered775=== PAUSE TestCompleteMultipartUnregistered776=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT777=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT778=== CONT TestAbortSucceeded779=== CONT TestService_createPendingClosureHandler780--- PASS: TestAbortSucceeded (0.00s)781=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT782=== CONT TestCompleteMultipartUnregistered783=== CONT TestService_verifyS3ReuploadsStaleNarinfo784=== CONT TestService_verifyS3Integrity785=== CONT TestMultipartCleanup786=== CONT TestServerTLSConfig787=== CONT TestService_NativeMTLS788=== RUN TestServerTLSConfig/no_client_CA789=== CONT TestMetricsCommit790=== CONT TestMetricsInventory791=== CONT TestNARDeduplicationMetadataUploadBug792=== CONT TestCreatePendingClosureRejectsOversizedNAR793=== CONT TestCacheConfigHandlerMaxNarSize794=== CONT TestEnsureAbortUploadsRule795=== CONT TestGenerateLandingPage796=== CONT TestService_readinessHandler7972026/11/11 23:34:44 INFO Received uploads request method=POST path=/api/pending_closures798=== CONT TestService_healthCheckHandler799=== CONT TestGracefulShutdownDrainsInflight800=== CONT TestGCTaskStore_Fail801=== CONT TestGCTaskStore_StartNew802=== CONT TestGCEndsOnShutdown803=== CONT TestGCTaskStore_PhaseUpdates804=== CONT TestCommitRacingPendingCleanupKeepsObjects8052026/11/11 23:34:44 INFO Starting HTTP server address=127.0.0.1:45997806=== CONT TestPushWaitsForSweepHoldingRow8072026/11/11 23:34:44 INFO Shutdown signal received, draining in-flight requests timeout=10s808=== CONT TestGCTaskStore_GetReturnsLatest809=== CONT TestSweepRechecksPendingAfterLocking810=== CONT TestGCTaskStore_GetEmpty811=== CONT TestGetExistingObjectsLocksRows812=== CONT TestGCTaskStore_ConflictDifferentParams813=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed814=== PAUSE TestServerTLSConfig/no_client_CA815--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)816=== CONT TestGCTaskStore_DeduplicateSameParams817=== RUN TestGCEndsOnShutdown/before_the_run818=== CONT TestGCTaskStore_CompletedAllowsNewTask819=== CONT TestRegisterCompletedObjectNeedsPendingRow820=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed821=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed822=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed823=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost824=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost825=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed826=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed827=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed828=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed829=== CONT TestForceGCDuringPushOffersSweptObject830=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows831=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows832=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check833=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check834=== RUN TestServerTLSConfig/missing_CA_file835=== PAUSE TestServerTLSConfig/missing_CA_file836=== RUN TestServerTLSConfig/not_a_PEM_file837=== PAUSE TestServerTLSConfig/not_a_PEM_file838--- PASS: TestGCTaskStore_Fail (0.00s)839--- PASS: TestGCTaskStore_StartNew (0.00s)840=== CONT TestSweepSkipsRowsLockedByPush841=== PAUSE TestGCEndsOnShutdown/before_the_run842=== CONT TestFailedS3DeleteKeepsTombstone843=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection844=== CONT TestGCSweepDeliversEachKeyOnce845=== CONT TestTombstonedObjectOfferedWithoutWaiting846--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)847--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)848--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)849--- PASS: TestGCTaskStore_GetEmpty (0.00s)850--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)851--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)852--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)853--- PASS: TestGenerateLandingPage (0.00s)854=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete855=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete856=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark857=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark858=== CONT TestGCSweepSkipsPendingObjects859--- PASS: TestGracefulShutdownDrainsInflight (0.07s)860=== CONT TestDeduplicatedObjectsRecordedAsPending8612026/11/11 23:34:44 INFO Received uploads request method=POST path=/api/pending_closures862--- PASS: TestMetricsInventory (0.39s)863=== CONT TestPushDedupSurvivesConcurrentGC8642026/11/11 23:34:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8652026/11/11 23:34:45 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst866--- PASS: TestCompleteMultipartUnregistered (0.42s)867=== CONT TestGCMetrics8682026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures8692026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures870--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.49s)871=== CONT TestGCBugBareHashReferences8722026/11/11 23:34:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8732026/11/11 23:34:45 WARN mTLS auth: subject not in bound subjects subject="CN=reader"874--- PASS: TestService_NativeMTLS (0.50s)875=== CONT TestGCAdvisoryLockBlocksConcurrentRun8762026/11/11 23:34:45 INFO Received cleanup request method=DELETE path=/api/pending_closures8772026/11/11 23:34:45 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket5/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8782026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=18792026/11/11 23:34:45 INFO Received cleanup request method=DELETE path=/api/pending_closures8802026/11/11 23:34:45 INFO Aborted multipart uploads count=1 kept=0881--- PASS: TestMultipartCleanup (0.52s)882=== CONT TestLeadEndsOnShutdown8832026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=08842026/11/11 23:34:45 WARN Force mode enabled - objects will be deleted immediately without grace period8852026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures8862026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures8872026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures8882026/11/11 23:34:45 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=08892026/11/11 23:34:45 INFO Vacuumed table table=pending_closures8902026/11/11 23:34:45 INFO Vacuumed table table=pending_objects8912026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads8922026/11/11 23:34:45 INFO Vacuumed table table=closures8932026/11/11 23:34:45 INFO Vacuumed table table=objects894--- PASS: TestSweepRechecksPendingAfterLocking (0.58s)895=== CONT TestLeadGenerationGrowsWithEveryGrant896--- PASS: TestService_healthCheckHandler (0.59s)897=== CONT TestLeadIncumbentAnnouncesAtOnce8982026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures8992026/11/11 23:34:45 INFO Received push request method=POST path=/api/pushes9002026/11/11 23:34:45 INFO Received complete push request method=POST path=/api/pushes/1/complete9012026/11/11 23:34:45 INFO Completed push id=1 objects=4 duration=6.485486ms9022026/11/11 23:34:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9032026/11/11 23:34:45 INFO Completed upload id=2 objects=2 duration=1.243359ms904--- PASS: TestMetricsCommit (0.70s)905=== CONT TestLeadUnannouncedStandbyYieldsToIncumbent9062026/11/11 23:34:45 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket15 days=2907--- PASS: TestEnsureAbortUploadsRule (0.70s)908=== CONT TestLeadElectsOneAndHandsOver909--- PASS: TestGetExistingObjectsLocksRows (0.73s)910=== CONT TestConnectWaitsForAPeerMigration911--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.75s)912=== CONT TestResolveDBConnectionString913=== RUN TestResolveDBConnectionString/flag_wins914=== PAUSE TestResolveDBConnectionString/flag_wins915=== RUN TestResolveDBConnectionString/file_when_flag_empty916=== PAUSE TestResolveDBConnectionString/file_when_flag_empty917=== RUN TestResolveDBConnectionString/missing_file_is_an_error918=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error919=== RUN TestResolveDBConnectionString/PGHOST_allows_empty920=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty921=== RUN TestResolveDBConnectionString/nothing_configured922=== PAUSE TestResolveDBConnectionString/nothing_configured923=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9242026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures9252026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures926--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.82s)927=== CONT TestDeleteClosuresRacingPins9282026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=09292026/11/11 23:34:45 WARN Force mode enabled - objects will be deleted immediately without grace period9302026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=09312026/11/11 23:34:45 WARN Force mode enabled - objects will be deleted immediately without grace period9322026/11/11 23:34:45 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9332026/11/11 23:34:45 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."934--- PASS: TestFailedS3DeleteKeepsTombstone (0.88s)935=== CONT TestClientFallsBackToClosures9362026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures937=== NAME TestNARDeduplicationMetadataUploadBug938 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3032308724/001/store/fr60bpjks0klzjisqg7wclp46bva9rb7-file1.txt9392026/11/11 23:34:45 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=09402026/11/11 23:34:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9412026/11/11 23:34:45 INFO Vacuumed table table=pending_closures9422026/11/11 23:34:45 INFO Vacuumed table table=pending_objects9432026/11/11 23:34:45 WARN readiness check failed error="closed pool"944--- PASS: TestService_readinessHandler (0.93s)945=== CONT TestClientPushesUseOnePush9462026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads9472026/11/11 23:34:45 INFO Vacuumed table table=closures9482026/11/11 23:34:45 INFO Vacuumed table table=objects949--- PASS: TestGCSweepDeliversEachKeyOnce (0.93s)950=== CONT TestPinProtectsFromGC9512026/11/11 23:34:45 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLjU5NTIwOTQyLTk2NjAtNGI5YS1iYmRkLTMxMzMzZTYzNWU1MngxNzk0NDQwMDg1MDQxMDg5MDgz parts=109522026/11/11 23:34:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9532026/11/11 23:34:45 INFO Completed upload id=1 objects=2 duration=3.213018ms9542026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures9552026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures9562026/11/11 23:34:45 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9572026/11/11 23:34:45 WARN Found objects in DB but missing from S3, will re-upload count=1958--- PASS: TestService_verifyS3Integrity (0.96s)959=== CONT TestClientSharedPathCommittedMidPush9602026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures961--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.90s)962=== CONT TestClientWithDependencies9632026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures9642026/11/11 23:34:45 INFO Received push request method=POST path=/api/pushes9652026/11/11 23:34:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9662026/11/11 23:34:45 INFO Uploading fr60bpjks0klzjisqg7wclp46bva9rb7-file1.txt (160B)9672026/11/11 23:34:45 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9682026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=09692026/11/11 23:34:45 WARN Failed to register uploaded object key=fr60bpjks0klzjisqg7wclp46bva9rb7.ls error="server returned 404: 404 page not found\n"9702026/11/11 23:34:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9712026/11/11 23:34:45 INFO Signed narinfos id=1 count=19722026/11/11 23:34:45 INFO Uploading 1 narinfos9732026/11/11 23:34:45 WARN Force mode enabled - objects will be deleted immediately without grace period9742026/11/11 23:34:45 INFO Received complete push request method=POST path=/api/pushes/1/complete9752026/11/11 23:34:45 WARN Failed to register uploaded object key=fr60bpjks0klzjisqg7wclp46bva9rb7.narinfo error="server returned 404: 404 page not found\n"9762026/11/11 23:34:45 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=09772026/11/11 23:34:45 INFO Vacuumed table table=pending_closures9782026/11/11 23:34:45 INFO Vacuumed table table=pending_objects9792026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads9802026/11/11 23:34:45 INFO Vacuumed table table=closures9812026/11/11 23:34:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9822026/11/11 23:34:45 INFO Completed push id=1 objects=3 duration=10.619974ms9832026/11/11 23:34:45 INFO Upload complete. (83ms)9842026/11/11 23:34:45 INFO Vacuumed table table=objects985=== NAME TestNARDeduplicationMetadataUploadBug986 metadata_upload_test.go:54: Retrieved narinfo from S3:987 StorePath: /build/TestNARDeduplicationMetadataUploadBug3032308724/001/store/fr60bpjks0klzjisqg7wclp46bva9rb7-file1.txt988 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst989 Compression: zstd990 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf991 NarSize: 160992 References: 993 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf9942026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=0995 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)996 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):997 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9982026/11/11 23:34:45 WARN Force mode enabled - objects will be deleted immediately without grace period999--- PASS: TestGCSweepSkipsPendingObjects (1.04s)1000=== CONT TestClientMultipleUploads10012026/11/11 23:34:45 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=010022026/11/11 23:34:45 INFO Vacuumed table table=pending_closures10032026/11/11 23:34:45 INFO Vacuumed table table=pending_objects10042026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads10052026/11/11 23:34:45 INFO Vacuumed table table=closures10062026/11/11 23:34:45 INFO Vacuumed table table=objects10072026/11/11 23:34:45 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLjI5NTFhYjYwLTJiOTAtNDMyYi04ZDFlLTljMjRhMWU5N2ZlMXgxNzk0NDQwMDg1MTY3MDc1ODU1 parts=1010082026/11/11 23:34:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10092026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=010102026/11/11 23:34:45 INFO Completed upload id=1 objects=2 duration=4.044457ms10112026/11/11 23:34:45 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010122026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures10132026/11/11 23:34:45 WARN Force mode enabled - objects will be deleted immediately without grace period10142026/11/11 23:34:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures10152026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=010162026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=01017=== NAME TestNARDeduplicationMetadataUploadBug1018 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3032308724/001/store/5ja2fhz56x40admyvyqrkj2z19d2h9lv-file2.txt10192026/11/11 23:34:45 WARN Force mode enabled - objects will be deleted immediately without grace period10202026/11/11 23:34:45 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=010212026/11/11 23:34:45 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=010222026/11/11 23:34:45 INFO Vacuumed table table=pending_closures10232026/11/11 23:34:45 INFO Vacuumed table table=pending_closures10242026/11/11 23:34:45 INFO Vacuumed table table=pending_objects10252026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads10262026/11/11 23:34:45 INFO Vacuumed table table=pending_objects10272026/11/11 23:34:45 INFO Vacuumed table table=closures10282026/11/11 23:34:45 INFO Vacuumed table table=objects10292026/11/11 23:34:45 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=010302026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures10312026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads10322026/11/11 23:34:45 INFO Vacuumed table table=pending_closures10332026/11/11 23:34:45 INFO Vacuumed table table=pending_objects10342026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads10352026/11/11 23:34:45 INFO Vacuumed table table=closures10362026/11/11 23:34:45 INFO Vacuumed table table=closures10372026/11/11 23:34:45 INFO Vacuumed table table=objects10382026/11/11 23:34:45 INFO Vacuumed table table=objects1039--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.10s)1040=== CONT TestClientIntegration1041--- PASS: TestSweepSkipsRowsLockedByPush (1.10s)1042=== CONT TestClientErrorHandling1043=== RUN TestClientErrorHandling/InvalidStorePath1044=== PAUSE TestClientErrorHandling/InvalidStorePath1045=== RUN TestClientErrorHandling/InvalidAuthToken1046=== PAUSE TestClientErrorHandling/InvalidAuthToken1047=== RUN TestClientErrorHandling/ServerNotAvailable1048=== PAUSE TestClientErrorHandling/ServerNotAvailable1049=== CONT TestClientCADerivations10502026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=010512026/11/11 23:34:45 WARN Force mode enabled - objects will be deleted immediately without grace period1052--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.11s)1053=== CONT TestCacheStatsHandler10542026/11/11 23:34:45 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=010552026/11/11 23:34:45 INFO Vacuumed table table=pending_closures10562026/11/11 23:34:45 INFO Vacuumed table table=pending_objects10572026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads10582026/11/11 23:34:45 INFO Vacuumed table table=closures10592026/11/11 23:34:45 INFO Vacuumed table table=objects10602026/11/11 23:34:45 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001061--- PASS: TestService_createPendingClosureHandler (1.13s)1062=== CONT TestCacheConfigHandler1063=== RUN TestCacheConfigHandler/full_config,_no_issuer1064=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1065=== RUN TestCacheConfigHandler/no_cache_url_configured1066=== PAUSE TestCacheConfigHandler/no_cache_url_configured1067=== RUN TestCacheConfigHandler/no_signing_keys1068=== PAUSE TestCacheConfigHandler/no_signing_keys1069=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1070=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1071=== CONT TestService_ReadScope_PublicByDefault1072--- PASS: TestGCMetrics (0.71s)1073=== CONT TestService_RequireScope_OIDC1074--- PASS: TestPushWaitsForSweepHoldingRow (1.14s)1075=== CONT TestService_AuthMiddleware_OIDC10762026/11/11 23:34:45 INFO Received push request method=POST path=/api/pushes10772026/11/11 23:34:45 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10782026/11/11 23:34:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10792026/11/11 23:34:45 INFO Signed narinfos id=2 count=110802026/11/11 23:34:45 WARN Failed to register uploaded object key=5ja2fhz56x40admyvyqrkj2z19d2h9lv.ls error="server returned 404: 404 page not found\n"10812026/11/11 23:34:45 INFO Uploading 1 narinfos10822026/11/11 23:34:45 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"1083--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.67s)1084=== CONT TestService_ReadAuthMiddleware10852026/11/11 23:34:45 INFO Received complete push request method=POST path=/api/pushes/2/complete10862026/11/11 23:34:45 WARN Failed to register uploaded object key=5ja2fhz56x40admyvyqrkj2z19d2h9lv.narinfo error="server returned 404: 404 page not found\n"10872026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=010882026/11/11 23:34:45 INFO Completed push id=2 objects=3 duration=3.810328ms10892026/11/11 23:34:45 INFO Upload complete. (58ms)1090=== NAME TestNARDeduplicationMetadataUploadBug1091 metadata_upload_test.go:76: Retrieved narinfo from S3:1092 StorePath: /build/TestNARDeduplicationMetadataUploadBug3032308724/001/store/5ja2fhz56x40admyvyqrkj2z19d2h9lv-file2.txt1093 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1094 Compression: zstd1095 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1096 NarSize: 1601097 References: 1098 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1099 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1100 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1101 {"version":1,"root":{"type":"regular","size":44}}1102--- PASS: TestNARDeduplicationMetadataUploadBug (1.18s)1103=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11042026/11/11 23:34:45 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=011052026/11/11 23:34:45 INFO Vacuumed table table=pending_closures11062026/11/11 23:34:45 INFO lead: acquired remote=192.0.2.1:1234 generation=111072026/11/11 23:34:45 INFO Vacuumed table table=pending_objects11082026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads11092026/11/11 23:34:45 INFO Vacuumed table table=closures11102026/11/11 23:34:45 INFO Vacuumed table table=objects11112026/11/11 23:34:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33201/oidc11122026/11/11 23:34:45 INFO Aborted multipart uploads count=0 kept=011132026/11/11 23:34:45 WARN Force mode enabled - objects will be deleted immediately without grace period11142026/11/11 23:34:45 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=011152026/11/11 23:34:45 INFO lead: acquired remote=192.0.2.1:1234 generation=111162026/11/11 23:34:45 INFO Vacuumed table table=pending_closures11172026/11/11 23:34:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37389/oidc11182026/11/11 23:34:45 INFO Vacuumed table table=pending_objects11192026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads11202026/11/11 23:34:45 INFO Vacuumed table table=closures11212026/11/11 23:34:45 INFO Vacuumed table table=objects1122--- PASS: TestPushDedupSurvivesConcurrentGC (0.85s)1123=== CONT TestService_AuthMiddleware_MTLSProxyHeader11242026/11/11 23:34:45 INFO lead: acquired remote=192.0.2.1:1234 generation=111252026/11/11 23:34:45 INFO lead: released remote=192.0.2.1:1234 generation=11126--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.67s)1127=== CONT TestService_AuthMiddleware11282026/11/11 23:34:45 INFO lead: acquired remote=192.0.2.1:1234 generation=111292026/11/11 23:34:45 INFO lead: acquired remote=192.0.2.1:1234 generation=11130--- PASS: TestGCBugBareHashReferences (0.88s)1131=== CONT TestReadRedirectKeepsNarinfoProxied1132=== NAME TestPinProtectsFromGC1133 client_integration_test.go:779: Pinned store path: /build/TestPinProtectsFromGC1390523923/001/store/zbscljrrlk9y3hlv0kz4nrn67bblycs6-pinned-file.txt1134 client_integration_test.go:780: Unpinned store path: /build/TestPinProtectsFromGC1390523923/001/store/999wwkl6iqpn2g74j74396ns5g9441x2-unpinned-file.txt1135--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.85s)1136=== CONT TestService_cleanupPendingClosuresHandler1137=== NAME TestClientMultipleUploads1138 client_integration_test.go:406: Created store path 0: /build/TestClientMultipleUploads1817901383/001/store/kgq88s0049757nnqqm0sisf187r16kqb-test-file-0.txt11392026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures11402026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures11412026/11/11 23:34:46 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11422026/11/11 23:34:46 INFO Uploading pqmnq7m0bzvfasgb2s9gb34aa8bjps88-a (216B)11432026/11/11 23:34:46 INFO Uploading hazkci8wvaxqzd7m6jfypcxlj2mqx4q9-shared-dep (136B)1144=== NAME TestClientWithDependencies1145 client_integration_test.go:661: Built derivation: /build/TestClientWithDependencies1746253158/001/store/1pkkazii893pi8lxrrbxyj2n54n2d658-test-script11462026/11/11 23:34:46 WARN Failed to register uploaded object key=pqmnq7m0bzvfasgb2s9gb34aa8bjps88.ls error="server returned 404: 404 page not found\n"11472026/11/11 23:34:46 WARN Failed to register uploaded object key=af5442rba9xggq051rnp78ina855c0r1.ls error="server returned 404: 404 page not found\n"11482026/11/11 23:34:46 WARN Failed to register uploaded object key=hazkci8wvaxqzd7m6jfypcxlj2mqx4q9.ls error="server returned 404: 404 page not found\n"11492026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11502026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/0d593glnkxfk1xwbmnq5i9fps9kzixp0782vkx3155ialnrn7gmr.nar.zst error="server returned 404: 404 page not found\n"11512026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11522026/11/11 23:34:46 INFO Signed narinfos id=1 count=211532026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11542026/11/11 23:34:46 INFO Signed narinfos id=2 count=211552026/11/11 23:34:46 INFO Uploading 4 narinfos11562026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes11572026/11/11 23:34:46 WARN Failed to register uploaded object key=af5442rba9xggq051rnp78ina855c0r1.narinfo error="server returned 404: 404 page not found\n"11582026/11/11 23:34:46 WARN Failed to register uploaded object key=pqmnq7m0bzvfasgb2s9gb34aa8bjps88.narinfo error="server returned 404: 404 page not found\n"11592026/11/11 23:34:46 WARN Failed to register uploaded object key=hazkci8wvaxqzd7m6jfypcxlj2mqx4q9.narinfo error="server returned 404: 404 page not found\n"11602026/11/11 23:34:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11612026/11/11 23:34:46 INFO Uploading zbscljrrlk9y3hlv0kz4nrn67bblycs6-pinned-file.txt (128B)11622026/11/11 23:34:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11632026/11/11 23:34:46 WARN Failed to register uploaded object key=hazkci8wvaxqzd7m6jfypcxlj2mqx4q9.narinfo error="server returned 404: 404 page not found\n"11642026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11652026/11/11 23:34:46 WARN Failed to register uploaded object key=zbscljrrlk9y3hlv0kz4nrn67bblycs6.ls error="server returned 404: 404 page not found\n"11662026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11672026/11/11 23:34:46 INFO Signed narinfos id=1 count=111682026/11/11 23:34:46 INFO Uploading 1 narinfos11692026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes1170--- PASS: TestCacheStatsHandler (0.55s)1171=== CONT TestUploadHandlersRejectOversizedBody11722026/11/11 23:34:46 INFO Completed upload id=1 objects=6 duration=10.065354ms11732026/11/11 23:34:46 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11742026/11/11 23:34:46 INFO Received complete push request method=POST path=/api/pushes/1/complete11752026/11/11 23:34:46 WARN Failed to register uploaded object key=zbscljrrlk9y3hlv0kz4nrn67bblycs6.narinfo error="server returned 404: 404 page not found\n"1176=== NAME TestClientMultipleUploads11772026/11/11 23:34:46 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1178 client_integration_test.go:406: Created store path 1: /build/TestClientMultipleUploads1817901383/001/store/5qflqjdmdkbv0d15hqz6x3fz7g7m6vfp-test-file-1.txt11792026/11/11 23:34:46 INFO Uploading qpkc3xa27r7inyqzs3crckl9n8a9nrbr-b (216B)11802026/11/11 23:34:46 INFO Uploading 5qj1wsmga5d6clr967c7dfbmbli883q0-shared-dep (136B)11812026/11/11 23:34:46 INFO Completed upload id=2 objects=6 duration=1.817569ms11822026/11/11 23:34:46 INFO Upload complete. (80ms)1183=== NAME TestClientIntegration1184 client_integration_test.go:292: Created store path: /build/TestClientIntegration2403006094/002/store/kxi2dmh829aiwcgndqfrrq6qsn3d58gs-test-file.txt11852026/11/11 23:34:46 INFO Completed push id=1 objects=3 duration=8.934664ms1186=== NAME TestClientMultipleUploads1187 client_integration_test.go:406: Created store path 2: /build/TestClientMultipleUploads1817901383/001/store/hapkp8hcp6mmlv6bny8aqqa0samj2fcx-test-file-2.txt11882026/11/11 23:34:46 INFO Upload complete. (241ms)1189=== NAME TestClientCADerivations11902026/11/11 23:34:46 WARN Failed to register uploaded object key=qpkc3xa27r7inyqzs3crckl9n8a9nrbr.ls error="server returned 404: 404 page not found\n"1191 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1470143169/001/store/xgvmgvpykgc0mg1lwisxmd0syhjnaks8-ca-test11922026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/05r19j9n2qlxxb00jik2y1qxzss8brzm1bbhxpxgjv3lvc9nhqmn.nar.zst error="server returned 404: 404 page not found\n"1193=== NAME TestClientWithDependencies11942026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes1195 client_integration_test.go:663: Found 1 dependencies (including self)1196--- PASS: TestService_ReadScope_PublicByDefault (0.73s)1197=== CONT TestUploadHandlersRejectInvalidKeys1198=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1199=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1200=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1201=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1202=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1203=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1204=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1205=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1206=== NAME TestClientFallsBackToClosures1207 client_pushes_test.go:112: Retrieved narinfo from S3:1208 StorePath: /build/TestClientFallsBackToClosures2707780319/001/store/hazkci8wvaxqzd7m6jfypcxlj2mqx4q9-shared-dep1209 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1210 Compression: zstd1211 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821212 NarSize: 1361213 References: 1214 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1215=== CONT TestIsValidUploadKey1216=== RUN TestIsValidUploadKey/narinfo1217=== PAUSE TestIsValidUploadKey/narinfo1218=== RUN TestIsValidUploadKey/nar_zst1219=== PAUSE TestIsValidUploadKey/nar_zst1220=== RUN TestIsValidUploadKey/nar_xz1221=== PAUSE TestIsValidUploadKey/nar_xz1222=== RUN TestIsValidUploadKey/nar_plain1223=== PAUSE TestIsValidUploadKey/nar_plain1224=== RUN TestIsValidUploadKey/listing1225=== PAUSE TestIsValidUploadKey/listing1226=== RUN TestIsValidUploadKey/build_log1227=== PAUSE TestIsValidUploadKey/build_log1228=== RUN TestIsValidUploadKey/build_log_home-manager_file1229=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1230=== RUN TestIsValidUploadKey/build_log_plus_in_name1231=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1232=== RUN TestIsValidUploadKey/build_log_question_mark1233=== PAUSE TestIsValidUploadKey/build_log_question_mark1234=== RUN TestIsValidUploadKey/build_log_equals1235=== PAUSE TestIsValidUploadKey/build_log_equals1236=== RUN TestIsValidUploadKey/realisation1237=== PAUSE TestIsValidUploadKey/realisation1238=== RUN TestIsValidUploadKey/realisation_plus_in_output1239=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1240=== RUN TestIsValidUploadKey/nix-cache-info1241=== PAUSE TestIsValidUploadKey/nix-cache-info1242=== RUN TestIsValidUploadKey/index.html1243=== PAUSE TestIsValidUploadKey/index.html1244=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1245=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1246=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1247=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1248=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1249=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1250=== RUN TestIsValidUploadKey/traversal1251=== PAUSE TestIsValidUploadKey/traversal1252=== RUN TestIsValidUploadKey/traversal_nar1253=== PAUSE TestIsValidUploadKey/traversal_nar1254=== RUN TestIsValidUploadKey/absolute1255=== PAUSE TestIsValidUploadKey/absolute1256=== RUN TestIsValidUploadKey/empty_key1257=== PAUSE TestIsValidUploadKey/empty_key1258=== RUN TestIsValidUploadKey/unknown_type1259=== PAUSE TestIsValidUploadKey/unknown_type1260=== CONT TestPendingClosureWriteTimeout1261=== RUN TestPendingClosureWriteTimeout/empty1262=== PAUSE TestPendingClosureWriteTimeout/empty1263=== RUN TestPendingClosureWriteTimeout/400_objects1264=== PAUSE TestPendingClosureWriteTimeout/400_objects1265=== RUN TestPendingClosureWriteTimeout/670k_objects1266=== PAUSE TestPendingClosureWriteTimeout/670k_objects1267=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1268=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1269=== CONT TestProxyWriteTimeout1270=== RUN TestProxyWriteTimeout/narinfo1271=== PAUSE TestProxyWriteTimeout/narinfo1272=== RUN TestProxyWriteTimeout/1_GiB_nar1273=== PAUSE TestProxyWriteTimeout/1_GiB_nar1274=== RUN TestProxyWriteTimeout/10_GiB_nar1275=== PAUSE TestProxyWriteTimeout/10_GiB_nar1276=== RUN TestProxyWriteTimeout/unknown_size1277=== PAUSE TestProxyWriteTimeout/unknown_size1278=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12792026/11/11 23:34:46 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12802026/11/11 23:34:46 INFO Uploading zydpzz9i1hbd5jr35zi58957333rbvvj-top (224B)12812026/11/11 23:34:46 INFO Uploading ffiqx4jf1fa7rwi89g5zm60688dkm7xl-shared-dep (136B)12822026/11/11 23:34:46 WARN Failed to register uploaded object key=3c2psmg7pk3zyma4xwj2479g959fxaxx.ls error="server returned 404: 404 page not found\n"12832026/11/11 23:34:46 WARN Failed to register uploaded object key=5qj1wsmga5d6clr967c7dfbmbli883q0.ls error="server returned 404: 404 page not found\n"12842026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12852026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12862026/11/11 23:34:46 INFO Signed narinfos id=1 count=312872026/11/11 23:34:46 INFO Uploading 3 narinfos1288=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1289=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1290=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1291=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1292=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1293=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1294=== CONT TestSkippedUploadsHandler12952026/11/11 23:34:46 INFO Received complete push request method=POST path=/api/pushes/1/complete1296=== NAME TestClientCADerivations12972026/11/11 23:34:46 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001298 client_ca_test.go:139: Found 1 dependencies (including self)12992026/11/11 23:34:46 WARN Failed to register uploaded object key=ffiqx4jf1fa7rwi89g5zm60688dkm7xl.ls error="server returned 404: 404 page not found\n"13002026/11/11 23:34:46 WARN Failed to register uploaded object key=5qj1wsmga5d6clr967c7dfbmbli883q0.narinfo error="server returned 404: 404 page not found\n"1301=== NAME TestClientFallsBackToClosures13022026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/0ljvn9rbmj70fv6ff2i4j4nlp2agbi6zrpg4rysibyaq2ygp5kf7.nar.zst error="server returned 404: 404 page not found\n"1303 client_pushes_test.go:112: Retrieved narinfo from S3:13042026/11/11 23:34:46 WARN Failed to register uploaded object key=qpkc3xa27r7inyqzs3crckl9n8a9nrbr.narinfo error="server returned 404: 404 page not found\n"1305 StorePath: /build/TestClientFallsBackToClosures2707780319/001/store/pqmnq7m0bzvfasgb2s9gb34aa8bjps88-a13062026/11/11 23:34:46 WARN Failed to register uploaded object key=zydpzz9i1hbd5jr35zi58957333rbvvj.ls error="server returned 404: 404 page not found\n"1307 URL: nar/0d593glnkxfk1xwbmnq5i9fps9kzixp0782vkx3155ialnrn7gmr.nar.zst13082026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes1309 Compression: zstd1310 NarHash: sha256:0d593glnkxfk1xwbmnq5i9fps9kzixp0782vkx3155ialnrn7gmr13112026/11/11 23:34:46 WARN Failed to register uploaded object key=3c2psmg7pk3zyma4xwj2479g959fxaxx.narinfo error="server returned 404: 404 page not found\n"1312 NarSize: 21613132026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1314 References: /build/TestClientFallsBackToClosures2707780319/001/store/hazkci8wvaxqzd7m6jfypcxlj2mqx4q9-shared-dep1315 CA: text:sha256:0bhz6dj85wps7jw8alb4wzadqbi7v7dh8pf8xq8d8s96ykb6m19a13162026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1317--- PASS: TestService_ReadAuthMiddleware (0.80s)1318=== CONT TestParseSize1319--- PASS: TestParseSize (0.00s)1320=== CONT TestService_Rustfstest13212026/11/11 23:34:46 INFO Signed narinfos id=1 count=213222026/11/11 23:34:46 INFO Uploading 2 narinfos1323--- PASS: TestSkippedUploadsHandler (0.01s)1324=== CONT TestPresignedUploadRegisteredBeforeCommit1325=== NAME TestClientFallsBackToClosures1326 client_pushes_test.go:112: Retrieved narinfo from S3:1327 StorePath: /build/TestClientFallsBackToClosures2707780319/001/store/af5442rba9xggq051rnp78ina855c0r1-b1328 URL: nar/0d593glnkxfk1xwbmnq5i9fps9kzixp0782vkx3155ialnrn7gmr.nar.zst1329 Compression: zstd1330 NarHash: sha256:0d593glnkxfk1xwbmnq5i9fps9kzixp0782vkx3155ialnrn7gmr1331 NarSize: 2161332 References: /build/TestClientFallsBackToClosures2707780319/001/store/hazkci8wvaxqzd7m6jfypcxlj2mqx4q9-shared-dep1333 CA: text:sha256:0bhz6dj85wps7jw8alb4wzadqbi7v7dh8pf8xq8d8s96ykb6m19a13342026/11/11 23:34:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13352026/11/11 23:34:46 INFO Uploading kxi2dmh829aiwcgndqfrrq6qsn3d58gs-test-file.txt (152B)13362026/11/11 23:34:46 INFO Completed push id=1 objects=8 duration=10.469243ms13372026/11/11 23:34:46 INFO Upload complete. (355ms)13382026/11/11 23:34:46 INFO Received complete push request method=POST path=/api/pushes/1/complete13392026/11/11 23:34:46 WARN Failed to register uploaded object key=ffiqx4jf1fa7rwi89g5zm60688dkm7xl.narinfo error="server returned 404: 404 page not found\n"13402026/11/11 23:34:46 WARN Failed to register uploaded object key=zydpzz9i1hbd5jr35zi58957333rbvvj.narinfo error="server returned 404: 404 page not found\n"1341=== NAME TestClientPushesUseOnePush1342 client_pushes_test.go:97: Retrieved narinfo from S3:1343 StorePath: /build/TestClientPushesUseOnePush3976089695/001/store/5qj1wsmga5d6clr967c7dfbmbli883q0-shared-dep1344 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1345 Compression: zstd1346 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821347 NarSize: 1361348 References: 1349 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1350--- PASS: TestClientFallsBackToClosures (1.09s)1351=== CONT TestCompletedNarNotReofferedAcrossClosures1352=== NAME TestClientPushesUseOnePush1353 client_pushes_test.go:97: Retrieved narinfo from S3:1354 StorePath: /build/TestClientPushesUseOnePush3976089695/001/store/3c2psmg7pk3zyma4xwj2479g959fxaxx-a13552026/11/11 23:34:46 WARN Failed to register uploaded object key=kxi2dmh829aiwcgndqfrrq6qsn3d58gs.ls error="server returned 404: 404 page not found\n"1356 URL: nar/05r19j9n2qlxxb00jik2y1qxzss8brzm1bbhxpxgjv3lvc9nhqmn.nar.zst13572026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1358 Compression: zstd1359 NarHash: sha256:05r19j9n2qlxxb00jik2y1qxzss8brzm1bbhxpxgjv3lvc9nhqmn1360 NarSize: 21613612026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1362 References: /build/TestClientPushesUseOnePush3976089695/001/store/5qj1wsmga5d6clr967c7dfbmbli883q0-shared-dep1363 CA: text:sha256:1yxr76m301bjkq898iv8yl3nl9ddvsn07p69ii7xxk83msvcdwg013642026/11/11 23:34:46 INFO Signed narinfos id=1 count=113652026/11/11 23:34:46 INFO Completed push id=1 objects=6 duration=5.415167ms13662026/11/11 23:34:46 INFO Uploading 1 narinfos13672026/11/11 23:34:46 INFO Upload complete. (344ms)1368=== NAME TestClientSharedPathCommittedMidPush1369 client_integration_test.go:728: Retrieved narinfo from S3:1370 StorePath: /build/TestClientSharedPathCommittedMidPush3545542425/001/store/ffiqx4jf1fa7rwi89g5zm60688dkm7xl-shared-dep1371 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1372 Compression: zstd1373 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821374 NarSize: 1361375 References: 1376 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1377=== NAME TestClientPushesUseOnePush1378 client_pushes_test.go:97: Retrieved narinfo from S3:1379 StorePath: /build/TestClientPushesUseOnePush3976089695/001/store/qpkc3xa27r7inyqzs3crckl9n8a9nrbr-b1380 URL: nar/05r19j9n2qlxxb00jik2y1qxzss8brzm1bbhxpxgjv3lvc9nhqmn.nar.zst1381 Compression: zstd1382 NarHash: sha256:05r19j9n2qlxxb00jik2y1qxzss8brzm1bbhxpxgjv3lvc9nhqmn1383 NarSize: 2161384 References: /build/TestClientPushesUseOnePush3976089695/001/store/5qj1wsmga5d6clr967c7dfbmbli883q0-shared-dep1385 CA: text:sha256:1yxr76m301bjkq898iv8yl3nl9ddvsn07p69ii7xxk83msvcdwg01386=== NAME TestClientSharedPathCommittedMidPush1387 client_integration_test.go:728: Retrieved narinfo from S3:1388 StorePath: /build/TestClientSharedPathCommittedMidPush3545542425/001/store/zydpzz9i1hbd5jr35zi58957333rbvvj-top1389 URL: nar/0ljvn9rbmj70fv6ff2i4j4nlp2agbi6zrpg4rysibyaq2ygp5kf7.nar.zst1390 Compression: zstd1391 NarHash: sha256:0ljvn9rbmj70fv6ff2i4j4nlp2agbi6zrpg4rysibyaq2ygp5kf71392 NarSize: 2241393 References: /build/TestClientSharedPathCommittedMidPush3545542425/001/store/ffiqx4jf1fa7rwi89g5zm60688dkm7xl-shared-dep1394 CA: text:sha256:06gw2xv73r9jcba89yvsx5gyha1793xdi58sr4w1hlv6x1v7a9c913952026/11/11 23:34:46 INFO Received complete push request method=POST path=/api/pushes/1/complete13962026/11/11 23:34:46 WARN Failed to register uploaded object key=kxi2dmh829aiwcgndqfrrq6qsn3d58gs.narinfo error="server returned 404: 404 page not found\n"1397--- PASS: TestClientPushesUseOnePush (1.06s)1398=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1399--- PASS: TestClientSharedPathCommittedMidPush (1.03s)1400=== CONT TestSharedNarBothUploadsComplete14012026/11/11 23:34:46 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14022026/11/11 23:34:46 WARN mTLS auth: bound subjects configured but subject DN unavailable14032026/11/11 23:34:46 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1404--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.82s)1405=== CONT TestPush_SignsNarinfosOfItsPendingObjects14062026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes14072026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes14082026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes14092026/11/11 23:34:46 INFO Completed push id=1 objects=3 duration=22.715416ms14102026/11/11 23:34:46 INFO Upload complete. (159ms)14112026/11/11 23:34:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14122026/11/11 23:34:46 INFO Uploading 999wwkl6iqpn2g74j74396ns5g9441x2-unpinned-file.txt (128B)14132026/11/11 23:34:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14142026/11/11 23:34:46 INFO Uploading 1pkkazii893pi8lxrrbxyj2n54n2d658-test-script (136B)14152026/11/11 23:34:46 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14162026/11/11 23:34:46 INFO Uploading kgq88s0049757nnqqm0sisf187r16kqb-test-file-0.txt (160B)14172026/11/11 23:34:46 INFO Uploading 5qflqjdmdkbv0d15hqz6x3fz7g7m6vfp-test-file-1.txt (160B)14182026/11/11 23:34:46 INFO Uploading hapkp8hcp6mmlv6bny8aqqa0samj2fcx-test-file-2.txt (160B)14192026/11/11 23:34:46 WARN Failed to register uploaded object key=999wwkl6iqpn2g74j74396ns5g9441x2.ls error="server returned 404: 404 page not found\n"14202026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14212026/11/11 23:34:46 INFO Signed narinfos id=2 count=114222026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14232026/11/11 23:34:46 INFO Uploading 1 narinfos14242026/11/11 23:34:46 WARN Failed to register uploaded object key=1pkkazii893pi8lxrrbxyj2n54n2d658.ls error="server returned 404: 404 page not found\n"14252026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14262026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14272026/11/11 23:34:46 WARN Failed to register uploaded object key=kgq88s0049757nnqqm0sisf187r16kqb.ls error="server returned 404: 404 page not found\n"14282026/11/11 23:34:46 WARN Failed to register uploaded object key=hapkp8hcp6mmlv6bny8aqqa0samj2fcx.ls error="server returned 404: 404 page not found\n"14292026/11/11 23:34:46 INFO Received complete push request method=POST path=/api/pushes/2/complete14302026/11/11 23:34:46 WARN Failed to register uploaded object key=999wwkl6iqpn2g74j74396ns5g9441x2.narinfo error="server returned 404: 404 page not found\n"14312026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14322026/11/11 23:34:46 WARN Failed to register uploaded object key=5qflqjdmdkbv0d15hqz6x3fz7g7m6vfp.ls error="server returned 404: 404 page not found\n"14332026/11/11 23:34:46 WARN Failed to register uploaded object key=log/c9i5zpwkl7ngqrjqwkddzzivvkxn78ha-test-script.drv error="server returned 404: 404 page not found\n"14342026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14352026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14362026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14372026/11/11 23:34:46 INFO Signed narinfos id=1 count=114382026/11/11 23:34:46 INFO Uploading 1 narinfos14392026/11/11 23:34:46 INFO Signed narinfos id=1 count=314402026/11/11 23:34:46 INFO Uploading 3 narinfos14412026/11/11 23:34:46 INFO Completed push id=2 objects=3 duration=3.900298ms14422026/11/11 23:34:46 INFO Upload complete. (66ms)14432026/11/11 23:34:46 INFO Received complete push request method=POST path=/api/pushes/1/complete14442026/11/11 23:34:46 WARN Failed to register uploaded object key=kgq88s0049757nnqqm0sisf187r16kqb.narinfo error="server returned 404: 404 page not found\n"14452026/11/11 23:34:46 WARN Failed to register uploaded object key=1pkkazii893pi8lxrrbxyj2n54n2d658.narinfo error="server returned 404: 404 page not found\n"14462026/11/11 23:34:46 WARN Failed to register uploaded object key=hapkp8hcp6mmlv6bny8aqqa0samj2fcx.narinfo error="server returned 404: 404 page not found\n"14472026/11/11 23:34:46 INFO Received complete push request method=POST path=/api/pushes/1/complete14482026/11/11 23:34:46 WARN Failed to register uploaded object key=5qflqjdmdkbv0d15hqz6x3fz7g7m6vfp.narinfo error="server returned 404: 404 page not found\n"14492026/11/11 23:34:46 INFO Completed push id=1 objects=4 duration=11.570183ms14502026/11/11 23:34:46 INFO Upload complete. (80ms)14512026/11/11 23:34:46 INFO Completed push id=1 objects=9 duration=12.304492ms14522026/11/11 23:34:46 INFO All 1 paths already cached14532026/11/11 23:34:46 INFO Upload complete. (82ms)1454=== NAME TestClientMultipleUploads1455 client_integration_test.go:417: Uploaded 3 paths in 193.67338ms1456=== NAME TestClientIntegration1457 client_integration_test.go:318: Retrieved narinfo from S3:1458 StorePath: /build/TestClientIntegration2403006094/002/store/kxi2dmh829aiwcgndqfrrq6qsn3d58gs-test-file.txt1459 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1460 Compression: zstd1461 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11462 NarSize: 1521463 References: 1464 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11465=== NAME TestClientWithDependencies1466 client_integration_test.go:665: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1746253158/001/store) requires matching store prefix1467=== RUN TestService_RequireScope_OIDC/builder_may_write1468=== PAUSE TestService_RequireScope_OIDC/builder_may_write1469=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1470=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1471=== RUN TestService_RequireScope_OIDC/ops_may_admin1472=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1473=== RUN TestService_RequireScope_OIDC/ops_may_not_write1474=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1475=== RUN TestService_RequireScope_OIDC/reader_may_not_write1476=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1477=== RUN TestService_RequireScope_OIDC/static_token_may_admin1478=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1479=== RUN TestService_RequireScope_OIDC/static_token_may_write1480=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1481=== RUN TestService_RequireScope_OIDC/reader_may_read1482=== PAUSE TestService_RequireScope_OIDC/reader_may_read1483=== RUN TestService_RequireScope_OIDC/writer_implies_read1484=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1485=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1486=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1487=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1488=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1489=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1490=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1491=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1492=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1493=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1494=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1495=== NAME TestClientIntegration1496 client_integration_test.go:319: Retrieved .ls file from S3 (compressed size: 77 bytes)1497=== CONT TestPush_RejectsBadRequests1498=== NAME TestClientIntegration1499 client_integration_test.go:319: Decompressed .ls content (64 bytes):1500 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1501--- PASS: TestClientWithDependencies (1.08s)1502=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1503--- PASS: TestClientMultipleUploads (1.01s)1504=== CONT TestPush_RootsAreLockedInByteOrder1505=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1506=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1507=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1508=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1509=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1510=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1511=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1512=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1513=== CONT TestPush_CompleteWaitsForCleanupOfThePush15142026/11/11 23:34:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures15152026/11/11 23:34:46 INFO Garbage collection started1516--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.85s)1517=== CONT TestPush_RepeatedRootCommitsOnce15182026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes15192026/11/11 23:34:46 INFO Aborted multipart uploads count=0 kept=015202026/11/11 23:34:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15212026/11/11 23:34:46 INFO Uploading xgvmgvpykgc0mg1lwisxmd0syhjnaks8-ca-test (144B)15222026/11/11 23:34:46 WARN Force mode enabled - objects will be deleted immediately without grace period15232026/11/11 23:34:46 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15242026/11/11 23:34:46 WARN Failed to register uploaded object key=xgvmgvpykgc0mg1lwisxmd0syhjnaks8.ls error="server returned 404: 404 page not found\n"15252026/11/11 23:34:46 WARN Failed to register uploaded object key=log/fxb11cnm9srvblcqi58vr9c799az71a6-ca-test.drv error="server returned 404: 404 page not found\n"15262026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15272026/11/11 23:34:46 INFO Signed narinfos id=1 count=115282026/11/11 23:34:46 INFO Uploading 1 narinfos15292026/11/11 23:34:46 INFO Received complete push request method=POST path=/api/pushes/1/complete15302026/11/11 23:34:46 WARN Failed to register uploaded object key=xgvmgvpykgc0mg1lwisxmd0syhjnaks8.narinfo error="server returned 404: 404 page not found\n"15312026/11/11 23:34:46 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1532--- PASS: TestService_AuthMiddleware (0.85s)1533=== CONT TestPush_CompleteCommitsEveryRoot15342026/11/11 23:34:46 INFO Completed push id=1 objects=4 duration=22.209676ms15352026/11/11 23:34:46 INFO Upload complete. (129ms)1536=== NAME TestClientCADerivations1537 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1470143169/001/store/xgvmgvpykgc0mg1lwisxmd0syhjnaks8-ca-test1538 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1539 Compression: zstd1540 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1541 NarSize: 1441542 References: 1543 Deriver: /build/TestClientCADerivations1470143169/001/store/fxb11cnm9srvblcqi58vr9c799az71a6-ca-test.drv1544 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1545 client_ca_test.go:185: Checking for realisation files in S3...1546 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1547 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15482026/11/11 23:34:46 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=015492026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes15502026/11/11 23:34:46 INFO Object in database but missing from S3 key=kxi2dmh829aiwcgndqfrrq6qsn3d58gs.ls15512026/11/11 23:34:46 WARN Found objects in DB but missing from S3, will re-upload count=115522026/11/11 23:34:46 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15532026/11/11 23:34:46 INFO Vacuumed table table=pending_closures15542026/11/11 23:34:46 INFO Received complete push request method=POST path=/api/pushes/2/complete15552026/11/11 23:34:46 WARN Failed to register uploaded object key=kxi2dmh829aiwcgndqfrrq6qsn3d58gs.ls error="server returned 404: 404 page not found\n"15562026/11/11 23:34:46 INFO Vacuumed table table=pending_objects1557--- PASS: TestReadRedirectKeepsNarinfoProxied (0.79s)1558=== CONT TestPush_OverlappingRootsStoreOneRowPerKey15592026/11/11 23:34:46 INFO Vacuumed table table=multipart_uploads15602026/11/11 23:34:46 INFO Completed push id=2 objects=3 duration=3.751428ms15612026/11/11 23:34:46 INFO Upload complete. (51ms)1562=== NAME TestClientIntegration1563 client_integration_test.go:336: Retrieved .ls file from S3 (compressed size: 62 bytes)1564 client_integration_test.go:336: Decompressed .ls content (49 bytes):1565 {"version":1,"root":{"type":"regular","size":39}}15662026/11/11 23:34:46 INFO Vacuumed table table=closures15672026/11/11 23:34:46 INFO Vacuumed table table=objects15682026/11/11 23:34:46 INFO Received cleanup request method=DELETE path=/api/pending_closures15692026/11/11 23:34:46 INFO Aborted multipart uploads count=0 kept=015702026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures15712026/11/11 23:34:46 INFO Received cleanup request method=DELETE path=/api/pending_closures15722026/11/11 23:34:46 INFO Aborted multipart uploads count=1 kept=015732026/11/11 23:34:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15742026-11-11 23:34:46.791 UTC [1372] ERROR: Closure does not exist: id=115752026-11-11 23:34:46.791 UTC [1372] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE15762026-11-11 23:34:46.791 UTC [1372] STATEMENT: -- name: CommitPendingClosure :one1577 SELECT commit_pending_closure($1::bigint)::bigint1578 1579--- PASS: TestService_cleanupPendingClosuresHandler (0.59s)1580=== CONT TestReadRedirectUsesPublicS3URL15812026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures1582--- PASS: TestService_Rustfstest (0.26s)1583=== CONT TestReadProxyRangeRequest15842026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes15852026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures1586=== NAME TestClientCADerivations1587 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1588 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1589 error: binary cache 's3://bucket45?endpoint=http://localhost:36219®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1470143169/001/store'1590 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11591--- PASS: TestClientCADerivations (1.16s)1592=== CONT TestReadProxyHead15932026/11/11 23:34:46 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15942026/11/11 23:34:46 INFO Received complete push request method=POST path=/api/pushes/3/complete15952026/11/11 23:34:46 WARN Failed to register uploaded object key=kxi2dmh829aiwcgndqfrrq6qsn3d58gs.ls error="server returned 404: 404 page not found\n"15962026/11/11 23:34:46 INFO Completed push id=3 objects=3 duration=2.532768ms15972026/11/11 23:34:46 INFO Upload complete. (58ms)1598=== NAME TestClientIntegration1599 client_integration_test.go:353: Retrieved .ls file from S3 (compressed size: 62 bytes)1600 client_integration_test.go:353: Decompressed .ls content (49 bytes):1601 {"version":1,"root":{"type":"regular","size":39}}1602 client_integration_test.go:364: Testing garbage collection...16032026/11/11 23:34:46 INFO lead: released remote=192.0.2.1:1234 generation=11604--- PASS: TestLeadEndsOnShutdown (1.76s)1605=== CONT TestReadRedirectNar16062026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures16072026/11/11 23:34:46 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst16082026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures1609--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.32s)1610=== CONT TestReadProxyDisabled16112026/11/11 23:34:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16122026/11/11 23:34:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures16132026/11/11 23:34:46 INFO Garbage collection started16142026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures16152026/11/11 23:34:46 INFO Aborted multipart uploads count=0 kept=016162026/11/11 23:34:46 WARN Force mode enabled - objects will be deleted immediately without grace period16172026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures16182026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures16192026/11/11 23:34:46 INFO lead: released remote=192.0.2.1:1234 generation=116202026/11/11 23:34:46 INFO lead: acquired remote=192.0.2.1:1234 generation=216212026/11/11 23:34:46 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=016222026/11/11 23:34:46 INFO Received push request method=POST path=/api/pushes16232026/11/11 23:34:46 INFO Vacuumed table table=pending_closures16242026/11/11 23:34:46 INFO Vacuumed table table=pending_objects16252026/11/11 23:34:46 INFO Vacuumed table table=multipart_uploads16262026/11/11 23:34:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16272026/11/11 23:34:46 INFO Vacuumed table table=closures16282026/11/11 23:34:46 INFO lead: released remote=192.0.2.1:1234 generation=116292026/11/11 23:34:46 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLmFiMjc3NDMzLTNjNjgtNGJmYy1iYjBkLTZkM2Q3ZTZmMzhjMngxNzk0NDQwMDg2OTUzMDAzNTI316302026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16312026/11/11 23:34:46 INFO Vacuumed table table=objects16322026/11/11 23:34:46 INFO Signed narinfos id=1 count=116332026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16342026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16352026/11/11 23:34:46 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"16362026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16372026/11/11 23:34:46 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"16382026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16392026/11/11 23:34:46 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=116402026/11/11 23:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16412026/11/11 23:34:46 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1642--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.39s)1643=== CONT TestReadProxyRootRedirectsToIndexHTML16442026/11/11 23:34:46 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLmFiMjc3NDMzLTNjNjgtNGJmYy1iYjBkLTZkM2Q3ZTZmMzhjMngxNzk0NDQwMDg2OTUzMDAzNTI3 parts=11645--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.41s)1646=== CONT TestReadProxyConditionalGet1647--- PASS: TestReadProxyRangeRequest (0.19s)1648=== CONT TestReadProxyOutlastsServerWriteTimeout16492026/11/11 23:34:47 INFO lead: acquired remote=192.0.2.1:1234 generation=21650=== RUN TestPush_RejectsBadRequests/no_roots1651=== PAUSE TestPush_RejectsBadRequests/no_roots1652=== RUN TestPush_RejectsBadRequests/no_objects1653=== PAUSE TestPush_RejectsBadRequests/no_objects1654=== RUN TestPush_RejectsBadRequests/bad_root1655=== PAUSE TestPush_RejectsBadRequests/bad_root1656=== RUN TestPush_RejectsBadRequests/root_not_in_objects1657=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1658=== CONT TestReadProxyNarStreaming16592026/11/11 23:34:47 INFO Received push request method=POST path=/api/pushes16602026/11/11 23:34:47 INFO lead: given back to the incumbent remote=192.0.2.1:1234 generation=216612026/11/11 23:34:47 INFO lead: acquired remote=192.0.2.1:1234 generation=316622026/11/11 23:34:47 INFO Received push request method=POST path=/api/pushes16632026/11/11 23:34:47 INFO Received complete push request method=POST path=/api/pushes/1/complete16642026-11-11 23:34:47.121 UTC [2019] ERROR: could not obtain lock on row in relation "closures"16652026-11-11 23:34:47.121 UTC [2019] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16662026-11-11 23:34:47.122 UTC [2019] ERROR: could not obtain lock on row in relation "closures"16672026-11-11 23:34:47.122 UTC [2019] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16682026-11-11 23:34:47.122 UTC [2019] ERROR: could not obtain lock on row in relation "closures"16692026-11-11 23:34:47.122 UTC [2019] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16702026-11-11 23:34:47.122 UTC [2019] ERROR: could not obtain lock on row in relation "closures"16712026-11-11 23:34:47.122 UTC [2019] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16722026-11-11 23:34:47.122 UTC [2019] ERROR: could not obtain lock on row in relation "closures"16732026-11-11 23:34:47.122 UTC [2019] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16742026/11/11 23:34:47 INFO Received push request method=POST path=/api/pushes16752026/11/11 23:34:47 INFO Completed push id=1 objects=4 duration=8.104155ms16762026/11/11 23:34:47 INFO Received push request method=POST path=/api/pushes1677--- PASS: TestPush_RootsAreLockedInByteOrder (0.47s)1678=== CONT TestReadProxyInvalidPath16792026/11/11 23:34:47 INFO Received push request method=POST path=/api/pushes16802026/11/11 23:34:47 INFO Received complete push request method=POST path=/api/pushes/1/complete16812026/11/11 23:34:47 INFO Aborted multipart uploads count=0 kept=01682--- PASS: TestDeleteClosuresRacingPins (1.76s)1683=== CONT TestReadProxy40416842026/11/11 23:34:47 INFO Completed push id=1 objects=4 duration=9.194524ms1685--- PASS: TestPush_RepeatedRootCommitsOnce (0.51s)1686=== CONT TestReadProxyContentNegotiation16872026/11/11 23:34:47 INFO Received push request method=POST path=/api/pushes16882026/11/11 23:34:47 WARN Force mode enabled - objects will be deleted immediately without grace period16892026/11/11 23:34:47 INFO lead: released remote=192.0.2.1:1234 generation=116902026/11/11 23:34:47 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=016912026/11/11 23:34:47 INFO Received complete push request method=POST path=/api/pushes/1/complete16922026/11/11 23:34:47 INFO Vacuumed table table=pending_closures16932026/11/11 23:34:47 INFO Received push request method=POST path=/api/pushes16942026/11/11 23:34:47 INFO Vacuumed table table=pending_objects16952026/11/11 23:34:47 INFO Completed push id=1 objects=6 duration=8.310705ms16962026/11/11 23:34:47 INFO Vacuumed table table=multipart_uploads1697--- PASS: TestPush_CompleteCommitsEveryRoot (0.52s)1698=== CONT TestReadProxyNarinfoAlreadyDecompressed16992026/11/11 23:34:47 INFO Vacuumed table table=closures17002026/11/11 23:34:47 INFO Vacuumed table table=objects17012026/11/11 23:34:47 INFO Received complete push request method=POST path=/api/pushes/2/complete17022026/11/11 23:34:47 INFO Completed push id=2 objects=4 duration=5.542587ms1703--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.59s)1704=== CONT TestCreatePin_ReservedPins1705--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.50s)1706=== CONT TestIsValidCachePath1707=== RUN TestIsValidCachePath/narinfo1708=== PAUSE TestIsValidCachePath/narinfo1709=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1710=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1711=== RUN TestIsValidCachePath/nar_zst1712=== PAUSE TestIsValidCachePath/nar_zst1713=== RUN TestIsValidCachePath/nar_xz1714=== PAUSE TestIsValidCachePath/nar_xz1715=== RUN TestIsValidCachePath/nar_bz21716=== PAUSE TestIsValidCachePath/nar_bz21717=== RUN TestIsValidCachePath/nar_uncompressed1718=== PAUSE TestIsValidCachePath/nar_uncompressed1719=== RUN TestIsValidCachePath/ls1720=== PAUSE TestIsValidCachePath/ls17212026/11/11 23:34:47 INFO lead: acquired remote=192.0.2.1:1234 generation=21722=== RUN TestIsValidCachePath/log1723=== PAUSE TestIsValidCachePath/log1724=== RUN TestIsValidCachePath/realisation1725=== PAUSE TestIsValidCachePath/realisation1726=== RUN TestIsValidCachePath/nix-cache-info1727=== PAUSE TestIsValidCachePath/nix-cache-info1728=== RUN TestIsValidCachePath/index.html1729=== PAUSE TestIsValidCachePath/index.html1730=== RUN TestIsValidCachePath/traversal_parent1731=== PAUSE TestIsValidCachePath/traversal_parent1732=== RUN TestIsValidCachePath/traversal_in_middle1733=== PAUSE TestIsValidCachePath/traversal_in_middle1734=== RUN TestIsValidCachePath/invalid_char_e1735=== PAUSE TestIsValidCachePath/invalid_char_e1736=== RUN TestIsValidCachePath/invalid_char_u1737=== PAUSE TestIsValidCachePath/invalid_char_u1738=== RUN TestIsValidCachePath/random_path1739=== PAUSE TestIsValidCachePath/random_path1740=== RUN TestIsValidCachePath/empty1741=== PAUSE TestIsValidCachePath/empty1742=== RUN TestIsValidCachePath/leading_slash1743=== PAUSE TestIsValidCachePath/leading_slash1744=== RUN TestIsValidCachePath/wrong_extension1745=== PAUSE TestIsValidCachePath/wrong_extension1746=== RUN TestIsValidCachePath/short_hash1747=== PAUSE TestIsValidCachePath/short_hash1748=== CONT TestParseSingleRange1749=== RUN TestParseSingleRange/none1750=== PAUSE TestParseSingleRange/none1751=== RUN TestParseSingleRange/unknown_unit1752=== PAUSE TestParseSingleRange/unknown_unit1753=== RUN TestParseSingleRange/multi-range_ignored1754=== PAUSE TestParseSingleRange/multi-range_ignored1755=== RUN TestParseSingleRange/malformed_no_dash1756=== PAUSE TestParseSingleRange/malformed_no_dash1757=== RUN TestParseSingleRange/malformed_both_empty1758=== PAUSE TestParseSingleRange/malformed_both_empty1759=== RUN TestParseSingleRange/malformed_end_before_start1760=== PAUSE TestParseSingleRange/malformed_end_before_start1761=== RUN TestParseSingleRange/closed1762=== PAUSE TestParseSingleRange/closed1763=== RUN TestParseSingleRange/open-ended1764=== PAUSE TestParseSingleRange/open-ended1765=== RUN TestParseSingleRange/end_clamped_to_size1766=== PAUSE TestParseSingleRange/end_clamped_to_size1767=== RUN TestParseSingleRange/suffix1768=== PAUSE TestParseSingleRange/suffix1769=== RUN TestParseSingleRange/suffix_exceeds_size1770=== PAUSE TestParseSingleRange/suffix_exceeds_size1771=== RUN TestParseSingleRange/single_byte1772=== PAUSE TestParseSingleRange/single_byte1773=== RUN TestParseSingleRange/start_past_EOF1774=== PAUSE TestParseSingleRange/start_past_EOF1775=== RUN TestParseSingleRange/start_far_past_EOF1776=== PAUSE TestParseSingleRange/start_far_past_EOF1777=== CONT TestReadProxyNarinfo1778--- PASS: TestReadRedirectUsesPublicS3URL (0.48s)1779=== CONT TestPresentNotReportedWhileGCDeletesClosure1780=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1781=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1782=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1783=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1784=== CONT TestPresentRefreshesOnlyStaleClosures1785--- PASS: TestReadProxyHead (0.44s)1786=== CONT TestPresentReportsOnlyClosureRoots17872026/11/11 23:34:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36083/oidc1788--- PASS: TestReadRedirectNar (0.46s)1789=== CONT TestObjectStatsUpdatedOncePerCommit1790--- PASS: TestReadProxyDisabled (0.50s)1791=== CONT TestPendingCleanupUsesOneCutoff1792--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.43s)1793=== CONT TestObjectStatsTrigger17942026-11-11 23:34:47.443 UTC [2031] ERROR: Push does not exist: id=117952026-11-11 23:34:47.443 UTC [2031] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE17962026-11-11 23:34:47.443 UTC [2031] STATEMENT: SELECT commit_push($1)1797--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.79s)1798=== CONT TestOrphanedObjectsGCStressTest1799--- PASS: TestReadProxyConditionalGet (0.46s)1800=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded18012026/11/11 23:34:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18022026/11/11 23:34:47 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLmVhMzBjYmZlLWQxYTctNDljMC1hYmIwLTc4MWFmMDI2N2I0MXgxNzk0NDQwMDg2ODkxMDc0NTI2 parts=1218032026/11/11 23:34:47 INFO Received uploads request method=POST path=/api/pending_closures1804--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.94s)1805=== CONT TestOrphanedObjectsGC18062026/11/11 23:34:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1807--- PASS: TestReadProxyNarStreaming (0.49s)1808=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed18092026/11/11 23:34:47 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLmIwMzE3M2Y1LTZhM2MtNDU0Ni05NmYyLWQyNDJkOTc4ZDQxMngxNzk0NDQwMDg2OTIyNTY5Mzc2 parts=121810--- PASS: TestReadProxyInvalidPath (0.42s)1811=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1812--- PASS: TestReadProxy404 (0.47s)1813=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1814--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.43s)1815=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1816--- PASS: TestReadProxyContentNegotiation (0.48s)1817=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1818--- PASS: TestPresentRefreshesOnlyStaleClosures (0.45s)1819=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1820--- PASS: TestPresentReportsOnlyClosureRoots (0.46s)1821=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18222026/11/11 23:34:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18232026/11/11 23:34:47 WARN Refused reserved pin name=worker-x86_64-linux18242026/11/11 23:34:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18252026/11/11 23:34:47 INFO Received create pin request method=POST path=/api/pins/my-app18262026/11/11 23:34:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1827--- PASS: TestCreatePin_ReservedPins (0.54s)1828=== CONT TestServerTLSConfig/no_client_CA1829=== CONT TestServerTLSConfig/not_a_PEM_file1830=== CONT TestServerTLSConfig/missing_CA_file1831--- PASS: TestServerTLSConfig (0.01s)1832 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1833 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1834 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1835=== CONT TestGCEndsOnShutdown/before_the_run18362026/11/11 23:34:47 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1837--- PASS: TestReadProxyNarinfo (0.55s)1838=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18392026/11/11 23:34:47 INFO Received uploads request method=POST path=/api/pending_closures18402026/11/11 23:34:47 INFO Received uploads request method=POST path=/api/pending_closures1841--- PASS: TestObjectStatsUpdatedOncePerCommit (0.53s)1842=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18432026/11/11 23:34:47 INFO Received cleanup request method=DELETE path=/api/pending_closures1844--- PASS: TestObjectStatsTrigger (0.47s)1845=== CONT TestResolveDBConnectionString/flag_wins1846=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1847=== CONT TestResolveDBConnectionString/nothing_configured1848=== CONT TestResolveDBConnectionString/missing_file_is_an_error1849=== CONT TestResolveDBConnectionString/file_when_flag_empty1850=== CONT TestClientErrorHandling/InvalidStorePath1851--- PASS: TestResolveDBConnectionString (0.00s)1852 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1853 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1854 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1855 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1856 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)18572026/11/11 23:34:47 INFO Received uploads request method=POST path=/api/pending_closures1858--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.49s)1859=== CONT TestClientErrorHandling/ServerNotAvailable18602026/11/11 23:34:47 INFO Received uploads request method=POST path=/api/pending_closures18612026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures18622026/11/11 23:34:48 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/present18632026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures18642026/11/11 23:34:48 INFO lead: released remote=192.0.2.1:1234 generation=218652026/11/11 23:34:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18662026/11/11 23:34:48 INFO lead: acquired remote=192.0.2.1:1234 generation=318672026/11/11 23:34:48 INFO lead: released remote=192.0.2.1:1234 generation=31868--- PASS: TestLeadGenerationGrowsWithEveryGrant (2.90s)1869=== CONT TestClientErrorHandling/InvalidAuthToken18702026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures18712026/11/11 23:34:48 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLjQ5OWE0YTE4LTQwNjgtNGNhMC1iNTI5LTczZWYzYTA4Y2M4OXgxNzk0NDQwMDg2OTMxNDgxMjYx parts=121872--- PASS: TestSharedNarBothUploadsComplete (1.51s)1873=== CONT TestCacheConfigHandler/full_config,_no_issuer1874=== CONT TestCacheConfigHandler/no_signing_keys1875=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1876=== CONT TestCacheConfigHandler/no_cache_url_configured1877--- PASS: TestCacheConfigHandler (0.00s)1878 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1879 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1880 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1881 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1882=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18832026/11/11 23:34:48 INFO Received uploads request method=POST path=/1884=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18852026/11/11 23:34:48 INFO Received complete multipart upload request method=POST path=/1886=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18872026/11/11 23:34:48 INFO Received uploads request method=POST path=/1888=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18892026/11/11 23:34:48 INFO Received request for more parts method=POST path=/1890--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1891 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1892 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1893 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1894 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1895=== CONT TestIsValidUploadKey/narinfo1896=== CONT TestIsValidUploadKey/realisation_plus_in_output1897=== CONT TestIsValidUploadKey/unknown_type1898=== CONT TestIsValidUploadKey/empty_key1899=== CONT TestIsValidUploadKey/absolute1900=== CONT TestIsValidUploadKey/traversal_nar1901=== CONT TestIsValidUploadKey/traversal1902=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1903=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1904=== CONT TestIsValidUploadKey/nix-cache-info1905=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1906=== CONT TestIsValidUploadKey/index.html1907=== CONT TestIsValidUploadKey/build_log_home-manager_file1908=== CONT TestIsValidUploadKey/realisation1909=== CONT TestIsValidUploadKey/build_log_plus_in_name1910=== CONT TestIsValidUploadKey/build_log_question_mark1911=== CONT TestIsValidUploadKey/build_log_equals1912=== CONT TestIsValidUploadKey/nar_plain1913=== CONT TestIsValidUploadKey/build_log1914=== CONT TestIsValidUploadKey/nar_xz1915=== CONT TestIsValidUploadKey/nar_zst1916=== CONT TestIsValidUploadKey/listing1917=== CONT TestPendingClosureWriteTimeout/empty1918=== CONT TestPendingClosureWriteTimeout/670k_objects1919=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1920--- PASS: TestIsValidUploadKey (0.00s)1921 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1922 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1923 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1924 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1925 --- PASS: TestIsValidUploadKey/absolute (0.00s)1926 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1927 --- PASS: TestIsValidUploadKey/traversal (0.00s)1928 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1929 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1930 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1931 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1932 --- PASS: TestIsValidUploadKey/index.html (0.00s)1933 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1934 --- PASS: TestIsValidUploadKey/realisation (0.00s)1935 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1936 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1937 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1938 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1939 --- PASS: TestIsValidUploadKey/build_log (0.00s)1940 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1941 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1942 --- PASS: TestIsValidUploadKey/listing (0.00s)19432026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures19442026/11/11 23:34:48 WARN Request failed, retrying attempt=2 backoff=212.092381ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19452026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures19462026/11/11 23:34:48 INFO Aborted multipart uploads count=0 kept=019472026/11/11 23:34:48 WARN Force mode enabled - objects will be deleted immediately without grace period19482026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures19492026/11/11 23:34:48 INFO Aborted multipart uploads count=0 kept=019502026/11/11 23:34:48 WARN Force mode enabled - objects will be deleted immediately without grace period19512026/11/11 23:34:48 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=019522026/11/11 23:34:48 INFO Vacuumed table table=pending_closures19532026/11/11 23:34:48 INFO Vacuumed table table=pending_objects19542026/11/11 23:34:48 INFO Vacuumed table table=multipart_uploads19552026/11/11 23:34:48 INFO Vacuumed table table=closures19562026/11/11 23:34:48 INFO Vacuumed table table=objects19572026/11/11 23:34:48 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=019582026/11/11 23:34:48 INFO Vacuumed table table=pending_closures19592026/11/11 23:34:48 INFO Vacuumed table table=pending_objects19602026/11/11 23:34:48 INFO Vacuumed table table=multipart_uploads19612026/11/11 23:34:48 INFO Vacuumed table table=closures1962=== CONT TestPendingClosureWriteTimeout/400_objects1963=== CONT TestProxyWriteTimeout/narinfo1964=== CONT TestProxyWriteTimeout/10_GiB_nar1965=== CONT TestProxyWriteTimeout/unknown_size1966=== CONT TestProxyWriteTimeout/1_GiB_nar1967--- PASS: TestProxyWriteTimeout (0.00s)1968 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1969 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1970 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1971 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1972=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19732026/11/11 23:34:48 INFO Received uploads request method=POST path=/19742026/11/11 23:34:48 INFO Vacuumed table table=objects1975=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19762026/11/11 23:34:48 INFO Received request for more parts method=POST path=/1977--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1978 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.47s)1979 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.52s)1980=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19812026/11/11 23:34:48 INFO Received complete multipart upload request method=POST path=/19822026/11/11 23:34:48 INFO Aborted multipart uploads count=0 kept=019832026/11/11 23:34:48 WARN Force mode enabled - objects will be deleted immediately without grace period1984=== CONT TestService_RequireScope_OIDC/builder_may_write19852026/11/11 23:34:48 INFO Aborted multipart uploads count=0 kept=01986=== CONT TestService_RequireScope_OIDC/reader_may_read1987=== CONT TestService_RequireScope_OIDC/static_token_may_write1988=== CONT TestService_RequireScope_OIDC/static_token_may_admin1989=== CONT TestService_RequireScope_OIDC/ops_may_not_write1990=== CONT TestService_RequireScope_OIDC/reader_may_not_write1991=== CONT TestService_RequireScope_OIDC/ops_may_admin1992=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1993=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19942026/11/11 23:34:48 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]1995=== CONT TestService_RequireScope_OIDC/writer_implies_read1996=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1997=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1998=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1999=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2000=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2001=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20022026/11/11 23:34:48 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]2003=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2004=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2005--- PASS: TestService_RequireScope_OIDC (0.93s)2006 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2007 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2008 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2009 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2010 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2011 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2012 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2013 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2014 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2015 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2016 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2017 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2018 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2019 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)20202026/11/11 23:34:48 WARN Force mode enabled - objects will be deleted immediately without grace period2021=== CONT TestPush_RejectsBadRequests/no_roots20222026/11/11 23:34:48 WARN Authentication failed token_preview=eyJhbGciOi...yfTKMK9J-A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]20232026/11/11 23:34:48 INFO Received push request method=POST path=/api/pushes2024=== CONT TestPush_RejectsBadRequests/bad_root20252026/11/11 23:34:48 INFO Received push request method=POST path=/api/pushes2026=== CONT TestPush_RejectsBadRequests/root_not_in_objects20272026/11/11 23:34:48 INFO Received push request method=POST path=/api/pushes2028=== CONT TestPush_RejectsBadRequests/no_objects20292026/11/11 23:34:48 INFO Received push request method=POST path=/api/pushes2030=== CONT TestIsValidCachePath/narinfo2031--- PASS: TestPush_RejectsBadRequests (0.39s)2032 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2033 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2034 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2035 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2036=== CONT TestIsValidCachePath/short_hash2037=== CONT TestIsValidCachePath/wrong_extension2038=== CONT TestIsValidCachePath/leading_slash2039=== CONT TestIsValidCachePath/empty2040=== CONT TestIsValidCachePath/random_path2041=== CONT TestIsValidCachePath/invalid_char_u2042=== CONT TestIsValidCachePath/invalid_char_e2043=== CONT TestIsValidCachePath/nar_uncompressed2044=== CONT TestIsValidCachePath/traversal_in_middle2045=== CONT TestIsValidCachePath/nix-cache-info2046=== CONT TestIsValidCachePath/realisation2047=== CONT TestIsValidCachePath/index.html2048=== CONT TestIsValidCachePath/traversal_parent2049=== CONT TestIsValidCachePath/nar_bz22050=== CONT TestIsValidCachePath/log2051--- PASS: TestService_AuthMiddleware_OIDC (0.92s)2052 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2053 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2054 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2055 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2056=== CONT TestIsValidCachePath/nar_xz2057=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2058=== CONT TestIsValidCachePath/ls2059=== CONT TestParseSingleRange/none2060=== CONT TestParseSingleRange/suffix2061=== CONT TestIsValidCachePath/nar_zst2062=== CONT TestParseSingleRange/end_clamped_to_size2063--- PASS: TestIsValidCachePath (0.00s)2064 --- PASS: TestIsValidCachePath/narinfo (0.00s)2065 --- PASS: TestIsValidCachePath/short_hash (0.00s)2066 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2067 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2068 --- PASS: TestIsValidCachePath/empty (0.00s)2069 --- PASS: TestIsValidCachePath/random_path (0.00s)2070 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2071 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2072 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2073 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2074 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2075 --- PASS: TestIsValidCachePath/realisation (0.00s)2076 --- PASS: TestIsValidCachePath/index.html (0.00s)2077 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2078 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2079 --- PASS: TestIsValidCachePath/log (0.00s)2080 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2081 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2082 --- PASS: TestIsValidCachePath/ls (0.00s)2083 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2084=== CONT TestParseSingleRange/open-ended2085=== CONT TestParseSingleRange/malformed_end_before_start2086=== CONT TestParseSingleRange/malformed_both_empty2087=== CONT TestParseSingleRange/malformed_no_dash2088=== CONT TestParseSingleRange/multi-range_ignored2089=== CONT TestParseSingleRange/unknown_unit2090=== CONT TestParseSingleRange/closed2091=== CONT TestParseSingleRange/suffix_exceeds_size2092=== CONT TestParseSingleRange/start_far_past_EOF2093=== CONT TestParseSingleRange/start_past_EOF2094=== CONT TestParseSingleRange/single_byte20952026/11/11 23:34:48 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:36219/bucket103/?delete=\": context canceled"2096--- PASS: TestParseSingleRange (0.00s)2097 --- PASS: TestParseSingleRange/none (0.00s)2098 --- PASS: TestParseSingleRange/suffix (0.00s)2099 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2100 --- PASS: TestParseSingleRange/open-ended (0.00s)2101 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2102 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2103 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2104 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2105 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2106 --- PASS: TestParseSingleRange/closed (0.00s)2107 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2108 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2109 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2110 --- PASS: TestParseSingleRange/single_byte (0.00s)2111=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale2112=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2113--- PASS: TestGCEndsOnShutdown (0.00s)2114 --- PASS: TestGCEndsOnShutdown/before_the_run (0.44s)2115 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.49s)2116 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.43s)21172026/11/11 23:34:48 WARN Request failed, retrying attempt=3 backoff=374.074977ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21182026/11/11 23:34:48 INFO lead: released remote=192.0.2.1:1234 generation=22119--- PASS: TestLeadElectsOneAndHandsOver (3.05s)21202026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures2121=== NAME TestOrphanedObjectsGC2122 orphaned_objects_gc_test.go:287: GC Test Summary:2123 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A2124 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B2125 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)2126 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)2127 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects2128--- PASS: TestOrphanedObjectsGC (0.86s)21292026/11/11 23:34:48 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21302026/11/11 23:34:48 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21312026/11/11 23:34:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21322026/11/11 23:34:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21332026/11/11 23:34:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLmVjMTBjMmVjLWYyNWUtNDE1MC04MTI2LTcxZjQzZjZkMzJmM3gxNzk0NDQwMDg4MDAyMTUzOTU3 parts=1021342026/11/11 23:34:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21352026/11/11 23:34:48 INFO Completed upload id=1 objects=3 duration=3.212158ms21362026/11/11 23:34:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLjE4Y2IwMDY5LTUxMmQtNGVkYS05NWM0LTgwN2QxNTk0ZTU0MHgxNzk0NDQwMDg4MDI3MzkzMjky parts=1021372026/11/11 23:34:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21382026/11/11 23:34:48 INFO Completed upload id=1 objects=3 duration=3.418737ms21392026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures21402026/11/11 23:34:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21412026/11/11 23:34:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21422026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures21432026/11/11 23:34:48 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21442026/11/11 23:34:48 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21452026/11/11 23:34:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLjhmMzA3MjlhLWMyZTUtNDYxOS04MWRmLWM5ODc5MzUxYzcxMngxNzk0NDQwMDg4MDg2NDA5MzA1 parts=1021462026/11/11 23:34:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021472026/11/11 23:34:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLjAwZDI0NzhlLTVjNWUtNDMyMS05YjcwLTNhZjNhMmI0NGRkMXgxNzk0NDQwMDg4MDU2MjIwOTA0 parts=1021482026/11/11 23:34:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21492026/11/11 23:34:48 INFO Received create pin request method=POST path=/api/pins/myapp21502026/11/11 23:34:48 INFO Completed upload id=1 objects=3 duration=3.400078ms21512026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures21522026/11/11 23:34:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21532026/11/11 23:34:48 INFO Completed upload id=1 objects=3 duration=3.292748ms21542026/11/11 23:34:48 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1390523923/001/store/zbscljrrlk9y3hlv0kz4nrn67bblycs6-pinned-file.txt narinfo_key=zbscljrrlk9y3hlv0kz4nrn67bblycs6.narinfo21552026/11/11 23:34:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures21562026/11/11 23:34:48 INFO Garbage collection started21572026/11/11 23:34:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21582026/11/11 23:34:48 INFO Aborted multipart uploads count=0 kept=021592026/11/11 23:34:48 WARN Force mode enabled - objects will be deleted immediately without grace period21602026/11/11 23:34:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLjdhMmZhMGM1LWZkYjMtNDdhZC04MjgzLWVjODcwNjY5YTRlYXgxNzk0NDQwMDg4MTE4NjEzNTY1 parts=1021612026/11/11 23:34:48 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=021622026/11/11 23:34:48 INFO Vacuumed table table=pending_closures21632026/11/11 23:34:48 WARN Request failed, retrying attempt=4 backoff=861.398819ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21642026/11/11 23:34:48 INFO Vacuumed table table=pending_objects21652026/11/11 23:34:48 INFO Vacuumed table table=multipart_uploads21662026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures21672026/11/11 23:34:48 INFO Vacuumed table table=closures21682026/11/11 23:34:48 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21692026/11/11 23:34:48 WARN Found objects in DB but missing from S3, will re-upload count=121702026/11/11 23:34:48 INFO Vacuumed table table=objects21712026/11/11 23:34:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21722026/11/11 23:34:48 INFO Completed upload id=1 objects=3 duration=3.998177ms21732026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures21742026/11/11 23:34:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02175=== NAME TestClientIntegration2176 client_integration_test.go:371: Objects in database after GC:2177 client_integration_test.go:371: Successfully deleted all objects with GC --force2178--- PASS: TestClientIntegration (3.22s)2179--- PASS: TestUploadHandlersRejectOversizedBody (0.30s)2180 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2181 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2182 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.72s)21832026/11/11 23:34:48 INFO lead: released remote=192.0.2.1:1234 generation=32184--- PASS: TestLeadUnannouncedStandbyYieldsToIncumbent (3.68s)2185--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2186 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.65s)2187 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.68s)21882026/11/11 23:34:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21892026/11/11 23:34:49 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLjYxNmZiNmUwLTBlZGItNGI4OS1hYTAxLTExZDk4ZmYwNjIzYngxNzk0NDQwMDg4NjQzMzQ0NjIx parts=1021902026/11/11 23:34:49 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21912026/11/11 23:34:49 INFO Completed upload id=2 objects=3 duration=1.452329ms21922026/11/11 23:34:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2193--- PASS: TestPendingClosureWriteTimeout (0.00s)2194 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2195 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2196 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2197 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.07s)21982026/11/11 23:34:49 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=YzE5MmQ3MjMtNjIzNy00ZDVlLWFhMzItMTg0YmEyZDk3NmFmLjlmMTQ5YzhkLWRlY2UtNDU3NS05MDYzLWY1YmY0MzUxZTkzNXgxNzk0NDQwMDg4NjgwMjg2NTQ4 parts=1021992026/11/11 23:34:49 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22002026/11/11 23:34:49 INFO Completed upload id=2 objects=3 duration=1.417599ms22012026/11/11 23:34:49 INFO Received uploads request method=POST path=/api/pending_closures22022026/11/11 23:34:49 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst22032026/11/11 23:34:49 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo22042026/11/11 23:34:49 INFO Received uploads request method=POST path=/api/pending_closures22052026/11/11 23:34:49 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst22062026/11/11 23:34:49 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2207--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.01s)2208 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (1.14s)2209 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (1.08s)2210 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (1.07s)2211 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.64s)2212 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.57s)22132026/11/11 23:34:49 WARN Request failed, retrying attempt=5 backoff=1.650988956s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2214=== NAME TestOrphanedObjectsGCStressTest2215 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2216 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2217--- PASS: TestConnectWaitsForAPeerMigration (5.15s)2218=== NAME TestPinProtectsFromGC2219 client_integration_test.go:888: Pin successfully protected closure from garbage collection2220--- PASS: TestPinProtectsFromGC (5.17s)2221=== NAME TestOrphanedObjectsGCStressTest2222 orphaned_objects_gc_test.go:503: Stress test completed successfully:2223 orphaned_objects_gc_test.go:504: - Active objects preserved: 202224 orphaned_objects_gc_test.go:505: - Objects deleted: 2102225 orphaned_objects_gc_test.go:506: - Total GC'd: 2102226--- PASS: TestOrphanedObjectsGCStressTest (3.78s)22272026/11/11 23:34:51 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-config22282026/11/11 23:34:51 WARN Rate limiter enabled after throttle name=s3-test rate=522292026/11/11 23:34:51 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2230=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2231 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102232 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002233--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.82s)22342026/11/11 23:34:51 WARN Request failed, retrying attempt=2 backoff=211.207567ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22352026/11/11 23:34:51 WARN Request failed, retrying attempt=3 backoff=386.649186ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2236--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.68s)22372026/11/11 23:34:51 WARN Request failed, retrying attempt=4 backoff=832.74992ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22382026/11/11 23:34:52 WARN Request failed, retrying attempt=5 backoff=1.743343154s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22392026/11/11 23:34:53 INFO Aborted multipart uploads count=1 kept=022402026/11/11 23:34:53 INFO Received cleanup request method=DELETE path=/api/pending_closures22412026/11/11 23:34:53 INFO Aborted multipart uploads count=1 kept=02242--- PASS: TestPendingCleanupUsesOneCutoff (6.52s)22432026/11/11 23:34:54 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"22442026/11/11 23:34:54 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-config22452026/11/11 23:34:54 WARN Request failed, retrying attempt=2 backoff=205.475227ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22462026/11/11 23:34:54 WARN Request failed, retrying attempt=3 backoff=405.950767ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22472026/11/11 23:34:55 WARN Request failed, retrying attempt=4 backoff=826.885159ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22482026/11/11 23:34:56 WARN Request failed, retrying attempt=5 backoff=1.585987831s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22492026/11/11 23:34:57 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_closures22502026/11/11 23:34:57 WARN Request failed, retrying attempt=2 backoff=192.944878ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22512026/11/11 23:34:57 WARN Request failed, retrying attempt=3 backoff=398.912463ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22522026/11/11 23:34:58 WARN Request failed, retrying attempt=4 backoff=807.075157ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22532026/11/11 23:34:59 WARN Request failed, retrying attempt=5 backoff=1.534203346s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2254--- PASS: TestClientErrorHandling (0.00s)2255 --- PASS: TestClientErrorHandling/InvalidStorePath (0.44s)2256 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.38s)2257 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.78s)2258PASS2259{"timestamp":"2026-11-11T23:35:00.742663714Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:47190","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(398)"}22602026-11-11 23:35:01.058 UTC [129] LOG: received smart shutdown request22612026-11-11 23:35:01.062 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122622026-11-11 23:35:01.068 UTC [134] LOG: shutting down22632026-11-11 23:35:01.069 UTC [134] LOG: checkpoint starting: shutdown immediate22642026-11-11 23:35:03.028 UTC [134] LOG: checkpoint complete: wrote 10870 buffers (66.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.229 s, sync=1.665 s, total=1.960 s; sync files=36842, longest=0.002 s, average=0.001 s; distance=530977 kB, estimate=530977 kB; lsn=0/21DEE1F0, redo lsn=0/21DEE1F022652026-11-11 23:35:03.109 UTC [129] LOG: database system is shut down2266Running OIDC tests...2267=== RUN TestAudienceForIssuer2268=== PAUSE TestAudienceForIssuer2269=== RUN TestGlobMatch2270=== PAUSE TestGlobMatch2271=== RUN TestValidateToken_ValidToken2272=== PAUSE TestValidateToken_ValidToken2273=== RUN TestValidateToken_WrongAudience2274=== PAUSE TestValidateToken_WrongAudience2275=== RUN TestValidateToken_Expired2276=== PAUSE TestValidateToken_Expired2277=== RUN TestValidateToken_BoundClaimsMismatch2278=== PAUSE TestValidateToken_BoundClaimsMismatch2279=== RUN TestValidateToken_BoundSubjectMismatch2280=== PAUSE TestValidateToken_BoundSubjectMismatch2281=== RUN TestValidateToken_MultipleProviders2282=== PAUSE TestValidateToken_MultipleProviders2283=== RUN TestValidateToken_NoMatchingProvider2284=== PAUSE TestValidateToken_NoMatchingProvider2285=== RUN TestValidateToken_KubernetesServiceAccount2286=== PAUSE TestValidateToken_KubernetesServiceAccount2287=== RUN TestNewValidator_KubernetesRequiresCA2288=== PAUSE TestNewValidator_KubernetesRequiresCA2289=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2290=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2291=== RUN TestPins_ReservedForMatchingRule2292=== PAUSE TestPins_ReservedForMatchingRule2293=== RUN TestPins_TopLevelShorthand2294=== PAUSE TestPins_TopLevelShorthand2295=== RUN TestPins_ConfigValidation2296=== PAUSE TestPins_ConfigValidation2297=== RUN TestScopes_LegacyProviderDefaultsToWrite2298=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2299=== RUN TestScopes_Rules2300=== PAUSE TestScopes_Rules2301=== RUN TestScopes_ConfigValidation2302=== PAUSE TestScopes_ConfigValidation2303=== CONT TestAudienceForIssuer2304=== CONT TestPins_ConfigValidation2305=== CONT TestValidateToken_BoundClaimsMismatch2306--- PASS: TestAudienceForIssuer (0.00s)2307=== CONT TestValidateToken_Expired2308=== CONT TestValidateToken_KubernetesServiceAccount2309=== CONT TestValidateToken_WrongAudience2310--- PASS: TestPins_ConfigValidation (0.00s)2311=== CONT TestValidateToken_ValidToken2312=== CONT TestPins_TopLevelShorthand2313=== CONT TestPins_ReservedForMatchingRule2314=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2315=== CONT TestGlobMatch2316=== RUN TestGlobMatch/foo_foo2317=== PAUSE TestGlobMatch/foo_foo2318=== CONT TestScopes_Rules2319=== CONT TestNewValidator_KubernetesRequiresCA2320=== CONT TestScopes_ConfigValidation2321=== CONT TestValidateToken_MultipleProviders2322=== CONT TestScopes_LegacyProviderDefaultsToWrite2323=== CONT TestValidateToken_NoMatchingProvider2324=== CONT TestValidateToken_BoundSubjectMismatch2325=== RUN TestGlobMatch/foo_bar2326=== PAUSE TestGlobMatch/foo_bar2327=== RUN TestGlobMatch/*_2328=== PAUSE TestGlobMatch/*_2329=== RUN TestGlobMatch/*_anything2330=== PAUSE TestGlobMatch/*_anything2331=== RUN TestGlobMatch/foo*_foo2332=== PAUSE TestGlobMatch/foo*_foo2333=== RUN TestGlobMatch/foo*_foobar2334=== PAUSE TestGlobMatch/foo*_foobar2335=== RUN TestGlobMatch/foo*_bar2336=== PAUSE TestGlobMatch/foo*_bar2337=== RUN TestGlobMatch/*bar_bar2338=== PAUSE TestGlobMatch/*bar_bar2339=== RUN TestGlobMatch/*bar_foobar2340=== PAUSE TestGlobMatch/*bar_foobar2341=== RUN TestGlobMatch/*bar_foo2342=== PAUSE TestGlobMatch/*bar_foo2343=== RUN TestGlobMatch/foo*bar_foobar2344=== PAUSE TestGlobMatch/foo*bar_foobar2345=== RUN TestGlobMatch/foo*bar_foo123bar2346=== PAUSE TestGlobMatch/foo*bar_foo123bar2347=== RUN TestGlobMatch/foo*bar_foobarbaz2348=== PAUSE TestGlobMatch/foo*bar_foobarbaz2349=== RUN TestGlobMatch/*/*_foo/bar2350=== PAUSE TestGlobMatch/*/*_foo/bar2351=== RUN TestGlobMatch/*/*_foo2352=== PAUSE TestGlobMatch/*/*_foo2353=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2354=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2355=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02356=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02357=== RUN TestGlobMatch/refs/*/main_refs/heads/main2358=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2359=== RUN TestGlobMatch/fo?_foo2360=== PAUSE TestGlobMatch/fo?_foo2361=== RUN TestGlobMatch/fo?_fo2362=== PAUSE TestGlobMatch/fo?_fo2363=== RUN TestGlobMatch/fo?_fooo2364=== PAUSE TestGlobMatch/fo?_fooo2365=== RUN TestGlobMatch/?oo_foo2366=== PAUSE TestGlobMatch/?oo_foo2367=== RUN TestGlobMatch/?oo_boo2368=== PAUSE TestGlobMatch/?oo_boo2369=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2370=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2371=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2372=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2373=== CONT TestGlobMatch/foo_foo2374=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2375=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2376=== CONT TestGlobMatch/?oo_boo2377=== CONT TestGlobMatch/?oo_foo2378=== CONT TestGlobMatch/fo?_fooo2379=== CONT TestGlobMatch/fo?_fo2380=== CONT TestGlobMatch/fo?_foo2381=== CONT TestGlobMatch/refs/*/main_refs/heads/main2382=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02383=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2384=== CONT TestGlobMatch/*/*_foo2385=== CONT TestGlobMatch/*/*_foo/bar2386=== CONT TestGlobMatch/foo*bar_foobarbaz2387=== CONT TestGlobMatch/foo*bar_foo123bar2388=== CONT TestGlobMatch/foo*bar_foobar2389=== CONT TestGlobMatch/*bar_foo2390=== CONT TestGlobMatch/*bar_foobar2391=== CONT TestGlobMatch/*bar_bar2392=== CONT TestGlobMatch/foo*_bar2393=== CONT TestGlobMatch/foo*_foobar2394=== CONT TestGlobMatch/foo*_foo2395=== CONT TestGlobMatch/*_anything2396=== CONT TestGlobMatch/*_2397=== CONT TestGlobMatch/foo_bar2398--- PASS: TestGlobMatch (0.00s)2399 --- PASS: TestGlobMatch/foo_foo (0.00s)2400 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2401 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2402 --- PASS: TestGlobMatch/?oo_boo (0.00s)2403 --- PASS: TestGlobMatch/?oo_foo (0.00s)2404 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2405 --- PASS: TestGlobMatch/fo?_fo (0.00s)2406 --- PASS: TestGlobMatch/fo?_foo (0.00s)2407 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2408 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2409 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2410 --- PASS: TestGlobMatch/*/*_foo (0.00s)2411 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2412 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2413 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2414 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2415 --- PASS: TestGlobMatch/*bar_foo (0.00s)2416 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2417 --- PASS: TestGlobMatch/*bar_bar (0.00s)2418 --- PASS: TestGlobMatch/foo*_bar (0.00s)2419 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2420 --- PASS: TestGlobMatch/foo*_foo (0.00s)2421 --- PASS: TestGlobMatch/*_anything (0.00s)2422 --- PASS: TestGlobMatch/*_ (0.00s)2423 --- PASS: TestGlobMatch/foo_bar (0.00s)2424--- PASS: TestScopes_ConfigValidation (0.00s)24252026/11/11 23:35:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41009/oidc2426--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)24272026/11/11 23:35:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39029/oidc2428--- PASS: TestValidateToken_WrongAudience (0.03s)24292026/11/11 23:35:05 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:396472430--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)24312026/11/11 23:35:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41091/oidc24322026/11/11 23:35:05 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232433--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)2434--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)24352026/11/11 23:35:05 http: TLS handshake error from 127.0.0.1:55892: remote error: tls: bad certificate2436--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)24372026/11/11 23:35:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32841/oidc24382026/11/11 23:35:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35137/oidc2439--- PASS: TestValidateToken_Expired (0.07s)2440--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)24412026/11/11 23:35:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43719/oidc2442--- PASS: TestValidateToken_ValidToken (0.09s)24432026/11/11 23:35:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33451/oidc2444--- PASS: TestValidateToken_NoMatchingProvider (0.09s)24452026/11/11 23:35:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41691/oidc24462026/11/11 23:35:05 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:39155/oidc2447--- PASS: TestValidateToken_MultipleProviders (0.10s)24482026/11/11 23:35:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43499/oidc2449--- PASS: TestPins_ReservedForMatchingRule (0.11s)24502026/11/11 23:35:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38135/oidc24512026/11/11 23:35:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44111/oidc2452--- PASS: TestPins_TopLevelShorthand (0.12s)2453--- PASS: TestScopes_Rules (0.12s)2454PASS2455Running hook tests...2456=== RUN TestSendPathsEmpty2457=== PAUSE TestSendPathsEmpty2458=== RUN TestQueueEnqueueAndFetch2459=== PAUSE TestQueueEnqueueAndFetch2460=== RUN TestQueueDeduplication2461=== PAUSE TestQueueDeduplication2462=== RUN TestQueueRemove2463=== PAUSE TestQueueRemove2464=== RUN TestQueueFetchBatchLimit2465=== PAUSE TestQueueFetchBatchLimit2466=== RUN TestQueueRetryMovesToBack2467=== PAUSE TestQueueRetryMovesToBack2468=== RUN TestQueueFetchRemoveLifecycle2469=== PAUSE TestQueueFetchRemoveLifecycle2470=== RUN TestQueueConcurrentWriters2471=== PAUSE TestQueueConcurrentWriters2472=== RUN TestQueueRemoveLargeClosure2473=== PAUSE TestQueueRemoveLargeClosure2474=== RUN TestServerClientIntegration2475--- PASS: TestServerClientIntegration (0.00s)2476=== RUN TestServerQueueError24772026/11/11 23:35:05 ERROR Failed to queue paths error="permission denied" count=12478--- PASS: TestServerQueueError (0.00s)2479=== RUN TestGetListenerSocketActivation2480 server_test.go:220: === RUN TestGetListenerSocketActivation2481 --- PASS: TestGetListenerSocketActivation (0.00s)2482 PASS2483 2484--- PASS: TestGetListenerSocketActivation (0.01s)2485=== RUN TestServerStalledClientDoesNotBlockShutdown2486=== PAUSE TestServerStalledClientDoesNotBlockShutdown2487=== RUN TestServerBacksOffOnAcceptErrors2488=== PAUSE TestServerBacksOffOnAcceptErrors2489=== RUN TestDrainIsolatesPoisonPath2490=== PAUSE TestDrainIsolatesPoisonPath2491=== RUN TestRunNotBlockedByPoisonHead2492=== PAUSE TestRunNotBlockedByPoisonHead2493=== RUN TestDrainGivesUpWhenServerDown2494=== PAUSE TestDrainGivesUpWhenServerDown2495=== RUN TestFailedPathPrunedByLaterClosure2496=== PAUSE TestFailedPathPrunedByLaterClosure2497=== RUN TestWorkerUploadsAndRemoves2498=== PAUSE TestWorkerUploadsAndRemoves2499=== RUN TestWorkerSkipsGCdPaths2500=== PAUSE TestWorkerSkipsGCdPaths2501=== RUN TestWorkerPrunesClosureDeps2502=== PAUSE TestWorkerPrunesClosureDeps2503=== RUN TestDrainTimeout2504=== PAUSE TestDrainTimeout2505=== RUN TestWorkerRemoveFailureIsNotProgress2506=== PAUSE TestWorkerRemoveFailureIsNotProgress2507=== RUN TestWorkerKeepsPathItCannotStat2508=== PAUSE TestWorkerKeepsPathItCannotStat2509=== CONT TestSendPathsEmpty2510--- PASS: TestSendPathsEmpty (0.00s)2511=== CONT TestWorkerSkipsGCdPaths2512=== CONT TestDrainIsolatesPoisonPath2513=== CONT TestQueueFetchRemoveLifecycle2514=== CONT TestWorkerKeepsPathItCannotStat2515=== CONT TestServerBacksOffOnAcceptErrors2516=== CONT TestWorkerRemoveFailureIsNotProgress25172000/01/01 00:00:00 ERROR Accept failed error="too many open files"25182000/01/01 00:00:00 ERROR Accept failed error="too many open files"25192000/01/01 00:00:00 ERROR Accept failed error="too many open files"25202000/01/01 00:00:00 ERROR Accept failed error="too many open files"2521=== CONT TestServerStalledClientDoesNotBlockShutdown25222000/01/01 00:00:00 ERROR Accept failed error="too many open files"25232000/01/01 00:00:00 ERROR Accept failed error="too many open files"25242000/01/01 00:00:00 ERROR Accept failed error="too many open files"25252000/01/01 00:00:00 ERROR Accept failed error="too many open files"2526--- PASS: TestServerBacksOffOnAcceptErrors (0.00s)2527=== CONT TestDrainTimeout2528=== CONT TestQueueRemoveLargeClosure2529=== CONT TestWorkerPrunesClosureDeps2530=== CONT TestQueueRetryMovesToBack2531=== CONT TestQueueConcurrentWriters2532=== CONT TestQueueFetchBatchLimit2533=== CONT TestQueueRemove2534=== CONT TestQueueDeduplication2535=== CONT TestFailedPathPrunedByLaterClosure2536=== CONT TestDrainGivesUpWhenServerDown2537=== CONT TestQueueEnqueueAndFetch2538=== CONT TestWorkerUploadsAndRemoves2539=== CONT TestRunNotBlockedByPoisonHead25402026/11/11 23:35:05 INFO Upload queue status pending=325412026/11/11 23:35:05 INFO Uploading batch count=125422026/11/11 23:35:05 INFO Upload queue status pending=225432026/11/11 23:35:05 ERROR Upload failed error="upload failed" count=125442026/11/11 23:35:05 INFO Uploading batch count=425452026/11/11 23:35:05 ERROR Upload failed error="upload failed" count=425462026/11/11 23:35:05 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2280902629/002/nonexistent25472026/11/11 23:35:05 INFO Upload queue status pending=225482026/11/11 23:35:05 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3922796779/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3922796779/002/locked/aaa: permission denied"2549--- PASS: TestQueueFetchBatchLimit (0.02s)25502026/11/11 23:35:05 INFO Uploading batch count=225512026/11/11 23:35:05 INFO Uploading batch count=225522026/11/11 23:35:05 ERROR Upload failed error="upload failed" count=225532026/11/11 23:35:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1774007222/002/a25542000/01/01 00:00:00 INFO Uploading batch count=22555--- PASS: TestQueueEnqueueAndFetch (0.01s)25562000/01/01 00:00:00 ERROR Upload failed error="context deadline exceeded" count=225572000/01/01 00:00:00 ERROR Drain finished with paths left in queue remaining=425582026/11/11 23:35:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2158583304/002/bbb25592026/11/11 23:35:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1774007222/002/b25602026/11/11 23:35:05 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1612547899/002/nonexistent25612026/11/11 23:35:05 INFO Uploading batch count=12562--- PASS: TestQueueDeduplication (0.02s)25632026/11/11 23:35:05 INFO Uploading batch count=12564--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25652026/11/11 23:35:05 ERROR Upload failed error="upload failed" count=125662026/11/11 23:35:05 INFO Upload queue status pending=225672026/11/11 23:35:05 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125682026/11/11 23:35:05 INFO Uploading batch count=125692026/11/11 23:35:05 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1612547899/002/nonexistent25702026/11/11 23:35:05 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125712026/11/11 23:35:05 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1612547899/002/nonexistent25722026/11/11 23:35:05 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3922796779/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3922796779/002/locked/aaa: permission denied"2573--- PASS: TestQueueRemove (0.02s)25742026/11/11 23:35:05 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125752026/11/11 23:35:05 ERROR Drain finished with paths left in queue remaining=125762026/11/11 23:35:05 INFO Uploading batch count=225772026/11/11 23:35:05 ERROR Upload failed error="upload failed" count=225782026/11/11 23:35:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1774007222/002/c2579--- PASS: TestQueueRetryMovesToBack (0.02s)25802026/11/11 23:35:05 INFO Uploading batch count=125812026/11/11 23:35:05 INFO Uploading batch count=125822026/11/11 23:35:05 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3922796779/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat3922796779/002/locked/aaa: permission denied"2583--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)25842026/11/11 23:35:05 ERROR Upload failed error="upload failed" count=125852026/11/11 23:35:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1774007222/002/d2586--- PASS: TestDrainTimeout (0.02s)25872026/11/11 23:35:05 ERROR Drain finished with paths left in queue remaining=125882026/11/11 23:35:05 INFO Uploading batch count=125892026/11/11 23:35:05 INFO Uploading batch count=125902026/11/11 23:35:05 ERROR Upload failed error="upload failed" count=125912026/11/11 23:35:05 INFO Uploading batch count=225922026/11/11 23:35:05 ERROR Upload failed error="upload failed" count=225932026/11/11 23:35:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1774007222/002/e25942026/11/11 23:35:05 INFO Uploading batch count=125952026/11/11 23:35:05 ERROR Upload failed error="upload failed" count=125962026/11/11 23:35:05 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1774007222/002/f2597--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)25982026/11/11 23:35:05 ERROR Drain finished with paths left in queue remaining=125992026/11/11 23:35:05 ERROR Drain finished with paths left in queue remaining=102600--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2601--- PASS: TestDrainIsolatesPoisonPath (0.03s)2602--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2603--- PASS: TestWorkerSkipsGCdPaths (0.04s)2604--- PASS: TestWorkerUploadsAndRemoves (0.03s)2605--- PASS: TestWorkerPrunesClosureDeps (0.04s)2606--- PASS: TestQueueRemoveLargeClosure (0.05s)26072026/11/11 23:35:05 ERROR Failed to decode request error="read unix /build/hook815138776/test.sock->@: i/o timeout"26082026/11/11 23:35:05 ERROR Failed to write response error="write unix /build/hook815138776/test.sock->@: i/o timeout"2609--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)2610--- PASS: TestQueueConcurrentWriters (0.20s)26112026/11/11 23:35:06 INFO Uploading batch count=126122026/11/11 23:35:06 INFO Uploading batch count=126132026/11/11 23:35:06 INFO Uploading batch count=126142026/11/11 23:35:06 ERROR Upload failed error="upload failed" count=126152026/11/11 23:35:06 INFO Uploading batch count=126162026/11/11 23:35:06 ERROR Upload failed error="upload failed" count=126172026/11/11 23:35:06 INFO Uploading batch count=126182026/11/11 23:35:06 ERROR Upload failed error="upload failed" count=126192026/11/11 23:35:06 INFO Uploading batch count=126202026/11/11 23:35:06 ERROR Upload failed error="upload failed" count=126212026/11/11 23:35:06 ERROR Drain finished with paths left in queue remaining=12622--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2623PASS2624Running signing tests...2625=== RUN TestExternalSigner2626=== PAUSE TestExternalSigner2627=== RUN TestExternalSignerWrongPublicKey2628=== PAUSE TestExternalSignerWrongPublicKey2629=== RUN TestExternalSignerErrors2630=== PAUSE TestExternalSignerErrors2631=== RUN TestExternalSignerRestartsAfterCrash2632=== PAUSE TestExternalSignerRestartsAfterCrash2633=== RUN TestExternalSignerProgramErrorKeepsProcess2634=== PAUSE TestExternalSignerProgramErrorKeepsProcess2635=== RUN TestExternalSignerClose2636=== PAUSE TestExternalSignerClose2637=== RUN TestExternalSignerRejectsInvalidPublicKey2638=== PAUSE TestExternalSignerRejectsInvalidPublicKey2639=== RUN TestExternalSignerCancellation2640=== PAUSE TestExternalSignerCancellation2641=== RUN TestGenerateFingerprint2642=== PAUSE TestGenerateFingerprint2643=== RUN TestParseSigningKey2644=== PAUSE TestParseSigningKey2645=== RUN TestSign2646=== PAUSE TestSign2647=== RUN TestSignBatch2648=== PAUSE TestSignBatch2649=== RUN TestNilKeyPublicKey2650=== PAUSE TestNilKeyPublicKey2651=== RUN TestSignErrors2652=== PAUSE TestSignErrors2653=== CONT TestExternalSigner2654=== CONT TestExternalSignerCancellation2655=== CONT TestExternalSignerProgramErrorKeepsProcess2656=== CONT TestExternalSignerErrors2657=== CONT TestExternalSignerRestartsAfterCrash2658=== CONT TestSign2659=== CONT TestNilKeyPublicKey2660=== CONT TestSignBatch2661=== CONT TestSignErrors2662=== CONT TestParseSigningKey2663=== RUN TestParseSigningKey/valid_32-byte_key2664=== CONT TestExternalSignerWrongPublicKey2665=== CONT TestGenerateFingerprint2666=== RUN TestGenerateFingerprint/basic_with_references2667=== PAUSE TestGenerateFingerprint/basic_with_references2668=== CONT TestExternalSignerRejectsInvalidPublicKey2669=== CONT TestExternalSignerClose2670=== RUN TestExternalSignerErrors/wrong_shape2671--- PASS: TestNilKeyPublicKey (0.00s)2672=== RUN TestGenerateFingerprint/no_references2673=== PAUSE TestExternalSignerErrors/wrong_shape2674--- PASS: TestSign (0.00s)2675--- PASS: TestSignBatch (0.00s)2676=== PAUSE TestGenerateFingerprint/no_references2677=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2678=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2679=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2680=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2681=== RUN TestSignErrors/nil_key2682=== PAUSE TestSignErrors/nil_key2683=== RUN TestSignErrors/nil_narinfo2684=== PAUSE TestSignErrors/nil_narinfo2685=== RUN TestSignErrors/invalid_narinfo2686=== PAUSE TestSignErrors/invalid_narinfo2687=== RUN TestSignErrors/canceled2688=== PAUSE TestSignErrors/canceled2689=== CONT TestSignErrors/nil_key2690=== CONT TestSignErrors/invalid_narinfo2691=== RUN TestExternalSignerRejectsInvalidPublicKey/#002692=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002693=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2694=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2695=== CONT TestSignErrors/canceled2696=== PAUSE TestParseSigningKey/valid_32-byte_key2697=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2698=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2699=== RUN TestParseSigningKey/no_colon2700=== PAUSE TestParseSigningKey/no_colon2701=== RUN TestParseSigningKey/empty_name2702=== PAUSE TestParseSigningKey/empty_name2703=== RUN TestParseSigningKey/invalid_base642704=== PAUSE TestParseSigningKey/invalid_base642705=== RUN TestParseSigningKey/wrong_length2706=== PAUSE TestParseSigningKey/wrong_length2707=== CONT TestParseSigningKey/valid_32-byte_key2708=== CONT TestParseSigningKey/wrong_length2709=== RUN TestExternalSignerErrors/wrong_signatures_shape2710=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2711=== RUN TestExternalSignerErrors/unrequested_key2712=== PAUSE TestExternalSignerErrors/unrequested_key2713=== CONT TestParseSigningKey/invalid_base642714=== RUN TestGenerateFingerprint/invalid_nar_hash_length2715=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2716=== CONT TestSignErrors/nil_narinfo2717--- PASS: TestSignErrors (0.00s)2718 --- PASS: TestSignErrors/nil_key (0.00s)2719 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2720 --- PASS: TestSignErrors/canceled (0.00s)2721 --- PASS: TestSignErrors/nil_narinfo (0.00s)2722=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2723=== CONT TestParseSigningKey/no_colon2724=== CONT TestParseSigningKey/empty_name2725=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2726--- PASS: TestParseSigningKey (0.00s)2727 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2728 --- PASS: TestParseSigningKey/wrong_length (0.00s)2729 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2730 --- PASS: TestParseSigningKey/no_colon (0.00s)2731 --- PASS: TestParseSigningKey/empty_name (0.00s)2732 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2733=== RUN TestExternalSignerErrors/exit_on_request2734=== PAUSE TestExternalSignerErrors/exit_on_request2735=== RUN TestExternalSignerErrors/invalid_JSON2736=== PAUSE TestExternalSignerErrors/invalid_JSON2737=== RUN TestGenerateFingerprint/invalid_store_path_prefix2738=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2739=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2740=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2741=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2742=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2743=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2744=== CONT TestExternalSignerRejectsInvalidPublicKey/#002745=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2746=== RUN TestExternalSignerErrors/null_signatures2747=== PAUSE TestExternalSignerErrors/null_signatures2748=== RUN TestExternalSignerErrors/too_few_signatures2749=== PAUSE TestExternalSignerErrors/too_few_signatures2750=== RUN TestExternalSignerErrors/exit_at_startup2751=== PAUSE TestExternalSignerErrors/exit_at_startup2752=== RUN TestExternalSignerErrors/null2753=== PAUSE TestExternalSignerErrors/null2754=== RUN TestExternalSignerErrors/wrong_id2755=== PAUSE TestExternalSignerErrors/wrong_id2756=== RUN TestExternalSignerErrors/missing_signatures2757=== PAUSE TestExternalSignerErrors/missing_signatures2758=== RUN TestExternalSignerErrors/wrong_signature_name2759=== PAUSE TestExternalSignerErrors/wrong_signature_name2760=== RUN TestExternalSignerErrors/wrong_signature_length2761=== PAUSE TestExternalSignerErrors/wrong_signature_length2762=== RUN TestExternalSignerErrors/program_error2763=== PAUSE TestExternalSignerErrors/program_error2764=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2765=== RUN TestGenerateFingerprint/invalid_reference_prefix2766=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2767=== CONT TestGenerateFingerprint/basic_with_references2768=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2769--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2770=== CONT TestGenerateFingerprint/invalid_store_path_prefix2771=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2772--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2773 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2774 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2775 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2776 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2777 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2778=== RUN TestExternalSignerErrors/missing_signature_name2779=== PAUSE TestExternalSignerErrors/missing_signature_name2780=== CONT TestGenerateFingerprint/invalid_nar_hash_length2781=== CONT TestGenerateFingerprint/invalid_reference_prefix2782=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2783=== CONT TestGenerateFingerprint/no_references2784=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2785--- PASS: TestGenerateFingerprint (0.00s)2786 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2787 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2788 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2789 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2790 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2791 --- PASS: TestGenerateFingerprint/no_references (0.00s)2792 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2793=== RUN TestExternalSignerErrors/invalid_signature_base642794=== PAUSE TestExternalSignerErrors/invalid_signature_base642795=== CONT TestExternalSignerErrors/wrong_shape2796=== CONT TestExternalSignerErrors/null_signatures2797=== CONT TestExternalSignerErrors/program_error2798=== CONT TestExternalSignerErrors/invalid_signature_base642799=== CONT TestExternalSignerErrors/missing_signature_name2800=== CONT TestExternalSignerErrors/wrong_signature_name2801=== CONT TestExternalSignerErrors/wrong_signature_length2802=== CONT TestExternalSignerErrors/wrong_id2803=== CONT TestExternalSignerErrors/null2804=== CONT TestExternalSignerErrors/exit_at_startup2805=== CONT TestExternalSignerErrors/exit_on_request2806=== CONT TestExternalSignerErrors/unrequested_key2807=== CONT TestExternalSignerErrors/wrong_signatures_shape2808=== CONT TestExternalSignerErrors/invalid_JSON2809=== CONT TestExternalSignerErrors/too_few_signatures2810=== CONT TestExternalSignerErrors/missing_signatures2811--- PASS: TestExternalSignerWrongPublicKey (0.00s)2812--- PASS: TestExternalSignerClose (0.00s)2813--- PASS: TestExternalSigner (0.01s)2814--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2815--- PASS: TestExternalSignerErrors (0.00s)2816 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2817 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2818 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2819 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2820 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2821 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2822 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2823 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2824 --- PASS: TestExternalSignerErrors/program_error (0.01s)2825 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2826 --- PASS: TestExternalSignerErrors/null (0.01s)2827 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2828 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2829 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2830 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2831 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2832--- PASS: TestExternalSignerCancellation (0.02s)2833PASS2834Running OpenBao signer tests...2835=== RUN TestSign2836=== PAUSE TestSign2837=== RUN TestSignErrors2838=== PAUSE TestSignErrors2839=== RUN TestServe2840=== PAUSE TestServe2841=== RUN TestServeRejectsGarbage2842=== PAUSE TestServeRejectsGarbage2843=== CONT TestSign2844=== CONT TestServe2845=== CONT TestSignErrors2846=== CONT TestServeRejectsGarbage2847=== RUN TestSignErrors/invalid_base642848=== PAUSE TestSignErrors/invalid_base642849--- PASS: TestServeRejectsGarbage (0.00s)2850=== RUN TestSignErrors/http_error2851=== PAUSE TestSignErrors/http_error2852--- PASS: TestServe (0.00s)2853=== RUN TestSignErrors/invalid_json2854=== PAUSE TestSignErrors/invalid_json2855=== RUN TestSignErrors/no_prefix2856=== PAUSE TestSignErrors/no_prefix2857=== CONT TestSignErrors/invalid_base642858=== CONT TestSignErrors/invalid_json2859=== CONT TestSignErrors/no_prefix2860=== CONT TestSignErrors/http_error2861--- PASS: TestSign (0.00s)2862--- PASS: TestSignErrors (0.00s)2863 --- PASS: TestSignErrors/invalid_base64 (0.00s)2864 --- PASS: TestSignErrors/invalid_json (0.00s)2865 --- PASS: TestSignErrors/no_prefix (0.00s)2866 --- PASS: TestSignErrors/http_error (0.00s)2867PASS