niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #471
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_ReturnsAfterDroppedBody20=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.07s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestCaseHackPathIsRefusedWithoutStrip28--- PASS: TestCaseHackPathIsRefusedWithoutStrip (0.00s)29=== RUN TestDumpPathMatchesNix30=== PAUSE TestDumpPathMatchesNix31=== RUN TestDumpPathSingleFile32=== PAUSE TestDumpPathSingleFile33=== RUN TestDumpPathWriterError34=== PAUSE TestDumpPathWriterError35=== RUN TestEncodeNixBase3236=== PAUSE TestEncodeNixBase3237=== RUN TestEncodeNixBase32WithRealHash38=== PAUSE TestEncodeNixBase32WithRealHash39=== RUN TestConvertHashToNix3240=== PAUSE TestConvertHashToNix3241=== RUN TestGetStorePathHash42=== PAUSE TestGetStorePathHash43=== RUN TestPathInfoHashCompatibility44=== PAUSE TestPathInfoHashCompatibility45=== RUN TestParsePathInfoJSON46=== PAUSE TestParsePathInfoJSON47=== RUN TestParsePathInfoJSONMultiplePaths48=== PAUSE TestParsePathInfoJSONMultiplePaths49=== RUN TestPathInfoCACompatibility50=== PAUSE TestPathInfoCACompatibility51=== RUN TestRateLimiterFeedback52=== PAUSE TestRateLimiterFeedback53=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess54=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess55=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer56=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer57=== RUN TestRegisterUploadedObject_OutlivesPush58=== PAUSE TestRegisterUploadedObject_OutlivesPush59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestScriptTokenScriptFails117=== CONT TestScriptTokenEmptyCommand118--- PASS: TestScriptTokenEmptyCommand (0.00s)119=== CONT TestStreamPushReportsSkippedPaths120=== CONT TestStreamPushStopsWhenCanceled121=== CONT TestScriptTokenBadJSON122=== CONT TestScriptTokenEmptyToken123=== CONT TestStreamPushGivesUpOnDeadServer124=== CONT TestScriptTokenCachesUntilRefresh125=== CONT TestEncodeNixBase32126=== CONT TestScriptTokenNoExpiryRerunsEveryCall127=== CONT TestFileTokenEmpty1282026/11/09 11:52:34 ERROR Upload failed error="connection refused" count=201292026/11/09 11:52:34 ERROR Server seems unavailable, giving up on batch untried=17130=== CONT TestFileTokenMissing131=== CONT TestFileTokenReadsAndCaches132=== CONT TestResolveStorePath133=== CONT TestUploadMultipart_PartsInParallel134=== CONT TestRegisterUploadedObject_OutlivesPush135=== CONT TestDumpPathWriterError136=== CONT TestStaticToken137=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer138=== CONT TestDumpPathSingleFile139=== CONT TestSetClientTLSErrors140=== CONT TestStreamPushBatchesUnderLoad141=== CONT TestSetClientTLSDoesNotMutateDefaultTransport142=== CONT TestStreamPushReportsEveryPath143=== CONT TestSetClientTLS144=== CONT TestShellSplitErrors145=== CONT TestShellSplit146=== CONT TestStreamPushReportsSignatures147=== CONT TestDoWithRetry_FinalResponseBodyReadable148=== CONT TestClientSignaturesByStorePath149=== CONT TestRetryTimeoutOutlastsMaxRetries150--- PASS: TestStreamPushStopsWhenCanceled (0.00s)151--- PASS: TestStreamPushReportsSkippedPaths (0.00s)152=== CONT TestStreamPushRequestLine153=== RUN TestEncodeNixBase32/test_string_hash154=== CONT TestDoWithRetry_BodyReplayedViaGetBody155--- PASS: TestScriptTokenScriptFails (0.00s)156--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)157--- PASS: TestFileTokenMissing (0.00s)158--- PASS: TestFileTokenEmpty (0.00s)159--- PASS: TestFileTokenReadsAndCaches (0.00s)160--- PASS: TestDoServerRequestAttachesToken (0.01s)161--- PASS: TestStaticToken (0.00s)162--- PASS: TestResolveStorePath (0.00s)163=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess164=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false165--- PASS: TestShellSplitErrors (0.00s)166=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false167=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true168=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true169=== CONT TestRateLimiterFeedback170=== CONT TestDumpPathMatchesNix1712026/11/09 11:52:34 WARN Rate limiter enabled after throttle name=server-test rate=5172--- PASS: TestStreamPushReportsEveryPath (0.00s)173=== CONT TestPartSizeForNAR174=== RUN TestPartSizeForNAR/zero_stays_at_minimum1752026/11/09 11:52:34 ERROR Upload failed error=boom count=1176--- PASS: TestStreamPushReportsSignatures (0.00s)177=== CONT TestPathInfoCACompatibility178=== RUN TestPathInfoCACompatibility/null_ca_field179--- PASS: TestShellSplit (0.00s)180=== CONT TestUploadMultipart_ReturnsAfterDroppedBody181--- PASS: TestRegisterUploadedObject_OutlivesPush (0.03s)182--- PASS: TestClientSignaturesByStorePath (0.00s)183=== CONT TestParsePathInfoJSONMultiplePaths184=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths185=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths186=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths187=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths188=== CONT TestParsePathInfoJSON189=== RUN TestParsePathInfoJSON/Nix_format190=== CONT TestGetStorePathHash191--- PASS: TestScriptTokenBadJSON (0.04s)192=== RUN TestGetStorePathHash/valid_store_path193=== PAUSE TestGetStorePathHash/valid_store_path194=== RUN TestGetStorePathHash/basename_without_hyphen_should_error195=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error196=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error197=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error198=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error199=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error200=== CONT TestConvertHashToNix32201=== RUN TestConvertHashToNix32/SRI_format_to_Nix32202=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32203=== RUN TestConvertHashToNix32/already_Nix32_format204=== PAUSE TestConvertHashToNix32/already_Nix32_format205=== RUN TestConvertHashToNix32/invalid_format206=== PAUSE TestConvertHashToNix32/invalid_format207=== PAUSE TestEncodeNixBase32/test_string_hash208--- PASS: TestScriptTokenEmptyToken (0.04s)209=== RUN TestEncodeNixBase32/empty_input210=== PAUSE TestEncodeNixBase32/empty_input2112026/11/09 11:52:34 ERROR Upload failed error=boom count=12122026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39279213=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun214=== CONT TestPathInfoHashCompatibility215=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)216=== CONT TestEncodeNixBase32WithRealHash217--- PASS: TestEncodeNixBase32WithRealHash (0.00s)218=== CONT TestCaseHackSuffix219 listing_test.go:25: case hack suffixes are only stripped where nix enables use-case-hack by default220--- SKIP: TestCaseHackSuffix (0.00s)221=== CONT TestRegisterUploadedObjectReusesConnections222=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum223=== RUN TestPartSizeForNAR/small_stays_at_minimum224=== PAUSE TestPartSizeForNAR/small_stays_at_minimum225=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum226=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum227=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts228=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts229=== RUN TestPartSizeForNAR/1_TiB230=== PAUSE TestPartSizeForNAR/1_TiB231=== CONT TestFilterOversizedClosures232=== RUN TestFilterOversizedClosures/no_limit_keeps_everything233=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)234=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon235=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon236=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI237=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI238=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512239=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512240=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything241=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped242=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped243=== RUN TestFilterOversizedClosures/all_closures_skipped244=== PAUSE TestFilterOversizedClosures/all_closures_skipped245=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica246=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry247=== RUN TestSetClientTLSErrors/missing_cert_file248=== PAUSE TestSetClientTLSErrors/missing_cert_file249=== RUN TestSetClientTLSErrors/missing_key_file250=== PAUSE TestSetClientTLSErrors/missing_key_file251=== RUN TestSetClientTLSErrors/missing_ca_file252=== PAUSE TestSetClientTLSErrors/missing_ca_file253=== RUN TestSetClientTLSErrors/invalid_ca_file254=== PAUSE TestSetClientTLSErrors/invalid_ca_file255=== CONT TestStreamPushIsolatesFailures2562026/11/09 11:52:34 ERROR Upload failed error="bad path" count=3257--- PASS: TestStreamPushIsolatesFailures (0.00s)258=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths259=== RUN TestRateLimiterFeedback/429_enables_limiter260=== PAUSE TestRateLimiterFeedback/429_enables_limiter261=== RUN TestRateLimiterFeedback/503_enables_limiter262=== PAUSE TestRateLimiterFeedback/503_enables_limiter263=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter264=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter265=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter266=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter2672026/11/09 11:52:34 WARN Rate limiter enabled after throttle name=server-test rate=52682026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:42093269--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)270=== CONT TestGetStorePathHash/valid_store_path271=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false272=== CONT TestConvertHashToNix32/SRI_format_to_Nix32273--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)274=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error275=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error276=== CONT TestGetStorePathHash/basename_without_hyphen_should_error277--- PASS: TestGetStorePathHash (0.00s)278 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)279 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)280 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)281 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)282=== CONT TestConvertHashToNix32/invalid_format283=== CONT TestConvertHashToNix32/already_Nix32_format284=== CONT TestEncodeNixBase32/test_string_hash285=== CONT TestEncodeNixBase32/empty_input286--- PASS: TestEncodeNixBase32 (0.03s)287 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)288 --- PASS: TestEncodeNixBase32/empty_input (0.00s)289=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)290=== RUN TestPartSizeForNAR/5_TiB_S3_max_object2912026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39279292=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object293=== RUN TestPartSizeForNAR/capped_at_5_GiB294=== PAUSE TestPartSizeForNAR/capped_at_5_GiB295=== CONT TestFilterOversizedClosures/no_limit_keeps_everything296=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI297=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512298=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon299=== RUN TestSetClientTLS/rejects_connection_without_client_cert300=== CONT TestSetClientTLSErrors/invalid_ca_file301=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert302=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA303=== CONT TestSetClientTLSErrors/missing_ca_file3042026/11/09 11:52:34 WARN Rate limiter backed off name=server-test rate=53052026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:42093306=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths307=== CONT TestSetClientTLSErrors/missing_key_file308=== PAUSE TestParsePathInfoJSON/Nix_format309=== RUN TestParsePathInfoJSON/Lix_format310=== PAUSE TestParsePathInfoJSON/Lix_format311=== RUN TestParsePathInfoJSON/empty_input312=== PAUSE TestParsePathInfoJSON/empty_input313=== RUN TestParsePathInfoJSON/whitespace_only314=== PAUSE TestParsePathInfoJSON/whitespace_only315=== RUN TestParsePathInfoJSON/invalid_JSON316=== PAUSE TestParsePathInfoJSON/invalid_JSON317=== CONT TestRateLimiterFeedback/429_enables_limiter3182026/11/09 11:52:34 WARN Rate limiter enabled after throttle name=server-test rate=53192026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:355213202026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39279321=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3222026/11/09 11:52:34 WARN Rate limiter backed off name=server-test rate=5323=== CONT TestSetClientTLSErrors/missing_cert_file3242026/11/09 11:52:34 INFO Garbage collection started325=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true326=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3272026/11/09 11:52:34 INFO Garbage collection started328=== CONT TestPartSizeForNAR/capped_at_5_GiB329=== CONT TestPartSizeForNAR/5_TiB_S3_max_object330=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum331=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts332=== CONT TestRateLimiterFeedback/503_enables_limiter333=== CONT TestPartSizeForNAR/small_stays_at_minimum3342026/11/09 11:52:34 WARN Rate limiter enabled after throttle name=server-test rate=5335=== CONT TestParsePathInfoJSON/Nix_format3362026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:43307337=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA338--- PASS: TestConvertHashToNix32 (0.00s)339 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)340 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)341 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)342=== CONT TestPartSizeForNAR/zero_stays_at_minimum343=== CONT TestParsePathInfoJSON/invalid_JSON344=== CONT TestParsePathInfoJSON/whitespace_only345=== CONT TestParsePathInfoJSON/Lix_format346=== RUN TestSetClientTLS/preserves_debug_logging_transport347=== PAUSE TestSetClientTLS/preserves_debug_logging_transport348=== CONT TestParsePathInfoJSON/empty_input349=== CONT TestFilterOversizedClosures/all_closures_skipped3502026/11/09 11:52:34 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=50351=== CONT TestPartSizeForNAR/1_TiB352=== CONT TestSetClientTLS/rejects_connection_without_client_cert3532026/11/09 11:52:34 WARN Rate limiter backed off name=server-test rate=53542026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:392793552026/11/09 11:52:34 WARN Rate limiter enabled after throttle name=server-test rate=5356=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3572026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:372713582026/11/09 11:52:34 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=2000359=== CONT TestSetClientTLS/preserves_debug_logging_transport3602026/11/09 11:52:34 WARN Rate limiter backed off name=server-test rate=53612026/11/09 11:52:34 WARN Rate limiter enabled after throttle name=s3-test rate=53622026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:364733632026/11/09 11:52:34 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=0364=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA365--- PASS: TestPathInfoHashCompatibility (0.00s)366 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)367 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)368 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)369 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)370--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)371--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)372--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)373--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.01s)374--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)375 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)376 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)377--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)378--- PASS: TestPartSizeForNAR (0.01s)379 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)380 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)381 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)382 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)383 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)384 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)385 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)386--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)387--- PASS: TestFilterOversizedClosures (0.00s)388 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)389 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)390 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)391=== PAUSE TestPathInfoCACompatibility/null_ca_field392=== RUN TestPathInfoCACompatibility/old_string_format_-_text393--- PASS: TestSetClientTLSErrors (0.01s)394 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)395 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)396 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)397 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)398--- PASS: TestRateLimiterFeedback (0.00s)399 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)400 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)401 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)402 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)403--- PASS: TestParsePathInfoJSON (0.01s)404 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)405 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)406 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)407 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)408 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)409--- PASS: TestStreamPushBatchesUnderLoad (0.03s)410 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)411 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)4122026/11/09 11:52:34 WARN Garbage collection finished on another replica. Its statistics are not available here4132026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:39279414--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)415=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text416=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive417=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive418=== RUN TestPathInfoCACompatibility/new_structured_format_-_text419=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text420=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method421=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method422=== CONT TestPathInfoCACompatibility/null_ca_field423=== CONT TestPathInfoCACompatibility/new_structured_format_-_text424=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive425=== CONT TestPathInfoCACompatibility/old_string_format_-_text426=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method427--- PASS: TestPathInfoCACompatibility (0.02s)428 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)429 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)430 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)431 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)432 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)4332026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:392794342026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:392794352026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:392794362026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:392794372026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:392794382026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:392794392026/11/09 11:52:34 http: TLS handshake error from 127.0.0.1:48150: remote error: tls: bad certificate4402026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:39279441--- PASS: TestSetClientTLS (0.01s)442 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)443 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)444 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)4452026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:39279446--- PASS: TestStreamPushRequestLine (0.03s)4472026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:392794482026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:392794492026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:39279450--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)4512026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:392794522026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:39279453--- PASS: TestDumpPathWriterError (0.07s)4542026/11/09 11:52:34 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:39279455--- PASS: TestDumpPathSingleFile (0.07s)456--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.04s)4572026/11/09 11:52:34 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:45811/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:45811/api/uploads/complete4582026/11/09 11:52:34 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4592026/11/09 11:52:34 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:45811/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:45811/api/uploads/complete4602026/11/09 11:52:34 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4612026/11/09 11:52:34 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:45811/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:45811/api/uploads/complete4622026/11/09 11:52:34 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"463--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.10s)464--- PASS: TestDumpPathMatchesNix (0.08s)465--- PASS: TestUploadMultipart_PartsInParallel (0.66s)466--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.03s)467PASS468Running server tests...469The files belonging to this database system will be owned by user "nixbld".470This user must also own the server process.471472The database cluster will be initialized with locale "C".473The default database encoding has accordingly been set to "SQL_ASCII".474The default text search configuration will be set to "english".475476Data page checksums are enabled.477478creating directory /build/postgres1822590175/data ... ok479creating subdirectories ... ok480selecting dynamic shared memory implementation ... posix481selecting default "max_connections" ... 100482selecting default "shared_buffers" ... 128MB483selecting default time zone ... UTC484creating configuration files ... ok485running bootstrap script ... ok486performing post-bootstrap initialization ... ok487syncing data to disk ... ok488489initdb: warning: enabling "trust" authentication for local connections490initdb: 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.491492Success. You can now start the database server using:493494 pg_ctl -D /build/postgres1822590175/data -l logfile start495496/build/postgres1822590175:5432 - no response4972026-11-09 11:52:36.693 UTC [111] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4982026-11-09 11:52:36.693 UTC [111] LOG: listening on Unix socket "/build/postgres1822590175/.s.PGSQL.5432"4992026-11-09 11:52:36.699 UTC [118] LOG: database system was shut down at 2026-11-09 11:52:36 UTC5002026-11-09 11:52:36.705 UTC [111] LOG: database system is ready to accept connections501/build/postgres1822590175:5432 - accepting connections502=== RUN TestAbortSucceeded503=== PAUSE TestAbortSucceeded504=== RUN TestService_AuthMiddleware505=== PAUSE TestService_AuthMiddleware506=== RUN TestService_AuthMiddleware_MTLSProxyHeader507=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader508=== RUN TestService_AuthMiddleware_MTLSBoundSubjects509=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects510=== RUN TestService_ReadAuthMiddleware511=== PAUSE TestService_ReadAuthMiddleware512=== RUN TestService_AuthMiddleware_OIDC513=== PAUSE TestService_AuthMiddleware_OIDC514=== RUN TestService_RequireScope_OIDC515=== PAUSE TestService_RequireScope_OIDC516=== RUN TestService_ReadScope_PublicByDefault517=== PAUSE TestService_ReadScope_PublicByDefault518=== RUN TestCacheConfigHandler519=== PAUSE TestCacheConfigHandler520=== RUN TestCacheStatsHandler521=== PAUSE TestCacheStatsHandler522=== RUN TestClientCADerivations523=== PAUSE TestClientCADerivations524=== RUN TestClientErrorHandling525=== PAUSE TestClientErrorHandling526=== RUN TestClientIntegration527=== PAUSE TestClientIntegration528=== RUN TestClientMultipleUploads529=== PAUSE TestClientMultipleUploads530=== RUN TestClientWithDependencies531=== PAUSE TestClientWithDependencies532=== RUN TestClientSharedPathCommittedMidPush533=== PAUSE TestClientSharedPathCommittedMidPush534=== RUN TestPinProtectsFromGC535=== PAUSE TestPinProtectsFromGC536=== RUN TestClientPushesUseOnePush537=== PAUSE TestClientPushesUseOnePush538=== RUN TestClientFallsBackToClosures539=== PAUSE TestClientFallsBackToClosures540=== RUN TestDeleteClosuresRacingPins541=== PAUSE TestDeleteClosuresRacingPins542=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock543=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock544=== RUN TestRetryableCompletionError545=== PAUSE TestRetryableCompletionError546=== RUN TestCompleteMultipartUploadRetriesTransientFailure547=== PAUSE TestCompleteMultipartUploadRetriesTransientFailure548=== RUN TestResolveDBConnectionString549=== PAUSE TestResolveDBConnectionString550=== RUN TestConnectWaitsForAPeerMigration551=== PAUSE TestConnectWaitsForAPeerMigration552=== RUN TestLeadElectsOneAndHandsOver553=== PAUSE TestLeadElectsOneAndHandsOver554=== RUN TestLeadIncumbentWinsAfterRestart5552026/11/09 11:52:37 INFO lead: acquired remote=192.0.2.1:12345562026/11/09 11:52:37 INFO lead: released remote=192.0.2.1:12345572026/11/09 11:52:37 INFO lead: acquired remote=192.0.2.1:12345582026/11/09 11:52:38 INFO lead: released remote=192.0.2.1:1234559--- PASS: TestLeadIncumbentWinsAfterRestart (1.84s)560=== RUN TestLeadIncumbentAnnouncesAtOnce561=== PAUSE TestLeadIncumbentAnnouncesAtOnce562=== RUN TestLeadEndsOnShutdown563=== PAUSE TestLeadEndsOnShutdown564=== RUN TestLeadEndsWhenItsConnectionHangs5652026/11/09 11:52:38 INFO lead: acquired remote=192.0.2.1:12345662026-11-09 11:52:40.353 UTC [367] FATAL: terminating connection due to administrator command5672026/11/09 11:52:40 INFO lead: acquired remote=192.0.2.1:12345682026/11/09 11:52:41 WARN lead: lock connection lost error="timeout: context deadline exceeded"5692026/11/09 11:52:41 INFO lead: released remote=192.0.2.1:12345702026/11/09 11:52:41 INFO lead: released remote=192.0.2.1:1234571--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)572=== RUN TestGCAdvisoryLockBlocksConcurrentRun573=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun574=== RUN TestGCBugBareHashReferences575=== PAUSE TestGCBugBareHashReferences576=== RUN TestGCMetrics577=== PAUSE TestGCMetrics578=== RUN TestPushDedupSurvivesConcurrentGC579=== PAUSE TestPushDedupSurvivesConcurrentGC580=== RUN TestDeduplicatedObjectsRecordedAsPending581=== PAUSE TestDeduplicatedObjectsRecordedAsPending582=== RUN TestGCSweepSkipsPendingObjects583=== PAUSE TestGCSweepSkipsPendingObjects584=== RUN TestTombstonedObjectOfferedWithoutWaiting585=== PAUSE TestTombstonedObjectOfferedWithoutWaiting586=== RUN TestGCSweepDeliversEachKeyOnce587=== PAUSE TestGCSweepDeliversEachKeyOnce588=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection589=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection590=== RUN TestForceGCDuringPushOffersSweptObject591=== PAUSE TestForceGCDuringPushOffersSweptObject592=== RUN TestFailedS3DeleteKeepsTombstone593=== PAUSE TestFailedS3DeleteKeepsTombstone594=== RUN TestSweepSkipsRowsLockedByPush595=== PAUSE TestSweepSkipsRowsLockedByPush596=== RUN TestRegisterCompletedObjectNeedsPendingRow597=== PAUSE TestRegisterCompletedObjectNeedsPendingRow598=== RUN TestGetExistingObjectsLocksRows599=== PAUSE TestGetExistingObjectsLocksRows600=== RUN TestSweepRechecksPendingAfterLocking601=== PAUSE TestSweepRechecksPendingAfterLocking602=== RUN TestPushWaitsForSweepHoldingRow603=== PAUSE TestPushWaitsForSweepHoldingRow604=== RUN TestCommitRacingPendingCleanupKeepsObjects605=== PAUSE TestCommitRacingPendingCleanupKeepsObjects606=== RUN TestGCEndsOnShutdown607=== PAUSE TestGCEndsOnShutdown608=== RUN TestGCTaskStore_StartNew609=== PAUSE TestGCTaskStore_StartNew610=== RUN TestGCTaskStore_DeduplicateSameParams611=== PAUSE TestGCTaskStore_DeduplicateSameParams612=== RUN TestGCTaskStore_ConflictDifferentParams613=== PAUSE TestGCTaskStore_ConflictDifferentParams614=== RUN TestGCTaskStore_GetEmpty615=== PAUSE TestGCTaskStore_GetEmpty616=== RUN TestGCTaskStore_GetReturnsLatest617=== PAUSE TestGCTaskStore_GetReturnsLatest618=== RUN TestGCTaskStore_CompletedAllowsNewTask619=== PAUSE TestGCTaskStore_CompletedAllowsNewTask620=== RUN TestGCTaskStore_PhaseUpdates621=== PAUSE TestGCTaskStore_PhaseUpdates622=== RUN TestGCTaskStore_Fail623=== PAUSE TestGCTaskStore_Fail624=== RUN TestGracefulShutdownDrainsInflight625=== PAUSE TestGracefulShutdownDrainsInflight626=== RUN TestService_healthCheckHandler627=== PAUSE TestService_healthCheckHandler628=== RUN TestService_readinessHandler629=== PAUSE TestService_readinessHandler630=== RUN TestGenerateLandingPage631=== PAUSE TestGenerateLandingPage632=== RUN TestEnsureAbortUploadsRule633=== PAUSE TestEnsureAbortUploadsRule634=== RUN TestCacheConfigHandlerMaxNarSize635=== PAUSE TestCacheConfigHandlerMaxNarSize636=== RUN TestCreatePendingClosureRejectsOversizedNAR637=== PAUSE TestCreatePendingClosureRejectsOversizedNAR638=== RUN TestNARDeduplicationMetadataUploadBug639=== PAUSE TestNARDeduplicationMetadataUploadBug640=== RUN TestMetricsInventory641=== PAUSE TestMetricsInventory642=== RUN TestMetricsCommit643=== PAUSE TestMetricsCommit644=== RUN TestService_NativeMTLS645=== PAUSE TestService_NativeMTLS646=== RUN TestServerTLSConfig647=== PAUSE TestServerTLSConfig648=== RUN TestMultipartCleanup649=== PAUSE TestMultipartCleanup650=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded651=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded652=== RUN TestPendingCleanupUsesOneCutoff653=== PAUSE TestPendingCleanupUsesOneCutoff654=== RUN TestObjectStatsTrigger655=== PAUSE TestObjectStatsTrigger656=== RUN TestObjectStatsUpdatedOncePerCommit657=== PAUSE TestObjectStatsUpdatedOncePerCommit658=== RUN TestOrphanedObjectsGC659=== PAUSE TestOrphanedObjectsGC660=== RUN TestOrphanedObjectsGCStressTest661=== PAUSE TestOrphanedObjectsGCStressTest662=== RUN TestCreatePin_ReservedPins663=== PAUSE TestCreatePin_ReservedPins664=== RUN TestPresentReportsOnlyClosureRoots665=== PAUSE TestPresentReportsOnlyClosureRoots666=== RUN TestPresentRefreshesOnlyStaleClosures667=== PAUSE TestPresentRefreshesOnlyStaleClosures668=== RUN TestPresentNotReportedWhileGCDeletesClosure669=== PAUSE TestPresentNotReportedWhileGCDeletesClosure670=== RUN TestParseSingleRange671=== PAUSE TestParseSingleRange672=== RUN TestProxyHeadersOnlyTrustedOnSocket6732026/11/09 11:52:41 INFO Starting HTTP server address=127.0.0.1:405616742026/11/09 11:52:41 INFO Starting HTTP server address=proxy.sock6752026/11/09 11:52:41 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6762026/11/09 11:52:41 INFO Shutdown signal received, draining in-flight requests timeout=10s677--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)678=== RUN TestIsValidCachePath679=== PAUSE TestIsValidCachePath680=== RUN TestReadProxyNarinfo681=== PAUSE TestReadProxyNarinfo682=== RUN TestReadProxyNarinfoAlreadyDecompressed683=== PAUSE TestReadProxyNarinfoAlreadyDecompressed684=== RUN TestReadProxyContentNegotiation685=== PAUSE TestReadProxyContentNegotiation686=== RUN TestReadProxyNarStreaming687=== PAUSE TestReadProxyNarStreaming688=== RUN TestReadProxy404689=== PAUSE TestReadProxy404690=== RUN TestReadProxyInvalidPath691=== PAUSE TestReadProxyInvalidPath692=== RUN TestReadProxyHead693=== PAUSE TestReadProxyHead694=== RUN TestReadProxyOutlastsServerWriteTimeout695=== PAUSE TestReadProxyOutlastsServerWriteTimeout696=== RUN TestReadProxyConditionalGet697=== PAUSE TestReadProxyConditionalGet698=== RUN TestReadProxyRootRedirectsToIndexHTML699=== PAUSE TestReadProxyRootRedirectsToIndexHTML700=== RUN TestReadProxyDisabled701=== PAUSE TestReadProxyDisabled702=== RUN TestReadRedirectNar703=== PAUSE TestReadRedirectNar704=== RUN TestReadRedirectKeepsNarinfoProxied705=== PAUSE TestReadRedirectKeepsNarinfoProxied706=== RUN TestReadProxyRangeRequest707=== PAUSE TestReadProxyRangeRequest708=== RUN TestReadRedirectUsesPublicS3URL709=== PAUSE TestReadRedirectUsesPublicS3URL710=== RUN TestPush_OverlappingRootsStoreOneRowPerKey711=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey712=== RUN TestPush_CompleteCommitsEveryRoot713=== PAUSE TestPush_CompleteCommitsEveryRoot714=== RUN TestPush_RepeatedRootCommitsOnce715=== PAUSE TestPush_RepeatedRootCommitsOnce716=== RUN TestPush_CompleteWaitsForCleanupOfThePush717=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush718=== RUN TestPush_RootsAreLockedInByteOrder719=== PAUSE TestPush_RootsAreLockedInByteOrder720=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit721=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit722=== RUN TestPush_RejectsBadRequests723=== PAUSE TestPush_RejectsBadRequests724=== RUN TestPush_SignsNarinfosOfItsPendingObjects725=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects726=== RUN TestSharedNarBothUploadsComplete727=== PAUSE TestSharedNarBothUploadsComplete728=== RUN TestCompleteMultipartUpload_ErrorButObjectExists729=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists730=== RUN TestCompletedNarNotReofferedAcrossClosures731=== PAUSE TestCompletedNarNotReofferedAcrossClosures732=== RUN TestPresignedUploadRegisteredBeforeCommit733=== PAUSE TestPresignedUploadRegisteredBeforeCommit734=== RUN TestService_Rustfstest735=== PAUSE TestService_Rustfstest736=== RUN TestParseSize737=== PAUSE TestParseSize738=== RUN TestSkippedUploadsHandler739=== PAUSE TestSkippedUploadsHandler740=== RUN TestSystemdListenerNotActivated741--- PASS: TestSystemdListenerNotActivated (0.00s)742=== RUN TestWatchdogBeatsWhenHealthy743--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)744=== RUN TestWatchdogSkipsWhenUnhealthy7452026/11/09 11:52:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/11/09 11:52:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/09 11:52:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/09 11:52:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/09 11:52:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/11/09 11:52:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/11/09 11:52:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/11/09 11:52:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7532026/11/09 11:52:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7542026/11/09 11:52:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"755--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)756=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle757=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle758=== RUN TestProxyWriteTimeout759=== PAUSE TestProxyWriteTimeout760=== RUN TestPendingClosureWriteTimeout761=== PAUSE TestPendingClosureWriteTimeout762=== RUN TestIsValidUploadKey763=== PAUSE TestIsValidUploadKey764=== RUN TestUploadHandlersRejectInvalidKeys765=== PAUSE TestUploadHandlersRejectInvalidKeys766=== RUN TestUploadHandlersRejectOversizedBody767=== PAUSE TestUploadHandlersRejectOversizedBody768=== RUN TestService_cleanupPendingClosuresHandler769=== PAUSE TestService_cleanupPendingClosuresHandler770=== RUN TestService_createPendingClosureHandler771=== PAUSE TestService_createPendingClosureHandler772=== RUN TestService_verifyS3Integrity773=== PAUSE TestService_verifyS3Integrity774=== RUN TestService_verifyS3ReuploadsStaleNarinfo775=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo776=== RUN TestCompleteMultipartUnregistered777=== PAUSE TestCompleteMultipartUnregistered778=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT779=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT780=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle781=== CONT TestAbortSucceeded782--- PASS: TestAbortSucceeded (0.00s)783=== CONT TestSkippedUploadsHandler784=== CONT TestReadProxyRootRedirectsToIndexHTML785=== CONT TestParseSize786--- PASS: TestParseSize (0.00s)787=== CONT TestCompleteMultipartUnregistered788=== CONT TestService_Rustfstest789=== CONT TestPresignedUploadRegisteredBeforeCommit790=== CONT TestCompletedNarNotReofferedAcrossClosures7912026/11/09 11:52:42 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000792=== CONT TestCompleteMultipartUpload_ErrorButObjectExists793=== CONT TestSharedNarBothUploadsComplete794=== CONT TestPush_SignsNarinfosOfItsPendingObjects795=== CONT TestPush_RejectsBadRequests796=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit797=== CONT TestPush_RootsAreLockedInByteOrder798=== CONT TestPush_CompleteWaitsForCleanupOfThePush799=== CONT TestPush_RepeatedRootCommitsOnce800=== CONT TestPush_CompleteCommitsEveryRoot801=== CONT TestPush_OverlappingRootsStoreOneRowPerKey802=== CONT TestReadRedirectUsesPublicS3URL803=== CONT TestReadProxyRangeRequest804=== CONT TestReadRedirectKeepsNarinfoProxied805=== CONT TestReadRedirectNar806=== CONT TestService_cleanupPendingClosuresHandler807=== CONT TestReadProxyDisabled808=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT809--- PASS: TestSkippedUploadsHandler (0.01s)810=== CONT TestReadProxyConditionalGet811--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.29s)812=== CONT TestService_verifyS3ReuploadsStaleNarinfo813=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed814=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed815=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed816=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed817=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost818=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost819=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed820=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed821=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed822=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed823=== CONT TestReadProxyOutlastsServerWriteTimeout8242026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures8252026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures8262026/11/09 11:52:42 INFO Received push request method=POST path=/api/pushes8272026/11/09 11:52:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8282026/11/09 11:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete8292026/11/09 11:52:42 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst830--- PASS: TestCompleteMultipartUnregistered (0.36s)831=== CONT TestService_verifyS3Integrity8322026/11/09 11:52:42 INFO Completed push id=1 objects=4 duration=11.098381ms8332026/11/09 11:52:42 INFO Received push request method=POST path=/api/pushes834--- PASS: TestService_Rustfstest (0.38s)835=== CONT TestReadProxyHead8362026/11/09 11:52:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8372026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures8382026/11/09 11:52:42 INFO Received push request method=POST path=/api/pushes8392026/11/09 11:52:42 INFO Aborted multipart uploads count=0 kept=08402026/11/09 11:52:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8412026/11/09 11:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8422026/11/09 11:52:42 INFO Signed narinfos id=1 count=18432026/11/09 11:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8442026/11/09 11:52:42 WARN Force mode enabled - objects will be deleted immediately without grace period8452026/11/09 11:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8462026/11/09 11:52:42 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8472026/11/09 11:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8482026/11/09 11:52:42 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8492026/11/09 11:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8502026/11/09 11:52:42 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18512026/11/09 11:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8522026/11/09 11:52:42 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo8532026/11/09 11:52:42 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LmQ3MDI4MmEyLTJhZDEtNDVjMC1iMWUyLTc4YTVjM2M4MWQxNngxNzk0MjI1MTYyNDkzMzk3MjU0854--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.43s)855=== CONT TestService_createPendingClosureHandler856=== RUN TestPush_RejectsBadRequests/bad_root857=== PAUSE TestPush_RejectsBadRequests/bad_root858=== RUN TestPush_RejectsBadRequests/root_not_in_objects859=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects860=== RUN TestPush_RejectsBadRequests/no_roots861=== PAUSE TestPush_RejectsBadRequests/no_roots862=== RUN TestPush_RejectsBadRequests/no_objects863=== PAUSE TestPush_RejectsBadRequests/no_objects864=== CONT TestReadProxyInvalidPath8652026/11/09 11:52:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LmQ3MDI4MmEyLTJhZDEtNDVjMC1iMWUyLTc4YTVjM2M4MWQxNngxNzk0MjI1MTYyNDkzMzk3MjU0 parts=1866--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.44s)867=== CONT TestReadProxy4048682026/11/09 11:52:42 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=08692026/11/09 11:52:42 INFO Vacuumed table table=pending_closures8702026/11/09 11:52:42 INFO Vacuumed table table=pending_objects8712026/11/09 11:52:42 INFO Vacuumed table table=multipart_uploads8722026/11/09 11:52:42 INFO Vacuumed table table=closures8732026/11/09 11:52:42 INFO Vacuumed table table=objects8742026/11/09 11:52:42 INFO Received complete push request method=POST path=/api/pushes/2/complete8752026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures8762026/11/09 11:52:42 INFO Completed push id=2 objects=4 duration=7.440008ms877--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.47s)878=== CONT TestGetExistingObjectsLocksRows8792026/11/09 11:52:42 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8802026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures881--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.49s)882=== CONT TestIsValidUploadKey883=== RUN TestIsValidUploadKey/narinfo884=== PAUSE TestIsValidUploadKey/narinfo885=== RUN TestIsValidUploadKey/nar_zst886=== PAUSE TestIsValidUploadKey/nar_zst887=== RUN TestIsValidUploadKey/nar_xz888=== PAUSE TestIsValidUploadKey/nar_xz889=== RUN TestIsValidUploadKey/nar_plain890=== PAUSE TestIsValidUploadKey/nar_plain891=== RUN TestIsValidUploadKey/listing892=== PAUSE TestIsValidUploadKey/listing893=== RUN TestIsValidUploadKey/build_log894=== PAUSE TestIsValidUploadKey/build_log895=== RUN TestIsValidUploadKey/build_log_home-manager_file896=== PAUSE TestIsValidUploadKey/build_log_home-manager_file897=== RUN TestIsValidUploadKey/build_log_plus_in_name898=== PAUSE TestIsValidUploadKey/build_log_plus_in_name899=== RUN TestIsValidUploadKey/build_log_question_mark900=== PAUSE TestIsValidUploadKey/build_log_question_mark901=== RUN TestIsValidUploadKey/build_log_equals902=== PAUSE TestIsValidUploadKey/build_log_equals903=== RUN TestIsValidUploadKey/realisation904=== PAUSE TestIsValidUploadKey/realisation905=== RUN TestIsValidUploadKey/realisation_plus_in_output906=== PAUSE TestIsValidUploadKey/realisation_plus_in_output907=== RUN TestIsValidUploadKey/nix-cache-info908=== PAUSE TestIsValidUploadKey/nix-cache-info909=== RUN TestIsValidUploadKey/index.html910=== PAUSE TestIsValidUploadKey/index.html911=== RUN TestIsValidUploadKey/narinfo_key,_nar_type912=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type913=== RUN TestIsValidUploadKey/nar_key,_narinfo_type914=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type915=== RUN TestIsValidUploadKey/listing_key,_narinfo_type916=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type917=== RUN TestIsValidUploadKey/traversal918=== PAUSE TestIsValidUploadKey/traversal919=== RUN TestIsValidUploadKey/traversal_nar920=== PAUSE TestIsValidUploadKey/traversal_nar921=== RUN TestIsValidUploadKey/absolute922=== PAUSE TestIsValidUploadKey/absolute923=== RUN TestIsValidUploadKey/empty_key924=== PAUSE TestIsValidUploadKey/empty_key925=== RUN TestIsValidUploadKey/unknown_type926=== PAUSE TestIsValidUploadKey/unknown_type927=== CONT TestRegisterCompletedObjectNeedsPendingRow928--- PASS: TestReadRedirectUsesPublicS3URL (0.51s)929=== CONT TestUploadHandlersRejectOversizedBody9302026/11/09 11:52:42 INFO Received push request method=POST path=/api/pushes931--- PASS: TestReadProxyDisabled (0.53s)932=== CONT TestSweepSkipsRowsLockedByPush9332026-11-09 11:52:42.641 UTC [494] ERROR: could not obtain lock on row in relation "closures"9342026-11-09 11:52:42.641 UTC [494] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9352026-11-09 11:52:42.641 UTC [494] ERROR: could not obtain lock on row in relation "closures"9362026-11-09 11:52:42.641 UTC [494] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9372026-11-09 11:52:42.642 UTC [494] ERROR: could not obtain lock on row in relation "closures"9382026-11-09 11:52:42.642 UTC [494] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9392026-11-09 11:52:42.642 UTC [494] ERROR: could not obtain lock on row in relation "closures"9402026-11-09 11:52:42.642 UTC [494] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9412026-11-09 11:52:42.642 UTC [494] ERROR: could not obtain lock on row in relation "closures"9422026-11-09 11:52:42.642 UTC [494] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9432026/11/09 11:52:42 INFO Received cleanup request method=DELETE path=/api/pending_closures9442026/11/09 11:52:42 INFO Aborted multipart uploads count=0 kept=0945--- PASS: TestPush_RootsAreLockedInByteOrder (0.56s)946=== CONT TestSweepRechecksPendingAfterLocking9472026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures9482026/11/09 11:52:42 INFO Received cleanup request method=DELETE path=/api/pending_closures9492026/11/09 11:52:42 INFO Aborted multipart uploads count=1 kept=09502026/11/09 11:52:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9512026-11-09 11:52:42.664 UTC [454] ERROR: Closure does not exist: id=19522026-11-09 11:52:42.664 UTC [454] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9532026-11-09 11:52:42.664 UTC [454] STATEMENT: -- name: CommitPendingClosure :one954 SELECT commit_pending_closure($1::bigint)::bigint955 956--- PASS: TestService_cleanupPendingClosuresHandler (0.57s)957=== CONT TestFailedS3DeleteKeepsTombstone9582026/11/09 11:52:42 INFO Received push request method=POST path=/api/pushes959--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.60s)960=== CONT TestUploadHandlersRejectInvalidKeys961=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info962=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info963=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal964=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal965=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key966=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key967=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key968=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key969=== CONT TestReadProxyNarStreaming970--- PASS: TestReadProxyRangeRequest (0.62s)971=== CONT TestForceGCDuringPushOffersSweptObject972=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows973=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows974=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check975=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check976=== CONT TestPendingClosureWriteTimeout977=== RUN TestPendingClosureWriteTimeout/empty978=== PAUSE TestPendingClosureWriteTimeout/empty979=== RUN TestPendingClosureWriteTimeout/400_objects980=== PAUSE TestPendingClosureWriteTimeout/400_objects981=== RUN TestPendingClosureWriteTimeout/670k_objects982=== PAUSE TestPendingClosureWriteTimeout/670k_objects983=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline984=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline985=== CONT TestReadProxyContentNegotiation9862026/11/09 11:52:42 INFO Received push request method=POST path=/api/pushes9872026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures988--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.66s)989=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection990=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure991=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure992=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart993=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart994=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts995=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts996=== CONT TestReadProxyNarinfoAlreadyDecompressed9972026/11/09 11:52:42 INFO Received push request method=POST path=/api/pushes9982026/11/09 11:52:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9992026/11/09 11:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete10002026/11/09 11:52:42 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LjE2Zjk4NWVlLTE5ZGYtNDJjYS05OGQ4LWQ1NjQxMmZjMTZhNngxNzk0MjI1MTYyNDAxMDg0NDY3 parts=1210012026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures1002--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.70s)1003=== CONT TestGCSweepDeliversEachKeyOnce10042026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures10052026/11/09 11:52:42 INFO Completed push id=1 objects=4 duration=9.906411ms1006--- PASS: TestPush_RepeatedRootCommitsOnce (0.70s)1007=== CONT TestCreatePendingClosureRejectsOversizedNAR10082026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures1009--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1010=== CONT TestTombstonedObjectOfferedWithoutWaiting10112026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures10122026/11/09 11:52:42 INFO Received push request method=POST path=/api/pushes10132026/11/09 11:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete10142026/11/09 11:52:42 INFO Completed push id=1 objects=6 duration=11.161362ms1015--- PASS: TestPush_CompleteCommitsEveryRoot (0.75s)1016=== CONT TestCacheConfigHandlerMaxNarSize1017--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1018=== CONT TestGCSweepSkipsPendingObjects1019--- PASS: TestReadRedirectKeepsNarinfoProxied (0.75s)1020=== CONT TestNARDeduplicationMetadataUploadBug1021--- PASS: TestReadProxyConditionalGet (0.78s)1022=== CONT TestDeduplicatedObjectsRecordedAsPending1023--- PASS: TestReadRedirectNar (0.80s)1024=== CONT TestEnsureAbortUploadsRule10252026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures1026--- PASS: TestReadProxyHead (0.49s)1027=== CONT TestReadProxyNarinfo1028--- PASS: TestReadProxyInvalidPath (0.44s)1029=== CONT TestPushDedupSurvivesConcurrentGC10302026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures10312026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures10322026/11/09 11:52:42 INFO Received uploads request method=POST path=/api/pending_closures10332026-11-09 11:52:43.038 UTC [511] ERROR: Push does not exist: id=110342026-11-09 11:52:43.038 UTC [511] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10352026-11-09 11:52:43.038 UTC [511] STATEMENT: SELECT commit_push($1)1036--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.95s)1037=== CONT TestGCTaskStore_GetEmpty1038--- PASS: TestGCTaskStore_GetEmpty (0.00s)1039=== CONT TestIsValidCachePath1040=== RUN TestIsValidCachePath/narinfo1041=== PAUSE TestIsValidCachePath/narinfo1042=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1043=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1044=== RUN TestIsValidCachePath/nar_zst1045=== PAUSE TestIsValidCachePath/nar_zst1046=== RUN TestIsValidCachePath/nar_xz1047=== PAUSE TestIsValidCachePath/nar_xz1048=== RUN TestIsValidCachePath/nar_bz21049=== PAUSE TestIsValidCachePath/nar_bz21050=== RUN TestIsValidCachePath/nar_uncompressed1051=== PAUSE TestIsValidCachePath/nar_uncompressed1052=== RUN TestIsValidCachePath/ls1053=== PAUSE TestIsValidCachePath/ls1054=== RUN TestIsValidCachePath/log1055=== PAUSE TestIsValidCachePath/log1056=== RUN TestIsValidCachePath/realisation1057=== PAUSE TestIsValidCachePath/realisation1058=== RUN TestIsValidCachePath/nix-cache-info1059=== PAUSE TestIsValidCachePath/nix-cache-info1060=== RUN TestIsValidCachePath/index.html1061=== PAUSE TestIsValidCachePath/index.html1062=== RUN TestIsValidCachePath/traversal_parent1063=== PAUSE TestIsValidCachePath/traversal_parent1064=== RUN TestIsValidCachePath/traversal_in_middle1065=== PAUSE TestIsValidCachePath/traversal_in_middle1066=== RUN TestIsValidCachePath/invalid_char_e1067=== PAUSE TestIsValidCachePath/invalid_char_e1068=== RUN TestIsValidCachePath/invalid_char_u1069=== PAUSE TestIsValidCachePath/invalid_char_u1070=== RUN TestIsValidCachePath/random_path1071=== PAUSE TestIsValidCachePath/random_path1072=== RUN TestIsValidCachePath/empty1073=== PAUSE TestIsValidCachePath/empty1074=== RUN TestIsValidCachePath/leading_slash1075=== PAUSE TestIsValidCachePath/leading_slash1076=== RUN TestIsValidCachePath/wrong_extension1077=== PAUSE TestIsValidCachePath/wrong_extension1078=== RUN TestIsValidCachePath/short_hash1079=== PAUSE TestIsValidCachePath/short_hash1080=== CONT TestGCMetrics1081--- PASS: TestGetExistingObjectsLocksRows (0.50s)1082=== CONT TestGCTaskStore_ConflictDifferentParams1083--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1084=== CONT TestGCBugBareHashReferences1085--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.49s)1086=== CONT TestParseSingleRange1087=== RUN TestParseSingleRange/none1088=== PAUSE TestParseSingleRange/none1089=== RUN TestParseSingleRange/unknown_unit1090=== PAUSE TestParseSingleRange/unknown_unit1091=== RUN TestParseSingleRange/multi-range_ignored1092=== PAUSE TestParseSingleRange/multi-range_ignored1093=== RUN TestParseSingleRange/malformed_no_dash1094=== PAUSE TestParseSingleRange/malformed_no_dash1095=== RUN TestParseSingleRange/malformed_both_empty1096=== PAUSE TestParseSingleRange/malformed_both_empty1097=== RUN TestParseSingleRange/malformed_end_before_start1098=== PAUSE TestParseSingleRange/malformed_end_before_start1099=== RUN TestParseSingleRange/closed1100=== PAUSE TestParseSingleRange/closed1101=== RUN TestParseSingleRange/open-ended1102=== PAUSE TestParseSingleRange/open-ended1103=== RUN TestParseSingleRange/end_clamped_to_size1104=== PAUSE TestParseSingleRange/end_clamped_to_size1105=== RUN TestParseSingleRange/suffix1106=== PAUSE TestParseSingleRange/suffix1107=== RUN TestParseSingleRange/suffix_exceeds_size1108=== PAUSE TestParseSingleRange/suffix_exceeds_size1109=== RUN TestParseSingleRange/single_byte1110=== PAUSE TestParseSingleRange/single_byte1111=== RUN TestParseSingleRange/start_past_EOF1112=== PAUSE TestParseSingleRange/start_past_EOF1113=== RUN TestParseSingleRange/start_far_past_EOF1114=== PAUSE TestParseSingleRange/start_far_past_EOF1115=== CONT TestGCTaskStore_DeduplicateSameParams1116--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1117=== CONT TestGCAdvisoryLockBlocksConcurrentRun1118--- PASS: TestReadProxy404 (0.54s)1119=== CONT TestPresentNotReportedWhileGCDeletesClosure1120=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1121=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1122=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1123=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1124=== CONT TestLeadEndsOnShutdown11252026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=011262026/11/09 11:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period11272026/11/09 11:52:43 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=011282026/11/09 11:52:43 INFO Vacuumed table table=pending_closures11292026/11/09 11:52:43 INFO Vacuumed table table=pending_objects11302026/11/09 11:52:43 INFO Vacuumed table table=multipart_uploads11312026/11/09 11:52:43 INFO Vacuumed table table=closures11322026/11/09 11:52:43 INFO Vacuumed table table=objects11332026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=011342026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=011352026/11/09 11:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period11362026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures11372026/11/09 11:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period11382026/11/09 11:52:43 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=011392026/11/09 11:52:43 INFO Vacuumed table table=pending_closures11402026/11/09 11:52:43 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=011412026/11/09 11:52:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11422026/11/09 11:52:43 INFO Vacuumed table table=pending_objects11432026/11/09 11:52:43 INFO Vacuumed table table=multipart_uploads11442026/11/09 11:52:43 INFO Vacuumed table table=pending_closures11452026/11/09 11:52:43 INFO Vacuumed table table=closures11462026/11/09 11:52:43 INFO Vacuumed table table=pending_objects11472026/11/09 11:52:43 INFO Vacuumed table table=multipart_uploads11482026/11/09 11:52:43 INFO Vacuumed table table=closures11492026/11/09 11:52:43 INFO Vacuumed table table=objects1150--- PASS: TestSweepRechecksPendingAfterLocking (0.52s)1151=== CONT TestPresentRefreshesOnlyStaleClosures11522026/11/09 11:52:43 INFO Vacuumed table table=objects1153--- PASS: TestSweepSkipsRowsLockedByPush (0.55s)1154=== CONT TestLeadIncumbentAnnouncesAtOnce1155--- PASS: TestReadProxyNarStreaming (0.49s)1156=== CONT TestGCTaskStore_GetReturnsLatest1157--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1158=== CONT TestLeadElectsOneAndHandsOver11592026/11/09 11:52:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LmI1NWY2MjkwLTlhODgtNGNlZC1hYWQ4LTI5ODE5ZTRmNmZmMHgxNzk0MjI1MTYyNzkyMDgwNzM1 parts=1211602026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures11612026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=011622026/11/09 11:52:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11632026/11/09 11:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period11642026/11/09 11:52:43 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11652026/11/09 11:52:43 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."11662026/11/09 11:52:43 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LjY3ZGFjMzc4LTc0NTEtNGMyMi05NTg5LTI5MDg0M2EyMmYxOXgxNzk0MjI1MTYyOTMyMTY1MDQw parts=1011672026/11/09 11:52:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1168--- PASS: TestFailedS3DeleteKeepsTombstone (0.58s)1169=== CONT TestPresentReportsOnlyClosureRoots1170--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.49s)1171=== CONT TestConnectWaitsForAPeerMigration11722026/11/09 11:52:43 INFO Completed upload id=1 objects=2 duration=2.970907ms11732026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures11742026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures11752026/11/09 11:52:43 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11762026/11/09 11:52:43 WARN Found objects in DB but missing from S3, will re-upload count=11177--- PASS: TestService_verifyS3Integrity (0.81s)1178=== CONT TestGenerateLandingPage1179--- PASS: TestGenerateLandingPage (0.00s)1180=== CONT TestResolveDBConnectionString1181=== RUN TestResolveDBConnectionString/flag_wins1182=== PAUSE TestResolveDBConnectionString/flag_wins1183=== RUN TestResolveDBConnectionString/file_when_flag_empty1184=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1185=== RUN TestResolveDBConnectionString/missing_file_is_an_error1186=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1187=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1188=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1189=== RUN TestResolveDBConnectionString/nothing_configured1190=== PAUSE TestResolveDBConnectionString/nothing_configured1191=== CONT TestCreatePin_ReservedPins1192--- PASS: TestReadProxyContentNegotiation (0.55s)1193=== CONT TestCompleteMultipartUploadRetriesTransientFailure11942026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures1195--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.50s)1196=== CONT TestOrphanedObjectsGCStressTest11972026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=011982026/11/09 11:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period11992026/11/09 11:52:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12002026/11/09 11:52:43 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LjQ2YTBhYmRmLWYxNjctNDBhYi1hN2M3LTkwM2ZlMjE0MDk3YXgxNzk0MjI1MTYzMDAzMzg3OTc0 parts=1012012026/11/09 11:52:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12022026/11/09 11:52:43 INFO Completed upload id=1 objects=2 duration=3.532753ms12032026/11/09 11:52:43 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012042026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures12052026/11/09 11:52:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures12062026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures12072026/11/09 11:52:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=012082026/11/09 11:52:43 INFO Vacuumed table table=pending_closures12092026/11/09 11:52:43 INFO Vacuumed table table=pending_objects12102026/11/09 11:52:43 INFO Vacuumed table table=multipart_uploads12112026/11/09 11:52:43 INFO Vacuumed table table=closures12122026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=012132026/11/09 11:52:43 INFO Vacuumed table table=objects1214--- PASS: TestGCSweepDeliversEachKeyOnce (0.56s)1215=== CONT TestRetryableCompletionError1216=== RUN TestRetryableCompletionError/deadline_exceeded1217=== PAUSE TestRetryableCompletionError/deadline_exceeded1218=== RUN TestRetryableCompletionError/degraded_quorum1219=== PAUSE TestRetryableCompletionError/degraded_quorum1220=== RUN TestRetryableCompletionError/transport_failure1221=== PAUSE TestRetryableCompletionError/transport_failure1222=== RUN TestRetryableCompletionError/no_such_upload1223=== PAUSE TestRetryableCompletionError/no_such_upload1224=== RUN TestRetryableCompletionError/invalid_part1225=== PAUSE TestRetryableCompletionError/invalid_part1226=== RUN TestRetryableCompletionError/nil1227=== PAUSE TestRetryableCompletionError/nil1228=== RUN TestRetryableCompletionError/bad_gateway1229=== PAUSE TestRetryableCompletionError/bad_gateway1230=== RUN TestRetryableCompletionError/access_denied1231=== PAUSE TestRetryableCompletionError/access_denied1232=== RUN TestRetryableCompletionError/throttled1233=== PAUSE TestRetryableCompletionError/throttled1234=== RUN TestRetryableCompletionError/context_canceled1235=== PAUSE TestRetryableCompletionError/context_canceled1236=== CONT TestService_readinessHandler1237=== NAME TestNARDeduplicationMetadataUploadBug1238 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1309307243/001/store/6ham0hsqvhjc9865hxlq2v7smsb3gi28-file1.txt12392026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=012402026/11/09 11:52:43 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=012412026/11/09 11:52:43 INFO Vacuumed table table=pending_closures12422026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures12432026/11/09 11:52:43 INFO Vacuumed table table=pending_objects12442026/11/09 11:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period12452026/11/09 11:52:43 INFO Vacuumed table table=multipart_uploads1246--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.50s)1247=== CONT TestOrphanedObjectsGC12482026/11/09 11:52:43 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=012492026/11/09 11:52:43 INFO Vacuumed table table=closures12502026/11/09 11:52:43 INFO Vacuumed table table=pending_closures12512026/11/09 11:52:43 INFO Vacuumed table table=objects12522026/11/09 11:52:43 INFO Vacuumed table table=pending_objects12532026/11/09 11:52:43 INFO Vacuumed table table=multipart_uploads12542026/11/09 11:52:43 INFO Vacuumed table table=closures12552026/11/09 11:52:43 INFO Vacuumed table table=objects1256--- PASS: TestGCSweepSkipsPendingObjects (0.54s)1257=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12582026/11/09 11:52:43 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001259--- PASS: TestService_createPendingClosureHandler (0.86s)1260=== CONT TestGCTaskStore_StartNew1261--- PASS: TestGCTaskStore_StartNew (0.00s)1262=== CONT TestDeleteClosuresRacingPins12632026/11/09 11:52:43 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket48 days=21264--- PASS: TestEnsureAbortUploadsRule (0.50s)1265=== CONT TestGCEndsOnShutdown1266=== RUN TestGCEndsOnShutdown/before_the_run1267=== PAUSE TestGCEndsOnShutdown/before_the_run1268=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1269=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1270=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1271=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1272=== CONT TestService_healthCheckHandler12732026/11/09 11:52:43 INFO Received push request method=POST path=/api/pushes12742026/11/09 11:52:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12752026/11/09 11:52:43 INFO Uploading 6ham0hsqvhjc9865hxlq2v7smsb3gi28-file1.txt (160B)1276--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.69s)1277=== CONT TestCommitRacingPendingCleanupKeepsObjects12782026/11/09 11:52:43 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12792026/11/09 11:52:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12802026/11/09 11:52:43 WARN Failed to register uploaded object key=6ham0hsqvhjc9865hxlq2v7smsb3gi28.ls error="server returned 404: 404 page not found\n"12812026/11/09 11:52:43 INFO Signed narinfos id=1 count=112822026/11/09 11:52:43 INFO Uploading 1 narinfos12832026/11/09 11:52:43 INFO Received complete push request method=POST path=/api/pushes/1/complete12842026/11/09 11:52:43 WARN Failed to register uploaded object key=6ham0hsqvhjc9865hxlq2v7smsb3gi28.narinfo error="server returned 404: 404 page not found\n"12852026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures12862026/11/09 11:52:43 INFO Completed push id=1 objects=3 duration=8.163234ms12872026/11/09 11:52:43 INFO Upload complete. (64ms)1288=== NAME TestNARDeduplicationMetadataUploadBug1289 metadata_upload_test.go:54: Retrieved narinfo from S3:1290 StorePath: /build/TestNARDeduplicationMetadataUploadBug1309307243/001/store/6ham0hsqvhjc9865hxlq2v7smsb3gi28-file1.txt1291 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1292 Compression: zstd1293 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1294 NarSize: 1601295 References: 1296 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12972026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=01298 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1299 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1300 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13012026/11/09 11:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period13022026/11/09 11:52:43 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=013032026/11/09 11:52:43 INFO Vacuumed table table=pending_closures13042026/11/09 11:52:43 INFO Vacuumed table table=pending_objects13052026/11/09 11:52:43 INFO Vacuumed table table=multipart_uploads13062026/11/09 11:52:43 INFO Vacuumed table table=closures13072026/11/09 11:52:43 INFO Vacuumed table table=objects1308--- PASS: TestGCMetrics (0.43s)1309=== CONT TestClientFallsBackToClosures13102026/11/09 11:52:43 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1311--- PASS: TestReadProxyNarinfo (0.53s)1312=== CONT TestPushWaitsForSweepHoldingRow1313=== NAME TestNARDeduplicationMetadataUploadBug1314 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1309307243/001/store/mcp8nrqx3bs06n2lfa77jlh8pvfm71a4-file2.txt13152026/11/09 11:52:43 INFO lead: acquired remote=192.0.2.1:123413162026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=013172026/11/09 11:52:43 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"1318--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.46s)1319=== CONT TestClientPushesUseOnePush13202026/11/09 11:52:43 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=013212026/11/09 11:52:43 INFO Vacuumed table table=pending_closures13222026/11/09 11:52:43 INFO Vacuumed table table=pending_objects13232026/11/09 11:52:43 INFO Vacuumed table table=multipart_uploads13242026/11/09 11:52:43 INFO Vacuumed table table=closures13252026/11/09 11:52:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13262026/11/09 11:52:43 INFO lead: acquired remote=192.0.2.1:123413272026/11/09 11:52:43 INFO lead: released remote=192.0.2.1:123413282026/11/09 11:52:43 INFO Vacuumed table table=objects1329--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.37s)1330=== CONT TestGCTaskStore_PhaseUpdates1331--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1332=== CONT TestProxyWriteTimeout1333=== RUN TestProxyWriteTimeout/narinfo1334=== PAUSE TestProxyWriteTimeout/narinfo1335=== RUN TestProxyWriteTimeout/1_GiB_nar1336=== PAUSE TestProxyWriteTimeout/1_GiB_nar1337=== RUN TestProxyWriteTimeout/10_GiB_nar1338=== PAUSE TestProxyWriteTimeout/10_GiB_nar1339=== RUN TestProxyWriteTimeout/unknown_size1340=== PAUSE TestProxyWriteTimeout/unknown_size1341=== CONT TestPinProtectsFromGC13422026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=013432026/11/09 11:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period13442026/11/09 11:52:43 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=013452026/11/09 11:52:43 INFO Vacuumed table table=pending_closures13462026/11/09 11:52:43 INFO Vacuumed table table=pending_objects13472026/11/09 11:52:43 INFO Vacuumed table table=multipart_uploads13482026/11/09 11:52:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LjI2NzM4MTUzLTJiODQtNDQ5OS1hNzI3LTQ4NGVjOGZhZmM4NXgxNzk0MjI1MTYyNzk4ODc1MTM3 parts=1213492026/11/09 11:52:43 INFO Vacuumed table table=closures1350--- PASS: TestSharedNarBothUploadsComplete (1.47s)1351=== CONT TestGCTaskStore_CompletedAllowsNewTask1352--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1353=== CONT TestClientSharedPathCommittedMidPush13542026/11/09 11:52:43 INFO Vacuumed table table=objects1355--- PASS: TestPushDedupSurvivesConcurrentGC (0.59s)1356=== CONT TestGracefulShutdownDrainsInflight13572026/11/09 11:52:43 INFO Starting HTTP server address=127.0.0.1:3319913582026/11/09 11:52:43 INFO Shutdown signal received, draining in-flight requests timeout=10s13592026/11/09 11:52:43 INFO Received push request method=POST path=/api/pushes13602026/11/09 11:52:43 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13612026/11/09 11:52:43 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13622026/11/09 11:52:43 WARN Failed to register uploaded object key=mcp8nrqx3bs06n2lfa77jlh8pvfm71a4.ls error="server returned 404: 404 page not found\n"13632026/11/09 11:52:43 INFO Signed narinfos id=2 count=113642026/11/09 11:52:43 INFO Uploading 1 narinfos1365--- PASS: TestPresentRefreshesOnlyStaleClosures (0.40s)1366=== CONT TestService_ReadScope_PublicByDefault13672026/11/09 11:52:43 INFO Received complete push request method=POST path=/api/pushes/2/complete13682026/11/09 11:52:43 WARN Failed to register uploaded object key=mcp8nrqx3bs06n2lfa77jlh8pvfm71a4.narinfo error="server returned 404: 404 page not found\n"13692026/11/09 11:52:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34703/oidc13702026/11/09 11:52:43 INFO lead: acquired remote=192.0.2.1:123413712026/11/09 11:52:43 INFO Completed push id=2 objects=3 duration=9.698368ms13722026/11/09 11:52:43 INFO Upload complete. (62ms)1373=== NAME TestNARDeduplicationMetadataUploadBug1374 metadata_upload_test.go:76: Retrieved narinfo from S3:1375 StorePath: /build/TestNARDeduplicationMetadataUploadBug1309307243/001/store/mcp8nrqx3bs06n2lfa77jlh8pvfm71a4-file2.txt1376 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1377 Compression: zstd1378 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1379 NarSize: 1601380 References: 1381 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1382 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1383 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1384 {"version":1,"root":{"type":"regular","size":44}}1385--- PASS: TestNARDeduplicationMetadataUploadBug (0.75s)1386=== CONT TestObjectStatsUpdatedOncePerCommit1387--- PASS: TestPresentReportsOnlyClosureRoots (0.37s)1388=== CONT TestClientIntegration1389--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1390=== CONT TestService_RequireScope_OIDC13912026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures13922026/11/09 11:52:43 WARN readiness check failed error="closed pool"1393--- PASS: TestService_readinessHandler (0.33s)1394=== CONT TestClientWithDependencies13952026/11/09 11:52:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1396--- PASS: TestGCBugBareHashReferences (0.64s)1397=== CONT TestGCTaskStore_Fail1398--- PASS: TestGCTaskStore_Fail (0.00s)1399=== CONT TestClientMultipleUploads1400--- PASS: TestService_healthCheckHandler (0.37s)1401=== CONT TestService_AuthMiddleware_OIDC14022026/11/09 11:52:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33759/oidc14032026/11/09 11:52:43 INFO Received uploads request method=POST path=/api/pending_closures14042026/11/09 11:52:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37939/oidc14052026/11/09 11:52:43 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccc0100000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LjAyNDRiOWI0LThjZDItNGY2NC1hZDIwLWIwZmZiMjU0MTNiOXgxNzk0MjI1MTYzNjM5MDc0MjI0 parts=21406--- PASS: TestCompleteMultipartUploadRetriesTransientFailure (0.57s)1407=== CONT TestObjectStatsTrigger14082026/11/09 11:52:43 INFO Aborted multipart uploads count=0 kept=014092026/11/09 11:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period14102026/11/09 11:52:43 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=014112026/11/09 11:52:43 INFO Vacuumed table table=pending_closures14122026/11/09 11:52:43 INFO Vacuumed table table=pending_objects14132026/11/09 11:52:43 INFO Vacuumed table table=multipart_uploads14142026/11/09 11:52:43 INFO Vacuumed table table=closures14152026/11/09 11:52:43 INFO Vacuumed table table=objects1416--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.43s)1417=== CONT TestClientCADerivations1418--- PASS: TestService_ReadScope_PublicByDefault (0.34s)1419=== CONT TestService_ReadAuthMiddleware1420=== NAME TestPinProtectsFromGC1421 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3776568965/001/store/q8p2ccmygphrp2km2sfpp7flzi19xwq5-pinned-file.txt1422 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3776568965/001/store/lvs6a08720s5grz089nzy4wgi5pmg079-unpinned-file.txt14232026/11/09 11:52:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14242026/11/09 11:52:43 WARN Refused reserved pin name=worker-x86_64-linux14252026/11/09 11:52:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14262026/11/09 11:52:43 INFO Received create pin request method=POST path=/api/pins/my-app14272026/11/09 11:52:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1428--- PASS: TestCreatePin_ReservedPins (0.70s)1429=== CONT TestCacheStatsHandler1430--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.60s)1431=== CONT TestClientErrorHandling1432=== RUN TestClientErrorHandling/InvalidStorePath1433=== PAUSE TestClientErrorHandling/InvalidStorePath1434=== RUN TestClientErrorHandling/InvalidAuthToken1435=== PAUSE TestClientErrorHandling/InvalidAuthToken1436=== RUN TestClientErrorHandling/ServerNotAvailable1437=== PAUSE TestClientErrorHandling/ServerNotAvailable1438=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1439--- PASS: TestObjectStatsUpdatedOncePerCommit (0.41s)1440=== CONT TestCacheConfigHandler1441=== RUN TestCacheConfigHandler/full_config,_no_issuer1442=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1443=== RUN TestCacheConfigHandler/no_cache_url_configured1444=== PAUSE TestCacheConfigHandler/no_cache_url_configured1445=== RUN TestCacheConfigHandler/no_signing_keys1446=== PAUSE TestCacheConfigHandler/no_signing_keys1447=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1448=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1449=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded14502026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes14512026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures14522026/11/09 11:52:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14532026/11/09 11:52:44 INFO Uploading q8p2ccmygphrp2km2sfpp7flzi19xwq5-pinned-file.txt (128B)14542026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures14552026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14562026/11/09 11:52:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14572026/11/09 11:52:44 WARN Failed to register uploaded object key=q8p2ccmygphrp2km2sfpp7flzi19xwq5.ls error="server returned 404: 404 page not found\n"14582026/11/09 11:52:44 INFO Signed narinfos id=1 count=114592026/11/09 11:52:44 INFO Uploading 1 narinfos14602026/11/09 11:52:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14612026/11/09 11:52:44 INFO Uploading zxlpwnkhdj6yl4g1q5xkvlkr4zs9365b-b (216B)14622026/11/09 11:52:44 INFO Uploading bphp6xizs4imncgkrmxnvx2ri4gvvfah-shared-dep (136B)1463=== NAME TestClientIntegration1464 client_integration_test.go:291: Created store path: /build/TestClientIntegration226790036/002/store/z363jhp0p3aczkhcjs2ahs1vd0ilvvws-test-file.txt14652026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14662026/11/09 11:52:44 WARN Failed to register uploaded object key=q8p2ccmygphrp2km2sfpp7flzi19xwq5.narinfo error="server returned 404: 404 page not found\n"14672026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes14682026/11/09 11:52:44 WARN Failed to register uploaded object key=bphp6xizs4imncgkrmxnvx2ri4gvvfah.ls error="server returned 404: 404 page not found\n"14692026/11/09 11:52:44 WARN Failed to register uploaded object key=znkg4h02akasmfg52mzjsdd45yjwfn6y.ls error="server returned 404: 404 page not found\n"14702026/11/09 11:52:44 WARN Failed to register uploaded object key=zxlpwnkhdj6yl4g1q5xkvlkr4zs9365b.ls error="server returned 404: 404 page not found\n"14712026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14722026/11/09 11:52:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14732026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/1xnz8d3qsmwvarvs0g5yvmsv600930s5k7xgmjbhdyz5vxsc06k0.nar.zst error="server returned 404: 404 page not found\n"14742026/11/09 11:52:44 INFO Signed narinfos id=1 count=214752026/11/09 11:52:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14762026/11/09 11:52:44 INFO Signed narinfos id=2 count=214772026/11/09 11:52:44 INFO Uploading 4 narinfos14782026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes14792026/11/09 11:52:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14802026/11/09 11:52:44 INFO Uploading psyapjhxjq95cb5qi5ify24f6i143krb-a (216B)14812026/11/09 11:52:44 INFO Uploading r7rjakhj0nw1pir8kwv6dqj3dcwkmwkb-shared-dep (136B)14822026/11/09 11:52:44 INFO Completed push id=1 objects=3 duration=6.567138ms14832026/11/09 11:52:44 INFO Upload complete. (68ms)14842026/11/09 11:52:44 WARN Failed to register uploaded object key=znkg4h02akasmfg52mzjsdd45yjwfn6y.narinfo error="server returned 404: 404 page not found\n"14852026/11/09 11:52:44 WARN Failed to register uploaded object key=bphp6xizs4imncgkrmxnvx2ri4gvvfah.narinfo error="server returned 404: 404 page not found\n"14862026/11/09 11:52:44 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14872026/11/09 11:52:44 INFO Uploading wmjvsgj102gh8sybaz2cclnbkf38821g-shared-dep (136B)14882026/11/09 11:52:44 WARN Failed to register uploaded object key=zxlpwnkhdj6yl4g1q5xkvlkr4zs9365b.narinfo error="server returned 404: 404 page not found\n"14892026/11/09 11:52:44 INFO Uploading 1bcdkc6003dja42ccznzhf6csgb5a472-top (224B)14902026/11/09 11:52:44 WARN Failed to register uploaded object key=rgpvazw5zs150a71riqlf8w9zy4xilvr.ls error="server returned 404: 404 page not found\n"14912026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/1gvhzl6kh1a3wz3bm34y3fnaayk49cgbnrf9ig5f0l52ggsn7kqx.nar.zst error="server returned 404: 404 page not found\n"14922026/11/09 11:52:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14932026/11/09 11:52:44 WARN Failed to register uploaded object key=bphp6xizs4imncgkrmxnvx2ri4gvvfah.narinfo error="server returned 404: 404 page not found\n"14942026/11/09 11:52:44 WARN Failed to register uploaded object key=psyapjhxjq95cb5qi5ify24f6i143krb.ls error="server returned 404: 404 page not found\n"14952026/11/09 11:52:44 WARN Failed to register uploaded object key=r7rjakhj0nw1pir8kwv6dqj3dcwkmwkb.ls error="server returned 404: 404 page not found\n"14962026/11/09 11:52:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14972026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14982026/11/09 11:52:44 WARN Failed to register uploaded object key=wmjvsgj102gh8sybaz2cclnbkf38821g.ls error="server returned 404: 404 page not found\n"14992026/11/09 11:52:44 WARN Failed to register uploaded object key=1bcdkc6003dja42ccznzhf6csgb5a472.ls error="server returned 404: 404 page not found\n"15002026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/0p0v61fxcbfz4r2sq4q186j952s5p7w188r07prpbrxz9fhpzrf7.nar.zst error="server returned 404: 404 page not found\n"15012026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15022026/11/09 11:52:44 INFO Signed narinfos id=1 count=315032026/11/09 11:52:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15042026/11/09 11:52:44 INFO Uploading 3 narinfos15052026/11/09 11:52:44 INFO Signed narinfos id=1 count=215062026/11/09 11:52:44 INFO Uploading 2 narinfos1507=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1508=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1509=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1510=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1511=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1512=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1513=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1514=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1515=== CONT TestService_AuthMiddleware_MTLSProxyHeader15162026/11/09 11:52:44 INFO Completed upload id=1 objects=6 duration=6.320375ms15172026/11/09 11:52:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15182026/11/09 11:52:44 INFO Completed upload id=2 objects=6 duration=1.670375ms1519=== NAME TestOrphanedObjectsGC1520 orphaned_objects_gc_test.go:287: GC Test Summary:15212026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/1/complete15222026/11/09 11:52:44 WARN Failed to register uploaded object key=rgpvazw5zs150a71riqlf8w9zy4xilvr.narinfo error="server returned 404: 404 page not found\n"1523 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A15242026/11/09 11:52:44 WARN Failed to register uploaded object key=1bcdkc6003dja42ccznzhf6csgb5a472.narinfo error="server returned 404: 404 page not found\n"1525 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B15262026/11/09 11:52:44 INFO Upload complete. (81ms)1527 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1528 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1529 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects15302026/11/09 11:52:44 WARN Failed to register uploaded object key=r7rjakhj0nw1pir8kwv6dqj3dcwkmwkb.narinfo error="server returned 404: 404 page not found\n"15312026/11/09 11:52:44 WARN Failed to register uploaded object key=psyapjhxjq95cb5qi5ify24f6i143krb.narinfo error="server returned 404: 404 page not found\n"1532--- PASS: TestOrphanedObjectsGC (0.70s)1533=== CONT TestServerTLSConfig1534=== RUN TestServerTLSConfig/no_client_CA1535=== PAUSE TestServerTLSConfig/no_client_CA1536=== RUN TestServerTLSConfig/missing_CA_file1537=== PAUSE TestServerTLSConfig/missing_CA_file1538=== RUN TestServerTLSConfig/not_a_PEM_file1539=== PAUSE TestServerTLSConfig/not_a_PEM_file1540=== CONT TestMultipartCleanup15412026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/1/complete15422026/11/09 11:52:44 WARN Failed to register uploaded object key=wmjvsgj102gh8sybaz2cclnbkf38821g.narinfo error="server returned 404: 404 page not found\n"1543=== NAME TestClientFallsBackToClosures1544 client_pushes_test.go:112: Retrieved narinfo from S3:1545 StorePath: /build/TestClientFallsBackToClosures3857783064/001/store/bphp6xizs4imncgkrmxnvx2ri4gvvfah-shared-dep1546 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1547 Compression: zstd1548 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821549 NarSize: 1361550 References: 1551 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1552 client_pushes_test.go:112: Retrieved narinfo from S3:1553 StorePath: /build/TestClientFallsBackToClosures3857783064/001/store/znkg4h02akasmfg52mzjsdd45yjwfn6y-a1554 URL: nar/1xnz8d3qsmwvarvs0g5yvmsv600930s5k7xgmjbhdyz5vxsc06k0.nar.zst1555 Compression: zstd1556 NarHash: sha256:1xnz8d3qsmwvarvs0g5yvmsv600930s5k7xgmjbhdyz5vxsc06k01557 NarSize: 2161558 References: /build/TestClientFallsBackToClosures3857783064/001/store/bphp6xizs4imncgkrmxnvx2ri4gvvfah-shared-dep1559 CA: text:sha256:172z284j1ch4m88j0dlb5736k9ranszqwhpbgpwpr1by1ycs574515602026/11/09 11:52:44 INFO Completed push id=1 objects=8 duration=7.305303ms15612026/11/09 11:52:44 INFO Upload complete. (69ms)15622026/11/09 11:52:44 INFO Completed push id=1 objects=6 duration=7.176522ms15632026/11/09 11:52:44 INFO Upload complete. (63ms)1564 client_pushes_test.go:112: Retrieved narinfo from S3:1565 StorePath: /build/TestClientFallsBackToClosures3857783064/001/store/zxlpwnkhdj6yl4g1q5xkvlkr4zs9365b-b1566 URL: nar/1xnz8d3qsmwvarvs0g5yvmsv600930s5k7xgmjbhdyz5vxsc06k0.nar.zst1567 Compression: zstd1568 NarHash: sha256:1xnz8d3qsmwvarvs0g5yvmsv600930s5k7xgmjbhdyz5vxsc06k01569 NarSize: 2161570 References: /build/TestClientFallsBackToClosures3857783064/001/store/bphp6xizs4imncgkrmxnvx2ri4gvvfah-shared-dep1571 CA: text:sha256:172z284j1ch4m88j0dlb5736k9ranszqwhpbgpwpr1by1ycs57451572=== NAME TestClientPushesUseOnePush1573 client_pushes_test.go:97: Retrieved narinfo from S3:1574 StorePath: /build/TestClientPushesUseOnePush3291540864/001/store/r7rjakhj0nw1pir8kwv6dqj3dcwkmwkb-shared-dep1575 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1576 Compression: zstd1577 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821578 NarSize: 1361579 References: 1580 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1581=== NAME TestClientSharedPathCommittedMidPush1582 client_integration_test.go:727: Retrieved narinfo from S3:1583 StorePath: /build/TestClientSharedPathCommittedMidPush2885988965/001/store/wmjvsgj102gh8sybaz2cclnbkf38821g-shared-dep1584 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1585 Compression: zstd1586 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821587 NarSize: 1361588 References: 1589 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1590=== NAME TestClientPushesUseOnePush1591 client_pushes_test.go:97: Retrieved narinfo from S3:1592 StorePath: /build/TestClientPushesUseOnePush3291540864/001/store/psyapjhxjq95cb5qi5ify24f6i143krb-a1593 URL: nar/1gvhzl6kh1a3wz3bm34y3fnaayk49cgbnrf9ig5f0l52ggsn7kqx.nar.zst1594 Compression: zstd1595 NarHash: sha256:1gvhzl6kh1a3wz3bm34y3fnaayk49cgbnrf9ig5f0l52ggsn7kqx1596 NarSize: 2161597 References: /build/TestClientPushesUseOnePush3291540864/001/store/r7rjakhj0nw1pir8kwv6dqj3dcwkmwkb-shared-dep1598 CA: text:sha256:1xy235wddmz326rp9kp723mh4zz9rpb06b95irg95alnf8wvd8rk1599--- PASS: TestClientFallsBackToClosures (0.60s)1600=== CONT TestService_AuthMiddleware1601=== NAME TestClientSharedPathCommittedMidPush1602 client_integration_test.go:727: Retrieved narinfo from S3:1603 StorePath: /build/TestClientSharedPathCommittedMidPush2885988965/001/store/1bcdkc6003dja42ccznzhf6csgb5a472-top1604 URL: nar/0p0v61fxcbfz4r2sq4q186j952s5p7w188r07prpbrxz9fhpzrf7.nar.zst1605 Compression: zstd1606 NarHash: sha256:0p0v61fxcbfz4r2sq4q186j952s5p7w188r07prpbrxz9fhpzrf71607 NarSize: 2241608 References: /build/TestClientSharedPathCommittedMidPush2885988965/001/store/wmjvsgj102gh8sybaz2cclnbkf38821g-shared-dep1609 CA: text:sha256:17xhlqw4cx0ifwzf4s5vp22iwd4925sjfzm0dxfq5b60l85bwiqy1610=== NAME TestClientPushesUseOnePush1611 client_pushes_test.go:97: Retrieved narinfo from S3:1612 StorePath: /build/TestClientPushesUseOnePush3291540864/001/store/rgpvazw5zs150a71riqlf8w9zy4xilvr-b1613 URL: nar/1gvhzl6kh1a3wz3bm34y3fnaayk49cgbnrf9ig5f0l52ggsn7kqx.nar.zst1614 Compression: zstd1615 NarHash: sha256:1gvhzl6kh1a3wz3bm34y3fnaayk49cgbnrf9ig5f0l52ggsn7kqx1616 NarSize: 2161617 References: /build/TestClientPushesUseOnePush3291540864/001/store/r7rjakhj0nw1pir8kwv6dqj3dcwkmwkb-shared-dep1618 CA: text:sha256:1xy235wddmz326rp9kp723mh4zz9rpb06b95irg95alnf8wvd8rk1619--- PASS: TestClientSharedPathCommittedMidPush (0.52s)1620=== CONT TestMetricsCommit1621--- PASS: TestClientPushesUseOnePush (0.55s)1622=== CONT TestService_NativeMTLS1623=== NAME TestClientMultipleUploads1624 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads3603146858/001/store/xb012np24hkg9nzfqdx2ss25mwhjcqqh-test-file-0.txt1625=== RUN TestService_RequireScope_OIDC/builder_may_write1626=== PAUSE TestService_RequireScope_OIDC/builder_may_write1627=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1628=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1629=== RUN TestService_RequireScope_OIDC/ops_may_admin1630=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1631=== RUN TestService_RequireScope_OIDC/ops_may_not_write1632=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1633=== RUN TestService_RequireScope_OIDC/reader_may_not_write1634=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1635=== RUN TestService_RequireScope_OIDC/static_token_may_admin1636=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1637=== RUN TestService_RequireScope_OIDC/static_token_may_write1638=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1639=== RUN TestService_RequireScope_OIDC/reader_may_read1640=== PAUSE TestService_RequireScope_OIDC/reader_may_read1641=== RUN TestService_RequireScope_OIDC/writer_implies_read1642=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1643=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1644=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1645=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1646=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1647=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1648=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1649=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1650=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1651=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1652=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1653=== CONT TestMetricsInventory1654=== NAME TestClientMultipleUploads1655 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads3603146858/001/store/inlc0p57w0nmx4gkjbfsiza77kah2jcr-test-file-1.txt1656=== NAME TestClientWithDependencies1657 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies3256925340/001/store/iypyls0yfgv6f5hgxajmj15hkgdd1jxs-test-script16582026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes16592026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes16602026/11/09 11:52:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16612026/11/09 11:52:44 INFO Uploading lvs6a08720s5grz089nzy4wgi5pmg079-unpinned-file.txt (128B)16622026/11/09 11:52:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16632026/11/09 11:52:44 INFO Uploading z363jhp0p3aczkhcjs2ahs1vd0ilvvws-test-file.txt (152B)16642026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16652026/11/09 11:52:44 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16662026/11/09 11:52:44 WARN Failed to register uploaded object key=lvs6a08720s5grz089nzy4wgi5pmg079.ls error="server returned 404: 404 page not found\n"16672026/11/09 11:52:44 INFO Signed narinfos id=2 count=116682026/11/09 11:52:44 INFO Uploading 1 narinfos16692026/11/09 11:52:44 WARN Failed to register uploaded object key=z363jhp0p3aczkhcjs2ahs1vd0ilvvws.ls error="server returned 404: 404 page not found\n"16702026/11/09 11:52:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16712026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1672--- PASS: TestObjectStatsTrigger (0.31s)1673=== CONT TestPendingCleanupUsesOneCutoff16742026/11/09 11:52:44 INFO Signed narinfos id=1 count=116752026/11/09 11:52:44 INFO Uploading 1 narinfos16762026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/2/complete16772026/11/09 11:52:44 WARN Failed to register uploaded object key=lvs6a08720s5grz089nzy4wgi5pmg079.narinfo error="server returned 404: 404 page not found\n"16782026/11/09 11:52:44 INFO Completed push id=2 objects=3 duration=2.388641ms16792026/11/09 11:52:44 INFO Upload complete. (57ms)16802026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/1/complete16812026/11/09 11:52:44 WARN Failed to register uploaded object key=z363jhp0p3aczkhcjs2ahs1vd0ilvvws.narinfo error="server returned 404: 404 page not found\n"16822026/11/09 11:52:44 INFO Completed push id=1 objects=3 duration=7.900929ms16832026/11/09 11:52:44 INFO Upload complete. (68ms)1684=== NAME TestClientWithDependencies1685 client_integration_test.go:662: Found 1 dependencies (including self)1686=== NAME TestClientMultipleUploads1687 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads3603146858/001/store/169qs6mbw0qdib4gkpmhk8k94b24rsyd-test-file-2.txt1688--- PASS: TestService_ReadAuthMiddleware (0.25s)1689=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed16902026/11/09 11:52:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures16912026/11/09 11:52:44 INFO Garbage collection started16922026/11/09 11:52:44 INFO All 1 paths already cached1693=== NAME TestClientIntegration1694 client_integration_test.go:317: Retrieved narinfo from S3:1695 StorePath: /build/TestClientIntegration226790036/002/store/z363jhp0p3aczkhcjs2ahs1vd0ilvvws-test-file.txt1696 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1697 Compression: zstd1698 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11699 NarSize: 1521700 References: 1701 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11702 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1703 client_integration_test.go:318: Decompressed .ls content (64 bytes):1704 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}17052026/11/09 11:52:44 INFO Aborted multipart uploads count=0 kept=01706--- PASS: TestCacheStatsHandler (0.25s)1707=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed17082026/11/09 11:52:44 WARN Force mode enabled - objects will be deleted immediately without grace period17092026/11/09 11:52:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17102026/11/09 11:52:44 WARN mTLS auth: bound subjects configured but subject DN unavailable17112026/11/09 11:52:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1712--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.23s)1713=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost17142026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes17152026/11/09 11:52:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17162026/11/09 11:52:44 INFO Uploading iypyls0yfgv6f5hgxajmj15hkgdd1jxs-test-script (136B)17172026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes17182026/11/09 11:52:44 WARN Failed to register uploaded object key=iypyls0yfgv6f5hgxajmj15hkgdd1jxs.ls error="server returned 404: 404 page not found\n"17192026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17202026/11/09 11:52:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17212026/11/09 11:52:44 WARN Failed to register uploaded object key=log/n0alsf5z30ylk363fgmzzbpx7j31ik8w-test-script.drv error="server returned 404: 404 page not found\n"17222026/11/09 11:52:44 INFO Signed narinfos id=1 count=117232026/11/09 11:52:44 INFO Uploading 1 narinfos17242026/11/09 11:52:44 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17252026/11/09 11:52:44 INFO Uploading 169qs6mbw0qdib4gkpmhk8k94b24rsyd-test-file-2.txt (160B)17262026/11/09 11:52:44 INFO Uploading xb012np24hkg9nzfqdx2ss25mwhjcqqh-test-file-0.txt (160B)17272026/11/09 11:52:44 INFO Uploading inlc0p57w0nmx4gkjbfsiza77kah2jcr-test-file-1.txt (160B)1728=== NAME TestClientCADerivations1729 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1340376511/001/store/lygphclgps39r6ysfx7xra2g2hqp8cvv-ca-test17302026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/1/complete17312026/11/09 11:52:44 WARN Failed to register uploaded object key=iypyls0yfgv6f5hgxajmj15hkgdd1jxs.narinfo error="server returned 404: 404 page not found\n"17322026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures17332026/11/09 11:52:44 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=017342026/11/09 11:52:44 WARN Failed to register uploaded object key=inlc0p57w0nmx4gkjbfsiza77kah2jcr.ls error="server returned 404: 404 page not found\n"17352026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17362026/11/09 11:52:44 WARN Failed to register uploaded object key=xb012np24hkg9nzfqdx2ss25mwhjcqqh.ls error="server returned 404: 404 page not found\n"17372026/11/09 11:52:44 WARN Failed to register uploaded object key=169qs6mbw0qdib4gkpmhk8k94b24rsyd.ls error="server returned 404: 404 page not found\n"17382026/11/09 11:52:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17392026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17402026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17412026/11/09 11:52:44 INFO Signed narinfos id=1 count=317422026/11/09 11:52:44 INFO Uploading 3 narinfos17432026/11/09 11:52:44 INFO Completed push id=1 objects=4 duration=5.339667ms17442026/11/09 11:52:44 INFO Upload complete. (57ms)17452026/11/09 11:52:44 INFO Vacuumed table table=pending_closures1746=== NAME TestClientWithDependencies1747 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3256925340/001/store) requires matching store prefix17482026/11/09 11:52:44 WARN Failed to register uploaded object key=inlc0p57w0nmx4gkjbfsiza77kah2jcr.narinfo error="server returned 404: 404 page not found\n"17492026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/1/complete17502026/11/09 11:52:44 WARN Failed to register uploaded object key=xb012np24hkg9nzfqdx2ss25mwhjcqqh.narinfo error="server returned 404: 404 page not found\n"17512026/11/09 11:52:44 WARN Failed to register uploaded object key=169qs6mbw0qdib4gkpmhk8k94b24rsyd.narinfo error="server returned 404: 404 page not found\n"1752--- PASS: TestClientWithDependencies (0.57s)1753=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed17542026/11/09 11:52:44 INFO Completed push id=1 objects=9 duration=6.219595ms17552026/11/09 11:52:44 INFO Upload complete. (62ms)1756=== NAME TestClientMultipleUploads1757 client_integration_test.go:416: Uploaded 3 paths in 95.452776ms17582026/11/09 11:52:44 INFO Vacuumed table table=pending_objects1759--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.24s)1760=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed17612026/11/09 11:52:44 INFO Vacuumed table table=multipart_uploads17622026/11/09 11:52:44 INFO Vacuumed table table=closures17632026/11/09 11:52:44 INFO Vacuumed table table=objects17642026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures1765--- PASS: TestClientMultipleUploads (0.56s)1766=== CONT TestPush_RejectsBadRequests/bad_root17672026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes1768=== CONT TestPush_RejectsBadRequests/no_roots17692026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes1770=== CONT TestPush_RejectsBadRequests/root_not_in_objects17712026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes1772=== CONT TestPush_RejectsBadRequests/no_objects17732026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes1774=== CONT TestIsValidUploadKey/narinfo1775=== CONT TestIsValidUploadKey/realisation_plus_in_output1776--- PASS: TestPush_RejectsBadRequests (0.44s)1777 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1778 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1779 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1780 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1781=== CONT TestIsValidUploadKey/unknown_type1782=== CONT TestIsValidUploadKey/empty_key1783=== CONT TestIsValidUploadKey/absolute1784=== CONT TestIsValidUploadKey/traversal_nar1785=== CONT TestIsValidUploadKey/traversal1786=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1787=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1788=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1789=== CONT TestIsValidUploadKey/index.html1790=== CONT TestIsValidUploadKey/nix-cache-info1791=== CONT TestIsValidUploadKey/build_log_home-manager_file1792=== CONT TestIsValidUploadKey/realisation1793=== CONT TestIsValidUploadKey/build_log_equals1794=== CONT TestIsValidUploadKey/build_log_question_mark1795=== CONT TestIsValidUploadKey/build_log_plus_in_name1796=== CONT TestIsValidUploadKey/nar_plain1797=== CONT TestIsValidUploadKey/build_log1798=== CONT TestIsValidUploadKey/listing1799=== CONT TestIsValidUploadKey/nar_xz1800=== CONT TestIsValidUploadKey/nar_zst1801=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18022026/11/09 11:52:44 INFO Received uploads request method=POST path=/1803--- PASS: TestIsValidUploadKey (0.00s)1804 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1805 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1806 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1807 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1808 --- PASS: TestIsValidUploadKey/absolute (0.00s)1809 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1810 --- PASS: TestIsValidUploadKey/traversal (0.00s)1811 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1812 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1813 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1814 --- PASS: TestIsValidUploadKey/index.html (0.00s)1815 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1816 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1817 --- PASS: TestIsValidUploadKey/realisation (0.00s)1818 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1819 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1820 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1821 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1822 --- PASS: TestIsValidUploadKey/build_log (0.00s)1823 --- PASS: TestIsValidUploadKey/listing (0.00s)1824 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1825 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1826=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18272026/11/09 11:52:44 INFO Received request for more parts method=POST path=/1828=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18292026/11/09 11:52:44 INFO Received complete multipart upload request method=POST path=/1830=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18312026/11/09 11:52:44 INFO Received uploads request method=POST path=/1832--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1833 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1834 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1835 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1836 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1837=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1838=== NAME TestClientCADerivations1839 client_ca_test.go:139: Found 1 dependencies (including self)18402026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes18412026/11/09 11:52:44 INFO Object in database but missing from S3 key=z363jhp0p3aczkhcjs2ahs1vd0ilvvws.ls18422026/11/09 11:52:44 WARN Found objects in DB but missing from S3, will re-upload count=118432026/11/09 11:52:44 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1844--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.23s)1845=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18462026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/2/complete18472026/11/09 11:52:44 WARN Failed to register uploaded object key=z363jhp0p3aczkhcjs2ahs1vd0ilvvws.ls error="server returned 404: 404 page not found\n"18482026/11/09 11:52:44 INFO Completed push id=2 objects=3 duration=2.25256ms18492026/11/09 11:52:44 INFO Upload complete. (49ms)1850=== NAME TestClientIntegration1851 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1852 client_integration_test.go:335: Decompressed .ls content (49 bytes):1853 {"version":1,"root":{"type":"regular","size":39}}18542026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes1855--- PASS: TestPushWaitsForSweepHoldingRow (0.83s)1856=== CONT TestPendingClosureWriteTimeout/empty1857=== CONT TestPendingClosureWriteTimeout/670k_objects1858=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18592026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/1/complete18602026/11/09 11:52:44 INFO Completed push id=1 objects=4 duration=8.06809ms18612026/11/09 11:52:44 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18622026/11/09 11:52:44 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1863--- PASS: TestService_NativeMTLS (0.25s)1864=== CONT TestPendingClosureWriteTimeout/400_objects1865=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18662026/11/09 11:52:44 INFO Received uploads request method=POST path=/18672026/11/09 11:52:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18682026/11/09 11:52:44 INFO Completed upload id=2 objects=2 duration=2.217ms1869--- PASS: TestMetricsCommit (0.26s)1870=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18712026/11/09 11:52:44 INFO Received request for more parts method=POST path=/18722026/11/09 11:52:44 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1873--- PASS: TestService_AuthMiddleware (0.28s)1874=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18752026/11/09 11:52:44 INFO Received complete multipart upload request method=POST path=/18762026/11/09 11:52:44 INFO Received cleanup request method=DELETE path=/api/pending_closures18772026/11/09 11:52:44 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket86/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18782026/11/09 11:52:44 INFO Aborted multipart uploads count=0 kept=118792026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes18802026/11/09 11:52:44 INFO Received cleanup request method=DELETE path=/api/pending_closures18812026/11/09 11:52:44 INFO Aborted multipart uploads count=1 kept=018822026/11/09 11:52:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18832026/11/09 11:52:44 INFO Uploading lygphclgps39r6ysfx7xra2g2hqp8cvv-ca-test (144B)18842026/11/09 11:52:44 INFO Received push request method=POST path=/api/pushes1885--- PASS: TestMultipartCleanup (0.32s)1886=== CONT TestIsValidCachePath/narinfo1887=== CONT TestIsValidCachePath/index.html1888=== CONT TestIsValidCachePath/short_hash1889=== CONT TestIsValidCachePath/wrong_extension1890=== CONT TestIsValidCachePath/leading_slash1891=== CONT TestIsValidCachePath/empty1892=== CONT TestIsValidCachePath/random_path1893=== CONT TestIsValidCachePath/invalid_char_u1894=== CONT TestIsValidCachePath/invalid_char_e1895=== CONT TestIsValidCachePath/traversal_in_middle1896=== CONT TestIsValidCachePath/traversal_parent1897=== CONT TestIsValidCachePath/nar_uncompressed1898=== CONT TestIsValidCachePath/nix-cache-info1899=== CONT TestIsValidCachePath/realisation1900=== CONT TestIsValidCachePath/log1901=== CONT TestIsValidCachePath/ls1902=== CONT TestIsValidCachePath/nar_xz1903=== CONT TestIsValidCachePath/nar_bz21904=== CONT TestIsValidCachePath/nar_zst1905=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1906--- PASS: TestIsValidCachePath (0.00s)1907 --- PASS: TestIsValidCachePath/narinfo (0.00s)1908 --- PASS: TestIsValidCachePath/index.html (0.00s)1909 --- PASS: TestIsValidCachePath/short_hash (0.00s)1910 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1911 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1912 --- PASS: TestIsValidCachePath/empty (0.00s)1913 --- PASS: TestIsValidCachePath/random_path (0.00s)1914 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1915 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1916 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1917 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1918 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1919 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1920 --- PASS: TestIsValidCachePath/realisation (0.00s)1921 --- PASS: TestIsValidCachePath/log (0.00s)1922 --- PASS: TestIsValidCachePath/ls (0.00s)1923 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1924 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1925 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1926 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1927=== CONT TestParseSingleRange/none1928=== CONT TestParseSingleRange/single_byte1929=== CONT TestParseSingleRange/suffix_exceeds_size1930=== CONT TestParseSingleRange/suffix1931=== CONT TestParseSingleRange/end_clamped_to_size1932=== CONT TestParseSingleRange/open-ended1933=== CONT TestParseSingleRange/start_past_EOF1934=== CONT TestParseSingleRange/closed1935=== CONT TestParseSingleRange/multi-range_ignored1936=== CONT TestParseSingleRange/unknown_unit1937=== CONT TestParseSingleRange/start_far_past_EOF1938=== CONT TestParseSingleRange/malformed_end_before_start1939=== CONT TestParseSingleRange/malformed_no_dash1940=== CONT TestParseSingleRange/malformed_both_empty1941--- PASS: TestParseSingleRange (0.00s)1942 --- PASS: TestParseSingleRange/none (0.00s)1943 --- PASS: TestParseSingleRange/single_byte (0.00s)1944 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1945 --- PASS: TestParseSingleRange/suffix (0.00s)1946 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1947 --- PASS: TestParseSingleRange/open-ended (0.00s)1948 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1949 --- PASS: TestParseSingleRange/closed (0.00s)1950 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1951 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1952 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1953 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1954 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1955 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1956=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale19572026/11/09 11:52:44 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19582026/11/09 11:52:44 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19592026/11/09 11:52:44 WARN Failed to register uploaded object key=lygphclgps39r6ysfx7xra2g2hqp8cvv.ls error="server returned 404: 404 page not found\n"19602026/11/09 11:52:44 WARN Failed to register uploaded object key=log/cn0sf2rg620nmm0qzhb5ss2hg3g231wk-ca-test.drv error="server returned 404: 404 page not found\n"19612026/11/09 11:52:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19622026/11/09 11:52:44 INFO Signed narinfos id=1 count=119632026/11/09 11:52:44 INFO Uploading 1 narinfos19642026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/3/complete19652026/11/09 11:52:44 WARN Failed to register uploaded object key=z363jhp0p3aczkhcjs2ahs1vd0ilvvws.ls error="server returned 404: 404 page not found\n"1966--- PASS: TestMetricsInventory (0.29s)1967=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh19682026/11/09 11:52:44 INFO Completed push id=3 objects=3 duration=1.695915ms19692026/11/09 11:52:44 INFO Received complete push request method=POST path=/api/pushes/1/complete19702026/11/09 11:52:44 WARN Failed to register uploaded object key=lygphclgps39r6ysfx7xra2g2hqp8cvv.narinfo error="server returned 404: 404 page not found\n"19712026/11/09 11:52:44 INFO Upload complete. (49ms)1972=== NAME TestClientIntegration1973 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1974 client_integration_test.go:352: Decompressed .ls content (49 bytes):1975 {"version":1,"root":{"type":"regular","size":39}}1976 client_integration_test.go:363: Testing garbage collection...1977=== CONT TestResolveDBConnectionString/flag_wins1978=== CONT TestResolveDBConnectionString/file_when_flag_empty1979=== CONT TestResolveDBConnectionString/missing_file_is_an_error1980=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1981=== CONT TestResolveDBConnectionString/nothing_configured1982=== CONT TestRetryableCompletionError/deadline_exceeded1983=== CONT TestRetryableCompletionError/context_canceled1984=== CONT TestRetryableCompletionError/throttled1985=== CONT TestRetryableCompletionError/access_denied1986=== CONT TestRetryableCompletionError/bad_gateway1987=== CONT TestRetryableCompletionError/nil1988=== CONT TestRetryableCompletionError/invalid_part1989=== CONT TestRetryableCompletionError/no_such_upload1990=== CONT TestRetryableCompletionError/transport_failure1991=== CONT TestRetryableCompletionError/degraded_quorum1992--- PASS: TestRetryableCompletionError (0.00s)1993 --- PASS: TestRetryableCompletionError/deadline_exceeded (0.00s)1994 --- PASS: TestRetryableCompletionError/context_canceled (0.00s)1995 --- PASS: TestRetryableCompletionError/throttled (0.00s)1996 --- PASS: TestRetryableCompletionError/access_denied (0.00s)1997 --- PASS: TestRetryableCompletionError/bad_gateway (0.00s)1998 --- PASS: TestRetryableCompletionError/nil (0.00s)1999 --- PASS: TestRetryableCompletionError/invalid_part (0.00s)2000 --- PASS: TestRetryableCompletionError/no_such_upload (0.00s)2001 --- PASS: TestRetryableCompletionError/transport_failure (0.00s)2002 --- PASS: TestRetryableCompletionError/degraded_quorum (0.00s)2003=== CONT TestGCEndsOnShutdown/before_the_run2004--- PASS: TestResolveDBConnectionString (0.00s)2005 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2006 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2007 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2008 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2009 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)20102026/11/09 11:52:44 INFO Completed push id=1 objects=4 duration=5.869891ms20112026/11/09 11:52:44 INFO Upload complete. (95ms)20122026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures2013=== NAME TestClientCADerivations2014 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1340376511/001/store/lygphclgps39r6ysfx7xra2g2hqp8cvv-ca-test2015 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2016 Compression: zstd2017 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2018 NarSize: 1442019 References: 2020 Deriver: /build/TestClientCADerivations1340376511/001/store/cn0sf2rg620nmm0qzhb5ss2hg3g231wk-ca-test.drv2021 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2022 client_ca_test.go:185: Checking for realisation files in S3...2023 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2024 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2025=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete20262026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures20272026/11/09 11:52:44 INFO Received cleanup request method=DELETE path=/api/pending_closures20282026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures20292026/11/09 11:52:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures20302026/11/09 11:52:44 INFO Garbage collection started20312026/11/09 11:52:44 INFO Aborted multipart uploads count=0 kept=020322026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures20332026/11/09 11:52:44 WARN Force mode enabled - objects will be deleted immediately without grace period20342026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures20352026/11/09 11:52:44 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=020362026/11/09 11:52:44 INFO Vacuumed table table=pending_closures20372026/11/09 11:52:44 INFO Vacuumed table table=pending_objects20382026/11/09 11:52:44 INFO Vacuumed table table=multipart_uploads20392026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures20402026/11/09 11:52:44 INFO Vacuumed table table=closures20412026/11/09 11:52:44 INFO Vacuumed table table=objects2042=== NAME TestClientCADerivations2043 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2044 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2045 error: binary cache 's3://bucket81?endpoint=http://localhost:33853®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1340376511/001/store'2046 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12047--- PASS: TestClientCADerivations (0.64s)2048=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark20492026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures20502026/11/09 11:52:44 INFO lead: released remote=192.0.2.1:12342051--- PASS: TestLeadEndsOnShutdown (1.47s)2052=== CONT TestProxyWriteTimeout/narinfo2053=== CONT TestProxyWriteTimeout/10_GiB_nar2054=== CONT TestProxyWriteTimeout/unknown_size2055=== CONT TestProxyWriteTimeout/1_GiB_nar2056--- PASS: TestProxyWriteTimeout (0.00s)2057 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2058 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2059 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2060 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2061=== CONT TestClientErrorHandling/InvalidStorePath20622026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures20632026/11/09 11:52:44 INFO Aborted multipart uploads count=0 kept=020642026/11/09 11:52:44 WARN Force mode enabled - objects will be deleted immediately without grace period20652026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures20662026/11/09 11:52:44 INFO Aborted multipart uploads count=0 kept=020672026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures20682026/11/09 11:52:44 WARN Force mode enabled - objects will be deleted immediately without grace period20692026/11/09 11:52:44 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=020702026/11/09 11:52:44 INFO Vacuumed table table=pending_closures20712026/11/09 11:52:44 INFO Vacuumed table table=pending_objects20722026/11/09 11:52:44 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=020732026/11/09 11:52:44 INFO Vacuumed table table=multipart_uploads20742026/11/09 11:52:44 INFO Vacuumed table table=closures20752026/11/09 11:52:44 INFO Vacuumed table table=pending_closures20762026/11/09 11:52:44 INFO Vacuumed table table=pending_objects20772026/11/09 11:52:44 INFO Vacuumed table table=multipart_uploads20782026/11/09 11:52:44 INFO Vacuumed table table=closures20792026/11/09 11:52:44 INFO Vacuumed table table=objects20802026/11/09 11:52:44 INFO Vacuumed table table=objects2081=== CONT TestClientErrorHandling/InvalidAuthToken2082--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2083 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.33s)2084 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.36s)2085=== CONT TestClientErrorHandling/ServerNotAvailable2086=== CONT TestCacheConfigHandler/full_config,_no_issuer2087=== CONT TestCacheConfigHandler/no_signing_keys2088=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2089=== CONT TestCacheConfigHandler/no_cache_url_configured2090--- PASS: TestCacheConfigHandler (0.00s)2091 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2092 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2093 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2094 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2095=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2096=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20972026/11/09 11:52:44 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]2098=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2099=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21002026/11/09 11:52:44 WARN Authentication failed token_preview=eyJhbGciOi...LNCg6f08xg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2101=== CONT TestServerTLSConfig/no_client_CA2102=== CONT TestServerTLSConfig/not_a_PEM_file2103=== CONT TestServerTLSConfig/missing_CA_file2104--- PASS: TestServerTLSConfig (0.00s)2105 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2106 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2107 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2108=== CONT TestService_RequireScope_OIDC/builder_may_write2109--- PASS: TestService_AuthMiddleware_OIDC (0.30s)2110 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2111 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2112 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2113 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2114=== CONT TestService_RequireScope_OIDC/reader_may_read2115=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2116=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21172026/11/09 11:52:44 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]2118=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2119=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2120=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2121=== CONT TestService_RequireScope_OIDC/writer_implies_read2122=== CONT TestService_RequireScope_OIDC/ops_may_admin2123=== CONT TestService_RequireScope_OIDC/ops_may_not_write2124=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2125=== CONT TestService_RequireScope_OIDC/reader_may_not_write2126=== CONT TestService_RequireScope_OIDC/static_token_may_write2127=== CONT TestService_RequireScope_OIDC/static_token_may_admin2128--- PASS: TestService_RequireScope_OIDC (0.48s)2129 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2130 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2131 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2132 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2133 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2134 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2135 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2136 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2137 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2138 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2139 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2140 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2141 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2142 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)21432026/11/09 11:52:44 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/present21442026/11/09 11:52:44 INFO Aborted multipart uploads count=0 kept=021452026/11/09 11:52:44 WARN Force mode enabled - objects will be deleted immediately without grace period21462026/11/09 11:52:44 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:33853/bucket104/?delete=\": context canceled"21472026/11/09 11:52:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21482026/11/09 11:52:44 INFO Aborted multipart uploads count=0 kept=021492026/11/09 11:52:44 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0Ljk1OWQ3MzA1LTRmYTQtNDlhZS05MTc5LTg5MTkzNmRlMDE5YngxNzk0MjI1MTY0NDMwNzQ5NzYy parts=1021502026/11/09 11:52:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21512026/11/09 11:52:44 WARN Force mode enabled - objects will be deleted immediately without grace period21522026/11/09 11:52:44 INFO Completed upload id=1 objects=3 duration=2.32056ms21532026/11/09 11:52:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2154--- PASS: TestGCEndsOnShutdown (0.00s)2155 --- PASS: TestGCEndsOnShutdown/before_the_run (0.27s)2156 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.32s)2157 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.25s)21582026/11/09 11:52:44 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LjY1YjhkZmE4LWNmMzktNDNjZC1hZGY3LTZkNjg1YzY0NjIyMXgxNzk0MjI1MTY0NDU2ODY2Mzcw parts=1021592026/11/09 11:52:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21602026/11/09 11:52:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21612026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures21622026/11/09 11:52:44 INFO Completed upload id=1 objects=3 duration=2.568903ms21632026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures21642026/11/09 11:52:44 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21652026/11/09 11:52:44 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21662026/11/09 11:52:44 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LjU0Njk2YjdjLTFkMmEtNGJlMS05OTdlLWZiNmUyOTYwMDkzYXgxNzk0MjI1MTY0NDc3ODg0ODk0 parts=1021672026/11/09 11:52:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21682026/11/09 11:52:44 INFO lead: released remote=192.0.2.1:123421692026/11/09 11:52:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21702026/11/09 11:52:44 INFO Completed upload id=1 objects=3 duration=3.154547ms21712026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures21722026/11/09 11:52:44 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LjI3NmIzMGRmLTE5NWYtNGM2NC1hMDdlLTJlYjM4NGU5ODQ2N3gxNzk0MjI1MTY0NTAwNjQxNDM0 parts=1021732026/11/09 11:52:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21742026/11/09 11:52:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21752026/11/09 11:52:44 INFO Completed upload id=1 objects=3 duration=2.579643ms21762026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures21772026/11/09 11:52:44 WARN Request failed, retrying attempt=2 backoff=185.175039ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21782026/11/09 11:52:44 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LmRkM2JhOTVmLTcwYjYtNDFiYS05MzQ4LWY5MzRmNjczMzM2MngxNzk0MjI1MTY0NTIxMzkyNjU1 parts=1021792026/11/09 11:52:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21802026/11/09 11:52:44 INFO Completed upload id=1 objects=3 duration=2.842965ms21812026/11/09 11:52:44 INFO lead: acquired remote=192.0.2.1:123421822026/11/09 11:52:44 INFO Received uploads request method=POST path=/api/pending_closures21832026/11/09 11:52:44 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21842026/11/09 11:52:44 WARN Found objects in DB but missing from S3, will re-upload count=121852026/11/09 11:52:44 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21862026/11/09 11:52:44 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2187--- PASS: TestDeleteClosuresRacingPins (1.60s)21882026/11/09 11:52:44 WARN Request failed, retrying attempt=3 backoff=374.239142ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21892026/11/09 11:52:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21902026/11/09 11:52:45 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LmFlMDUzOGZhLWRjNzYtNDViMC1hMTlkLTYzYzA0ZDk1M2I4ZHgxNzk0MjI1MTY0Nzc3OTQ0ODYw parts=1021912026/11/09 11:52:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21922026/11/09 11:52:45 INFO Completed upload id=2 objects=3 duration=834.887µs21932026/11/09 11:52:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21942026/11/09 11:52:45 INFO Received uploads request method=POST path=/api/pending_closures21952026/11/09 11:52:45 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=MGVhOGI2NDctMjJiMS00M2VhLTg5Y2ItZmM3NjRkOTM0OWI0LjhmNjAxZjMyLWUwMTctNDdlMC1hZWVmLTlkMmU3YzkwYjJhNngxNzk0MjI1MTY0Nzk2NzIwMTI1 parts=1021962026/11/09 11:52:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21972026/11/09 11:52:45 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21982026/11/09 11:52:45 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo21992026/11/09 11:52:45 INFO Completed upload id=2 objects=3 duration=793.047µs22002026/11/09 11:52:45 INFO Received uploads request method=POST path=/api/pending_closures22012026/11/09 11:52:45 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst22022026/11/09 11:52:45 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2203--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.00s)2204 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (0.62s)2205 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.57s)2206 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.60s)2207 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (0.87s)2208 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (0.88s)2209--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2210 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.73s)2211 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.75s)2212--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2213 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2214 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2215 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.82s)2216=== NAME TestOrphanedObjectsGCStressTest2217 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2218 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion22192026/11/09 11:52:45 WARN Request failed, retrying attempt=4 backoff=840.087488ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2220--- PASS: TestPendingClosureWriteTimeout (0.00s)2221 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2222 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2223 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2224 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.08s)2225=== NAME TestOrphanedObjectsGCStressTest2226 orphaned_objects_gc_test.go:503: Stress test completed successfully:2227 orphaned_objects_gc_test.go:504: - Active objects preserved: 202228 orphaned_objects_gc_test.go:505: - Objects deleted: 2102229 orphaned_objects_gc_test.go:506: - Total GC'd: 2102230--- PASS: TestOrphanedObjectsGCStressTest (2.57s)22312026/11/09 11:52:45 INFO lead: released remote=192.0.2.1:12342232--- PASS: TestLeadElectsOneAndHandsOver (2.71s)22332026/11/09 11:52:46 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022342026/11/09 11:52:46 INFO Received create pin request method=POST path=/api/pins/myapp22352026/11/09 11:52:46 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3776568965/001/store/q8p2ccmygphrp2km2sfpp7flzi19xwq5-pinned-file.txt narinfo_key=q8p2ccmygphrp2km2sfpp7flzi19xwq5.narinfo22362026/11/09 11:52:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures22372026/11/09 11:52:46 INFO Garbage collection started22382026/11/09 11:52:46 INFO Aborted multipart uploads count=0 kept=022392026/11/09 11:52:46 WARN Force mode enabled - objects will be deleted immediately without grace period22402026/11/09 11:52:46 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=022412026/11/09 11:52:46 INFO Vacuumed table table=pending_closures22422026/11/09 11:52:46 INFO Vacuumed table table=pending_objects22432026/11/09 11:52:46 INFO Vacuumed table table=multipart_uploads22442026/11/09 11:52:46 INFO Vacuumed table table=closures22452026/11/09 11:52:46 INFO Vacuumed table table=objects22462026/11/09 11:52:46 WARN Request failed, retrying attempt=5 backoff=1.631024526s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22472026/11/09 11:52:46 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02248=== NAME TestClientIntegration2249 client_integration_test.go:370: Objects in database after GC:2250 client_integration_test.go:370: Successfully deleted all objects with GC --force2251--- PASS: TestClientIntegration (2.82s)2252--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.73s)22532026/11/09 11:52:47 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-config22542026/11/09 11:52:47 WARN Request failed, retrying attempt=2 backoff=192.616538ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22552026/11/09 11:52:47 WARN Rate limiter enabled after throttle name=s3-test rate=522562026/11/09 11:52:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2257=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2258 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102259 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002260--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.89s)22612026/11/09 11:52:48 WARN Request failed, retrying attempt=3 backoff=404.250804ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2262=== NAME TestPinProtectsFromGC2263 client_integration_test.go:887: Pin successfully protected closure from garbage collection2264--- PASS: TestPinProtectsFromGC (4.66s)2265--- PASS: TestConnectWaitsForAPeerMigration (5.12s)22662026/11/09 11:52:48 WARN Request failed, retrying attempt=4 backoff=865.861417ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22672026/11/09 11:52:49 WARN Request failed, retrying attempt=5 backoff=1.720893469s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22682026/11/09 11:52:50 INFO Aborted multipart uploads count=1 kept=022692026/11/09 11:52:50 INFO Received cleanup request method=DELETE path=/api/pending_closures22702026/11/09 11:52:50 INFO Aborted multipart uploads count=1 kept=02271--- PASS: TestPendingCleanupUsesOneCutoff (6.30s)22722026/11/09 11:52:51 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"22732026/11/09 11:52: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-config22742026/11/09 11:52:51 WARN Request failed, retrying attempt=2 backoff=190.767021ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22752026/11/09 11:52:51 WARN Request failed, retrying attempt=3 backoff=428.104893ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22762026/11/09 11:52:51 WARN Request failed, retrying attempt=4 backoff=772.594409ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22772026/11/09 11:52:52 WARN Request failed, retrying attempt=5 backoff=1.512859141s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22782026/11/09 11:52:54 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_closures22792026/11/09 11:52:54 WARN Request failed, retrying attempt=2 backoff=188.935714ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22802026/11/09 11:52:54 WARN Request failed, retrying attempt=3 backoff=411.669444ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22812026/11/09 11:52:54 WARN Request failed, retrying attempt=4 backoff=874.261408ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22822026/11/09 11:52:55 WARN Request failed, retrying attempt=5 backoff=1.468637856s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2283--- PASS: TestClientErrorHandling (0.00s)2284 --- PASS: TestClientErrorHandling/InvalidStorePath (0.27s)2285 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.28s)2286 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.61s)2287PASS22882026-11-09 11:52:57.442 UTC [111] LOG: received smart shutdown request22892026-11-09 11:52:57.447 UTC [111] LOG: background worker "logical replication launcher" (PID 121) exited with exit code 122902026-11-09 11:52:57.458 UTC [116] LOG: shutting down22912026-11-09 11:52:57.459 UTC [116] LOG: checkpoint starting: shutdown immediate22922026-11-09 11:52:58.354 UTC [116] LOG: checkpoint complete: wrote 10574 buffers (64.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.191 s, sync=0.668 s, total=0.896 s; sync files=36398, longest=0.002 s, average=0.001 s; distance=526019 kB, estimate=526019 kB; lsn=0/21916BA8, redo lsn=0/21916BA822932026-11-09 11:52:58.430 UTC [111] LOG: database system is shut down2294Running OIDC tests...2295=== RUN TestAudienceForIssuer2296=== PAUSE TestAudienceForIssuer2297=== RUN TestGlobMatch2298=== PAUSE TestGlobMatch2299=== RUN TestValidateToken_ValidToken2300=== PAUSE TestValidateToken_ValidToken2301=== RUN TestValidateToken_WrongAudience2302=== PAUSE TestValidateToken_WrongAudience2303=== RUN TestValidateToken_Expired2304=== PAUSE TestValidateToken_Expired2305=== RUN TestValidateToken_BoundClaimsMismatch2306=== PAUSE TestValidateToken_BoundClaimsMismatch2307=== RUN TestValidateToken_BoundSubjectMismatch2308=== PAUSE TestValidateToken_BoundSubjectMismatch2309=== RUN TestValidateToken_MultipleProviders2310=== PAUSE TestValidateToken_MultipleProviders2311=== RUN TestValidateToken_NoMatchingProvider2312=== PAUSE TestValidateToken_NoMatchingProvider2313=== RUN TestValidateToken_KubernetesServiceAccount2314=== PAUSE TestValidateToken_KubernetesServiceAccount2315=== RUN TestNewValidator_KubernetesRequiresCA2316=== PAUSE TestNewValidator_KubernetesRequiresCA2317=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2318=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2319=== RUN TestPins_ReservedForMatchingRule2320=== PAUSE TestPins_ReservedForMatchingRule2321=== RUN TestPins_TopLevelShorthand2322=== PAUSE TestPins_TopLevelShorthand2323=== RUN TestPins_ConfigValidation2324=== PAUSE TestPins_ConfigValidation2325=== RUN TestScopes_LegacyProviderDefaultsToWrite2326=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2327=== RUN TestScopes_Rules2328=== PAUSE TestScopes_Rules2329=== RUN TestScopes_ConfigValidation2330=== PAUSE TestScopes_ConfigValidation2331=== CONT TestAudienceForIssuer2332=== CONT TestValidateToken_KubernetesServiceAccount2333--- PASS: TestAudienceForIssuer (0.00s)2334=== CONT TestValidateToken_BoundClaimsMismatch2335=== CONT TestPins_ConfigValidation2336=== CONT TestValidateToken_Expired2337=== CONT TestValidateToken_WrongAudience2338=== CONT TestValidateToken_ValidToken2339--- PASS: TestPins_ConfigValidation (0.00s)2340=== CONT TestGlobMatch2341=== RUN TestGlobMatch/foo_foo2342=== PAUSE TestGlobMatch/foo_foo2343=== RUN TestGlobMatch/foo_bar2344=== PAUSE TestGlobMatch/foo_bar2345=== RUN TestGlobMatch/*_2346=== PAUSE TestGlobMatch/*_2347=== RUN TestGlobMatch/*_anything2348=== PAUSE TestGlobMatch/*_anything2349=== RUN TestGlobMatch/foo*_foo2350=== PAUSE TestGlobMatch/foo*_foo2351=== RUN TestGlobMatch/foo*_foobar2352=== PAUSE TestGlobMatch/foo*_foobar2353=== RUN TestGlobMatch/foo*_bar2354=== CONT TestPins_ReservedForMatchingRule2355=== CONT TestPins_TopLevelShorthand2356=== CONT TestScopes_Rules2357=== CONT TestScopes_ConfigValidation2358=== CONT TestScopes_LegacyProviderDefaultsToWrite2359=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2360--- PASS: TestScopes_ConfigValidation (0.00s)2361=== CONT TestNewValidator_KubernetesRequiresCA2362=== CONT TestValidateToken_MultipleProviders2363=== CONT TestValidateToken_NoMatchingProvider2364=== CONT TestValidateToken_BoundSubjectMismatch2365=== PAUSE TestGlobMatch/foo*_bar2366=== RUN TestGlobMatch/*bar_bar2367=== PAUSE TestGlobMatch/*bar_bar2368=== RUN TestGlobMatch/*bar_foobar2369=== PAUSE TestGlobMatch/*bar_foobar2370=== RUN TestGlobMatch/*bar_foo2371=== PAUSE TestGlobMatch/*bar_foo2372=== RUN TestGlobMatch/foo*bar_foobar2373=== PAUSE TestGlobMatch/foo*bar_foobar2374=== RUN TestGlobMatch/foo*bar_foo123bar2375=== PAUSE TestGlobMatch/foo*bar_foo123bar2376=== RUN TestGlobMatch/foo*bar_foobarbaz2377=== PAUSE TestGlobMatch/foo*bar_foobarbaz2378=== RUN TestGlobMatch/*/*_foo/bar2379=== PAUSE TestGlobMatch/*/*_foo/bar2380=== RUN TestGlobMatch/*/*_foo2381=== PAUSE TestGlobMatch/*/*_foo2382=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2383=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2384=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02385=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02386=== RUN TestGlobMatch/refs/*/main_refs/heads/main2387=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2388=== RUN TestGlobMatch/fo?_foo2389=== PAUSE TestGlobMatch/fo?_foo2390=== RUN TestGlobMatch/fo?_fo2391=== PAUSE TestGlobMatch/fo?_fo2392=== RUN TestGlobMatch/fo?_fooo2393=== PAUSE TestGlobMatch/fo?_fooo2394=== RUN TestGlobMatch/?oo_foo2395=== PAUSE TestGlobMatch/?oo_foo2396=== RUN TestGlobMatch/?oo_boo2397=== PAUSE TestGlobMatch/?oo_boo2398=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2399=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2400=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2401=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2402=== CONT TestGlobMatch/foo_foo2403=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2404=== CONT TestGlobMatch/?oo_boo2405=== CONT TestGlobMatch/?oo_foo2406=== CONT TestGlobMatch/fo?_fooo2407=== CONT TestGlobMatch/fo?_fo2408=== CONT TestGlobMatch/fo?_foo2409=== CONT TestGlobMatch/refs/*/main_refs/heads/main2410=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02411=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2412=== CONT TestGlobMatch/*/*_foo2413=== CONT TestGlobMatch/*/*_foo/bar2414=== CONT TestGlobMatch/foo*bar_foobarbaz2415=== CONT TestGlobMatch/foo*bar_foo123bar2416=== CONT TestGlobMatch/foo*_bar2417=== CONT TestGlobMatch/*bar_bar2418=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2419=== CONT TestGlobMatch/foo*_foobar2420=== CONT TestGlobMatch/foo*_foo2421=== CONT TestGlobMatch/*_anything2422=== CONT TestGlobMatch/*_2423=== CONT TestGlobMatch/foo_bar2424=== CONT TestGlobMatch/*bar_foo2425=== CONT TestGlobMatch/foo*bar_foobar2426=== CONT TestGlobMatch/*bar_foobar2427--- PASS: TestGlobMatch (0.00s)2428 --- PASS: TestGlobMatch/foo_foo (0.00s)2429 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2430 --- PASS: TestGlobMatch/?oo_boo (0.00s)2431 --- PASS: TestGlobMatch/?oo_foo (0.00s)2432 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2433 --- PASS: TestGlobMatch/fo?_fo (0.00s)2434 --- PASS: TestGlobMatch/fo?_foo (0.00s)2435 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2436 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2437 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2438 --- PASS: TestGlobMatch/*/*_foo (0.00s)2439 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2440 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2441 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2442 --- PASS: TestGlobMatch/foo*_bar (0.00s)2443 --- PASS: TestGlobMatch/*bar_bar (0.00s)2444 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2445 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2446 --- PASS: TestGlobMatch/foo*_foo (0.00s)2447 --- PASS: TestGlobMatch/*_anything (0.00s)2448 --- PASS: TestGlobMatch/*_ (0.00s)2449 --- PASS: TestGlobMatch/foo_bar (0.00s)2450 --- PASS: TestGlobMatch/*bar_foo (0.00s)2451 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2452 --- PASS: TestGlobMatch/*bar_foobar (0.00s)24532026/11/09 11:53:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33213/oidc2454--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)24552026/11/09 11:53:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34045/oidc2456--- PASS: TestValidateToken_WrongAudience (0.07s)24572026/11/09 11:53:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34471/oidc2458--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)24592026/11/09 11:53:00 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:375972460--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)24612026/11/09 11:53:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38097/oidc24622026/11/09 11:53:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42461/oidc2463--- PASS: TestValidateToken_ValidToken (0.14s)2464--- PASS: TestScopes_Rules (0.14s)24652026/11/09 11:53:00 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324662026/11/09 11:53:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42985/oidc2467--- PASS: TestValidateToken_Expired (0.16s)2468--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.16s)24692026/11/09 11:53:00 http: TLS handshake error from 127.0.0.1:47644: remote error: tls: bad certificate2470--- PASS: TestNewValidator_KubernetesRequiresCA (0.19s)24712026/11/09 11:53:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46343/oidc24722026/11/09 11:53:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45845/oidc2473--- PASS: TestPins_ReservedForMatchingRule (0.20s)2474--- PASS: TestPins_TopLevelShorthand (0.20s)24752026/11/09 11:53:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33715/oidc2476--- PASS: TestValidateToken_NoMatchingProvider (0.27s)24772026/11/09 11:53:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46413/oidc24782026/11/09 11:53:00 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38419/oidc2479--- PASS: TestValidateToken_MultipleProviders (0.29s)24802026/11/09 11:53:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45709/oidc2481--- PASS: TestValidateToken_BoundSubjectMismatch (0.32s)2482PASS2483Running hook tests...2484=== RUN TestSendPathsEmpty2485=== PAUSE TestSendPathsEmpty2486=== RUN TestQueueEnqueueAndFetch2487=== PAUSE TestQueueEnqueueAndFetch2488=== RUN TestQueueDeduplication2489=== PAUSE TestQueueDeduplication2490=== RUN TestQueueRemove2491=== PAUSE TestQueueRemove2492=== RUN TestQueueFetchBatchLimit2493=== PAUSE TestQueueFetchBatchLimit2494=== RUN TestQueueRetryMovesToBack2495=== PAUSE TestQueueRetryMovesToBack2496=== RUN TestQueueFetchRemoveLifecycle2497=== PAUSE TestQueueFetchRemoveLifecycle2498=== RUN TestQueueConcurrentWriters2499=== PAUSE TestQueueConcurrentWriters2500=== RUN TestQueueRemoveLargeClosure2501=== PAUSE TestQueueRemoveLargeClosure2502=== RUN TestServerClientIntegration2503--- PASS: TestServerClientIntegration (0.00s)2504=== RUN TestServerQueueError25052026/11/09 11:53:00 ERROR Failed to queue paths error="permission denied" count=12506--- PASS: TestServerQueueError (0.00s)2507=== RUN TestGetListenerSocketActivation2508 server_test.go:218: === RUN TestGetListenerSocketActivation2509 --- PASS: TestGetListenerSocketActivation (0.00s)2510 PASS2511 2512--- PASS: TestGetListenerSocketActivation (0.01s)2513=== RUN TestServerStalledClientDoesNotBlockShutdown2514=== PAUSE TestServerStalledClientDoesNotBlockShutdown2515=== RUN TestServerBacksOffOnAcceptErrors2516=== PAUSE TestServerBacksOffOnAcceptErrors2517=== RUN TestDrainIsolatesPoisonPath2518=== PAUSE TestDrainIsolatesPoisonPath2519=== RUN TestRunNotBlockedByPoisonHead2520=== PAUSE TestRunNotBlockedByPoisonHead2521=== RUN TestDrainGivesUpWhenServerDown2522=== PAUSE TestDrainGivesUpWhenServerDown2523=== RUN TestFailedPathPrunedByLaterClosure2524=== PAUSE TestFailedPathPrunedByLaterClosure2525=== RUN TestWorkerUploadsAndRemoves2526=== PAUSE TestWorkerUploadsAndRemoves2527=== RUN TestWorkerSkipsGCdPaths2528=== PAUSE TestWorkerSkipsGCdPaths2529=== RUN TestWorkerPrunesClosureDeps2530=== PAUSE TestWorkerPrunesClosureDeps2531=== RUN TestDrainTimeout2532=== PAUSE TestDrainTimeout2533=== RUN TestWorkerRemoveFailureIsNotProgress2534=== PAUSE TestWorkerRemoveFailureIsNotProgress2535=== RUN TestWorkerKeepsPathItCannotStat2536=== PAUSE TestWorkerKeepsPathItCannotStat2537=== CONT TestSendPathsEmpty2538=== CONT TestWorkerKeepsPathItCannotStat2539--- PASS: TestSendPathsEmpty (0.00s)2540=== CONT TestWorkerRemoveFailureIsNotProgress2541=== CONT TestServerStalledClientDoesNotBlockShutdown2542=== CONT TestServerBacksOffOnAcceptErrors25432026/11/09 11:53:00 ERROR Accept failed error="too many open files"2544=== CONT TestDrainTimeout2545=== CONT TestWorkerPrunesClosureDeps2546=== CONT TestQueueRemoveLargeClosure2547=== CONT TestWorkerSkipsGCdPaths2548=== CONT TestQueueConcurrentWriters2549=== CONT TestWorkerUploadsAndRemoves2550=== CONT TestQueueFetchRemoveLifecycle2551=== CONT TestFailedPathPrunedByLaterClosure2552=== CONT TestQueueRetryMovesToBack2553=== CONT TestDrainGivesUpWhenServerDown2554=== CONT TestQueueFetchBatchLimit2555=== CONT TestQueueRemove2556=== CONT TestRunNotBlockedByPoisonHead2557=== CONT TestQueueDeduplication2558=== CONT TestDrainIsolatesPoisonPath2559=== CONT TestQueueEnqueueAndFetch25602026/11/09 11:53:00 ERROR Accept failed error="too many open files"25612026/11/09 11:53:00 INFO Uploading batch count=425622026/11/09 11:53:00 ERROR Upload failed error="upload failed" count=425632026/11/09 11:53:00 INFO Upload queue status pending=325642026/11/09 11:53:00 INFO Uploading batch count=125652026/11/09 11:53:00 ERROR Upload failed error="upload failed" count=125662026/11/09 11:53:00 INFO Upload queue status pending=22567--- PASS: TestQueueDeduplication (0.01s)25682026/11/09 11:53:00 INFO Upload queue status pending=22569--- PASS: TestQueueEnqueueAndFetch (0.01s)25702026/11/09 11:53:00 INFO Uploading batch count=225712026/11/09 11:53:00 INFO Uploading batch count=125722026/11/09 11:53:00 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1187392990/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1187392990/002/locked/aaa: permission denied"25732026/11/09 11:53:00 INFO Uploading batch count=225742026/11/09 11:53:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4133320023/002/bbb25752026/11/09 11:53:00 INFO Uploading batch count=125762026/11/09 11:53:00 ERROR Upload failed error="upload failed" count=125772026/11/09 11:53:00 INFO Uploading batch count=225782026/11/09 11:53:00 ERROR Upload failed error="upload failed" count=225792026/11/09 11:53:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1365840166/002/a25802026/11/09 11:53:00 INFO Upload queue status pending=225812026/11/09 11:53:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1365840166/002/b25822026/11/09 11:53:00 INFO Uploading batch count=12583--- PASS: TestQueueRetryMovesToBack (0.01s)25842026/11/09 11:53:00 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1187392990/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1187392990/002/locked/aaa: permission denied"25852026/11/09 11:53:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1100437371/002/nonexistent2586--- PASS: TestQueueFetchBatchLimit (0.01s)25872026/11/09 11:53:00 INFO Uploading batch count=125882026/11/09 11:53:00 ERROR Accept failed error="too many open files"25892026/11/09 11:53:00 INFO Uploading batch count=125902026/11/09 11:53:00 INFO Uploading batch count=125912026/11/09 11:53:00 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1187392990/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1187392990/002/locked/aaa: permission denied"25922026/11/09 11:53:00 ERROR Upload failed error="upload failed" count=125932026/11/09 11:53:00 INFO Uploading batch count=225942026/11/09 11:53:00 ERROR Upload failed error="upload failed" count=225952026/11/09 11:53:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1365840166/002/c25962026/11/09 11:53:00 ERROR Drain finished with paths left in queue remaining=12597--- PASS: TestQueueRemove (0.02s)2598--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25992026/11/09 11:53:00 INFO Uploading batch count=126002026/11/09 11:53:00 ERROR Upload failed error="upload failed" count=126012026/11/09 11:53:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1365840166/002/d26022026/11/09 11:53:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1243630006/002/nonexistent26032026/11/09 11:53:00 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126042026/11/09 11:53:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1243630006/002/nonexistent26052026/11/09 11:53:00 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126062026/11/09 11:53:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1243630006/002/nonexistent26072026/11/09 11:53:00 INFO Uploading batch count=126082026/11/09 11:53:00 ERROR Upload failed error="upload failed" count=126092026/11/09 11:53:00 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126102026/11/09 11:53:00 ERROR Drain finished with paths left in queue remaining=126112026/11/09 11:53:00 INFO Uploading batch count=226122026/11/09 11:53:00 ERROR Upload failed error="upload failed" count=226132026/11/09 11:53:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1365840166/002/e26142026/11/09 11:53:00 ERROR Drain finished with paths left in queue remaining=126152026/11/09 11:53:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1365840166/002/f2616--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2617--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)2618--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)26192026/11/09 11:53:00 ERROR Drain finished with paths left in queue remaining=102620--- PASS: TestDrainIsolatesPoisonPath (0.02s)2621--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2622--- PASS: TestWorkerPrunesClosureDeps (0.03s)2623--- PASS: TestWorkerUploadsAndRemoves (0.04s)2624--- PASS: TestWorkerSkipsGCdPaths (0.04s)26252026/11/09 11:53:00 ERROR Accept failed error="too many open files"26262026/11/09 11:53:00 ERROR Accept failed error="too many open files"2627--- PASS: TestQueueRemoveLargeClosure (0.11s)2628--- PASS: TestQueueConcurrentWriters (0.11s)26292026/11/09 11:53:00 ERROR Accept failed error="too many open files"26302026/11/09 11:53:00 ERROR Failed to decode request error="read unix /build/hook507238875/test.sock->@: i/o timeout"26312026/11/09 11:53:00 ERROR Failed to write response error="write unix /build/hook507238875/test.sock->@: i/o timeout"2632--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)26332026/11/09 11:53:00 ERROR Upload failed error="context deadline exceeded" count=226342026/11/09 11:53:00 ERROR Drain finished with paths left in queue remaining=42635--- PASS: TestDrainTimeout (0.22s)26362026/11/09 11:53:00 ERROR Accept failed error="too many open files"26372026/11/09 11:53:01 ERROR Accept failed error="too many open files"2638--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26392026/11/09 11:53:01 INFO Uploading batch count=126402026/11/09 11:53:01 INFO Uploading batch count=126412026/11/09 11:53:01 INFO Uploading batch count=126422026/11/09 11:53:01 ERROR Upload failed error="upload failed" count=126432026/11/09 11:53:01 INFO Uploading batch count=126442026/11/09 11:53:01 ERROR Upload failed error="upload failed" count=126452026/11/09 11:53:01 INFO Uploading batch count=126462026/11/09 11:53:01 ERROR Upload failed error="upload failed" count=126472026/11/09 11:53:01 INFO Uploading batch count=126482026/11/09 11:53:01 ERROR Upload failed error="upload failed" count=126492026/11/09 11:53:01 ERROR Drain finished with paths left in queue remaining=12650--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2651PASS2652Running signing tests...2653=== RUN TestExternalSigner2654=== PAUSE TestExternalSigner2655=== RUN TestExternalSignerWrongPublicKey2656=== PAUSE TestExternalSignerWrongPublicKey2657=== RUN TestExternalSignerErrors2658=== PAUSE TestExternalSignerErrors2659=== RUN TestExternalSignerRestartsAfterCrash2660=== PAUSE TestExternalSignerRestartsAfterCrash2661=== RUN TestExternalSignerProgramErrorKeepsProcess2662=== PAUSE TestExternalSignerProgramErrorKeepsProcess2663=== RUN TestExternalSignerClose2664=== PAUSE TestExternalSignerClose2665=== RUN TestExternalSignerRejectsInvalidPublicKey2666=== PAUSE TestExternalSignerRejectsInvalidPublicKey2667=== RUN TestExternalSignerCancellation2668=== PAUSE TestExternalSignerCancellation2669=== RUN TestGenerateFingerprint2670=== PAUSE TestGenerateFingerprint2671=== RUN TestParseSigningKey2672=== PAUSE TestParseSigningKey2673=== RUN TestSign2674=== PAUSE TestSign2675=== RUN TestSignBatch2676=== PAUSE TestSignBatch2677=== RUN TestNilKeyPublicKey2678=== PAUSE TestNilKeyPublicKey2679=== RUN TestSignErrors2680=== PAUSE TestSignErrors2681=== CONT TestExternalSigner2682=== CONT TestSignErrors2683=== CONT TestExternalSignerProgramErrorKeepsProcess2684=== CONT TestExternalSignerErrors2685=== CONT TestExternalSignerCancellation2686=== CONT TestExternalSignerClose2687=== CONT TestExternalSignerRestartsAfterCrash2688=== RUN TestExternalSignerErrors/program_error2689=== PAUSE TestExternalSignerErrors/program_error2690=== RUN TestExternalSignerErrors/exit_on_request2691=== PAUSE TestExternalSignerErrors/exit_on_request2692=== RUN TestExternalSignerErrors/invalid_JSON2693=== PAUSE TestExternalSignerErrors/invalid_JSON2694=== RUN TestExternalSignerErrors/wrong_id2695=== PAUSE TestExternalSignerErrors/wrong_id2696=== RUN TestExternalSignerErrors/wrong_signature_name2697=== PAUSE TestExternalSignerErrors/wrong_signature_name2698=== CONT TestExternalSignerRejectsInvalidPublicKey2699=== RUN TestExternalSignerRejectsInvalidPublicKey/#002700=== CONT TestNilKeyPublicKey2701--- PASS: TestNilKeyPublicKey (0.00s)2702=== CONT TestSignBatch2703=== CONT TestExternalSignerWrongPublicKey2704=== CONT TestParseSigningKey2705=== RUN TestParseSigningKey/valid_32-byte_key2706=== CONT TestGenerateFingerprint2707=== RUN TestExternalSignerErrors/invalid_signature_base642708=== CONT TestSign2709=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002710=== PAUSE TestParseSigningKey/valid_32-byte_key2711=== RUN TestGenerateFingerprint/basic_with_references2712=== PAUSE TestGenerateFingerprint/basic_with_references2713=== RUN TestGenerateFingerprint/no_references2714=== PAUSE TestGenerateFingerprint/no_references2715=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2716=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2717=== PAUSE TestExternalSignerErrors/invalid_signature_base642718=== RUN TestExternalSignerErrors/wrong_shape2719=== PAUSE TestExternalSignerErrors/wrong_shape2720=== RUN TestExternalSignerErrors/null2721=== PAUSE TestExternalSignerErrors/null2722=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2723=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2724=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2725=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2726=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2727=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2728=== RUN TestParseSigningKey/no_colon2729=== PAUSE TestParseSigningKey/no_colon2730=== RUN TestParseSigningKey/empty_name2731=== PAUSE TestParseSigningKey/empty_name2732=== RUN TestParseSigningKey/invalid_base642733=== PAUSE TestParseSigningKey/invalid_base642734=== RUN TestParseSigningKey/wrong_length2735=== PAUSE TestParseSigningKey/wrong_length2736=== CONT TestParseSigningKey/valid_32-byte_key2737=== RUN TestExternalSignerErrors/missing_signature_name2738=== CONT TestParseSigningKey/empty_name2739=== PAUSE TestExternalSignerErrors/missing_signature_name2740=== CONT TestParseSigningKey/invalid_base642741=== CONT TestParseSigningKey/wrong_length2742=== RUN TestExternalSignerErrors/wrong_signature_length2743=== PAUSE TestExternalSignerErrors/wrong_signature_length2744=== RUN TestExternalSignerErrors/exit_at_startup2745=== PAUSE TestExternalSignerErrors/exit_at_startup2746=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2747=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2748=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2749=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2750=== CONT TestParseSigningKey/no_colon2751=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2752=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2753=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2754=== RUN TestGenerateFingerprint/invalid_nar_hash_length2755=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2756=== RUN TestExternalSignerErrors/wrong_signatures_shape2757=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2758=== CONT TestExternalSignerRejectsInvalidPublicKey/#002759=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2760=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2761=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2762=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2763--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2764 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2765 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2766 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2767 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2768 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2769=== RUN TestGenerateFingerprint/invalid_store_path_prefix2770=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2771=== RUN TestGenerateFingerprint/invalid_reference_prefix2772=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2773=== CONT TestGenerateFingerprint/basic_with_references2774=== CONT TestGenerateFingerprint/no_references2775=== RUN TestExternalSignerErrors/unrequested_key2776=== PAUSE TestExternalSignerErrors/unrequested_key2777=== CONT TestGenerateFingerprint/invalid_nar_hash_length2778=== CONT TestGenerateFingerprint/invalid_reference_prefix2779=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2780=== CONT TestGenerateFingerprint/invalid_store_path_prefix2781=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2782--- PASS: TestGenerateFingerprint (0.00s)2783 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2784 --- PASS: TestGenerateFingerprint/no_references (0.00s)2785 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2786 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2787 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2788 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2789 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2790=== RUN TestExternalSignerErrors/missing_signatures2791=== PAUSE TestExternalSignerErrors/missing_signatures2792=== RUN TestExternalSignerErrors/null_signatures2793=== PAUSE TestExternalSignerErrors/null_signatures2794=== RUN TestExternalSignerErrors/too_few_signatures2795=== PAUSE TestExternalSignerErrors/too_few_signatures2796=== CONT TestExternalSignerErrors/program_error2797=== CONT TestExternalSignerErrors/wrong_signature_length2798=== CONT TestExternalSignerErrors/missing_signatures2799=== CONT TestExternalSignerErrors/wrong_signature_name2800=== CONT TestExternalSignerErrors/invalid_JSON2801--- PASS: TestParseSigningKey (0.00s)2802 --- PASS: TestParseSigningKey/empty_name (0.00s)2803 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2804 --- PASS: TestParseSigningKey/wrong_length (0.00s)2805 --- PASS: TestParseSigningKey/no_colon (0.00s)2806 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2807 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2808--- PASS: TestSign (0.00s)2809=== CONT TestExternalSignerErrors/too_few_signatures2810=== CONT TestExternalSignerErrors/null_signatures2811=== CONT TestExternalSignerErrors/wrong_signatures_shape2812=== CONT TestExternalSignerErrors/exit_at_startup2813--- PASS: TestSignBatch (0.00s)2814=== CONT TestExternalSignerErrors/unrequested_key2815=== CONT TestExternalSignerErrors/invalid_signature_base642816=== CONT TestExternalSignerErrors/null2817=== CONT TestExternalSignerErrors/wrong_shape2818=== CONT TestExternalSignerErrors/missing_signature_name2819=== CONT TestExternalSignerErrors/wrong_id2820=== CONT TestExternalSignerErrors/exit_on_request2821=== RUN TestSignErrors/nil_key2822--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2823--- PASS: TestExternalSignerClose (0.01s)2824--- PASS: TestExternalSignerWrongPublicKey (0.01s)2825=== PAUSE TestSignErrors/nil_key2826=== RUN TestSignErrors/nil_narinfo2827=== PAUSE TestSignErrors/nil_narinfo2828=== RUN TestSignErrors/invalid_narinfo2829=== PAUSE TestSignErrors/invalid_narinfo2830=== RUN TestSignErrors/canceled2831=== PAUSE TestSignErrors/canceled2832=== CONT TestSignErrors/nil_key2833=== CONT TestSignErrors/invalid_narinfo2834=== CONT TestSignErrors/nil_narinfo2835=== CONT TestSignErrors/canceled2836--- PASS: TestSignErrors (0.01s)2837 --- PASS: TestSignErrors/nil_key (0.00s)2838 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2839 --- PASS: TestSignErrors/nil_narinfo (0.00s)2840 --- PASS: TestSignErrors/canceled (0.00s)2841--- PASS: TestExternalSigner (0.01s)2842--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2843--- PASS: TestExternalSignerErrors (0.00s)2844 --- PASS: TestExternalSignerErrors/program_error (0.00s)2845 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2846 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2847 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2848 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2849 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2850 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2851 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2852 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2853 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2854 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2855 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2856 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2857 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2858 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2859 --- PASS: TestExternalSignerErrors/null (0.01s)2860--- PASS: TestExternalSignerCancellation (0.02s)2861PASS2862Running OpenBao signer tests...2863=== RUN TestSign2864=== PAUSE TestSign2865=== RUN TestSignErrors2866=== PAUSE TestSignErrors2867=== RUN TestServe2868=== PAUSE TestServe2869=== RUN TestServeRejectsGarbage2870=== PAUSE TestServeRejectsGarbage2871=== CONT TestSign2872=== CONT TestServe2873=== CONT TestSignErrors2874=== CONT TestServeRejectsGarbage2875--- PASS: TestServeRejectsGarbage (0.00s)2876=== RUN TestSignErrors/http_error2877=== PAUSE TestSignErrors/http_error2878=== RUN TestSignErrors/invalid_json2879=== PAUSE TestSignErrors/invalid_json2880=== RUN TestSignErrors/no_prefix2881=== PAUSE TestSignErrors/no_prefix2882=== RUN TestSignErrors/invalid_base642883=== PAUSE TestSignErrors/invalid_base642884=== CONT TestSignErrors/http_error2885=== CONT TestSignErrors/no_prefix2886--- PASS: TestServe (0.00s)2887=== CONT TestSignErrors/invalid_json2888=== CONT TestSignErrors/invalid_base642889--- PASS: TestSign (0.00s)2890--- PASS: TestSignErrors (0.00s)2891 --- PASS: TestSignErrors/http_error (0.00s)2892 --- PASS: TestSignErrors/invalid_json (0.00s)2893 --- PASS: TestSignErrors/invalid_base64 (0.00s)2894 --- PASS: TestSignErrors/no_prefix (0.00s)2895PASS