niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #416
· raw
1tribuchet: building on mac022Running 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 TestPartSizeForNAR20=== PAUSE TestPartSizeForNAR21=== RUN TestUploadMultipart_SupersededByPeer22=== PAUSE TestUploadMultipart_SupersededByPeer23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestSupersededNARStillUploadsListing28=== PAUSE TestSupersededNARStillUploadsListing29=== 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 TestResolveStorePath58=== PAUSE TestResolveStorePath59=== RUN TestDoWithRetry_BodyReplayedViaGetBody60=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody61=== RUN TestRetryTimeoutOutlastsMaxRetries62=== PAUSE TestRetryTimeoutOutlastsMaxRetries63=== RUN TestDoWithRetry_FinalResponseBodyReadable64=== PAUSE TestDoWithRetry_FinalResponseBodyReadable65=== RUN TestShellSplit66=== PAUSE TestShellSplit67=== RUN TestShellSplitErrors68=== PAUSE TestShellSplitErrors69=== RUN TestStreamPushReportsEveryPath70=== PAUSE TestStreamPushReportsEveryPath71=== RUN TestStreamPushBatchesUnderLoad72=== PAUSE TestStreamPushBatchesUnderLoad73=== RUN TestStreamPushIsolatesFailures74=== PAUSE TestStreamPushIsolatesFailures75=== RUN TestStreamPushGivesUpOnDeadServer76=== PAUSE TestStreamPushGivesUpOnDeadServer77=== RUN TestStreamPushRequestLine78=== PAUSE TestStreamPushRequestLine79=== RUN TestStreamPushReportsSignatures80=== PAUSE TestStreamPushReportsSignatures81=== RUN TestStreamPushReportsSkippedPaths82=== PAUSE TestStreamPushReportsSkippedPaths83=== RUN TestClientSignaturesByStorePath84=== PAUSE TestClientSignaturesByStorePath85=== RUN TestStreamPushStopsWhenCanceled86=== PAUSE TestStreamPushStopsWhenCanceled87=== RUN TestSetClientTLS88=== PAUSE TestSetClientTLS89=== RUN TestSetClientTLSDoesNotMutateDefaultTransport90=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport91=== RUN TestSetClientTLSErrors92=== PAUSE TestSetClientTLSErrors93=== RUN TestStaticToken94=== PAUSE TestStaticToken95=== RUN TestFileTokenReadsAndCaches96=== PAUSE TestFileTokenReadsAndCaches97=== RUN TestFileTokenMissing98=== PAUSE TestFileTokenMissing99=== RUN TestFileTokenEmpty100=== PAUSE TestFileTokenEmpty101=== RUN TestScriptTokenNoExpiryRerunsEveryCall102=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall103=== RUN TestScriptTokenCachesUntilRefresh104=== PAUSE TestScriptTokenCachesUntilRefresh105=== RUN TestScriptTokenEmptyToken106=== PAUSE TestScriptTokenEmptyToken107=== RUN TestScriptTokenBadJSON108=== PAUSE TestScriptTokenBadJSON109=== RUN TestScriptTokenScriptFails110=== PAUSE TestScriptTokenScriptFails111=== RUN TestScriptTokenEmptyCommand112=== PAUSE TestScriptTokenEmptyCommand113=== CONT TestDoServerRequestAttachesToken114=== CONT TestEncodeNixBase32115=== RUN TestEncodeNixBase32/test_string_hash116=== CONT TestRetryTimeoutOutlastsMaxRetries117=== CONT TestScriptTokenEmptyCommand118=== CONT TestScriptTokenScriptFails119=== CONT TestScriptTokenBadJSON120=== CONT TestScriptTokenEmptyToken121=== CONT TestScriptTokenCachesUntilRefresh122=== CONT TestScriptTokenNoExpiryRerunsEveryCall123=== CONT TestFileTokenEmpty124=== CONT TestFileTokenMissing125=== CONT TestFileTokenReadsAndCaches126=== CONT TestStaticToken127=== CONT TestSetClientTLSErrors128=== CONT TestSetClientTLSDoesNotMutateDefaultTransport129=== CONT TestSetClientTLS130=== CONT TestStreamPushStopsWhenCanceled131=== CONT TestClientSignaturesByStorePath132=== CONT TestStreamPushReportsSkippedPaths133=== CONT TestPathInfoCACompatibility134=== CONT TestStreamPushReportsSignatures135=== CONT TestStreamPushRequestLine136=== CONT TestDoWithRetry_BodyReplayedViaGetBody137=== CONT TestStreamPushGivesUpOnDeadServer138=== PAUSE TestEncodeNixBase32/test_string_hash139--- PASS: TestScriptTokenEmptyCommand (0.00s)140=== CONT TestResolveStorePath141--- PASS: TestFileTokenEmpty (0.00s)142--- PASS: TestScriptTokenScriptFails (0.00s)143=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess144--- PASS: TestClientSignaturesByStorePath (0.00s)145=== CONT TestRateLimiterFeedback146=== RUN TestRateLimiterFeedback/429_enables_limiter147--- PASS: TestStaticToken (0.00s)148=== CONT TestDumpPathMatchesNix1492026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=server-test rate=5150--- PASS: TestFileTokenReadsAndCaches (0.00s)151=== CONT TestDumpPathWriterError152=== PAUSE TestRateLimiterFeedback/429_enables_limiter153=== RUN TestRateLimiterFeedback/503_enables_limiter154=== PAUSE TestRateLimiterFeedback/503_enables_limiter155=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter156=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter157=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter158=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter159=== CONT TestDumpPathSingleFile1602026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:58875161=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer162=== RUN TestEncodeNixBase32/empty_input163--- PASS: TestStreamPushStopsWhenCanceled (0.00s)164=== CONT TestPathInfoHashCompatibility165--- PASS: TestFileTokenMissing (0.00s)166=== RUN TestSetClientTLSErrors/missing_cert_file167--- PASS: TestDoServerRequestAttachesToken (0.01s)168=== CONT TestParsePathInfoJSON169=== RUN TestParsePathInfoJSON/Nix_format170=== PAUSE TestParsePathInfoJSON/Nix_format171=== RUN TestParsePathInfoJSON/Lix_format172=== PAUSE TestParsePathInfoJSON/Lix_format173=== RUN TestPathInfoCACompatibility/null_ca_field174--- PASS: TestStreamPushReportsSkippedPaths (0.00s)175=== CONT TestShellSplitErrors176--- PASS: TestShellSplitErrors (0.00s)177=== CONT TestStreamPushBatchesUnderLoad178=== PAUSE TestPathInfoCACompatibility/null_ca_field179=== RUN TestPathInfoCACompatibility/old_string_format_-_text180=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text181=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive182=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive183=== RUN TestPathInfoCACompatibility/new_structured_format_-_text184=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text185=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method186=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method187=== CONT TestStreamPushReportsEveryPath188=== PAUSE TestEncodeNixBase32/empty_input189=== RUN TestParsePathInfoJSON/empty_input190=== PAUSE TestParsePathInfoJSON/empty_input191=== RUN TestParsePathInfoJSON/whitespace_only192=== PAUSE TestParsePathInfoJSON/whitespace_only193=== RUN TestParsePathInfoJSON/invalid_JSON194=== PAUSE TestParsePathInfoJSON/invalid_JSON195=== CONT TestFilterOversizedClosures196--- PASS: TestStreamPushReportsEveryPath (0.00s)197=== RUN TestFilterOversizedClosures/no_limit_keeps_everything198=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything199=== RUN TestSetClientTLS/rejects_connection_without_client_cert200=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped201=== CONT TestUploadMultipart_PartsInParallel202=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped203=== RUN TestFilterOversizedClosures/all_closures_skipped2042026/10/14 16:46:32 ERROR Upload failed error=boom count=12052026/10/14 16:46:32 ERROR Upload failed error="connection refused" count=202062026/10/14 16:46:32 ERROR Server seems unavailable, giving up on batch untried=17207=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)208=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)209=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon210=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon211=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2122026/10/14 16:46:32 ERROR Upload failed error=boom count=1213=== PAUSE TestSetClientTLSErrors/missing_cert_file214=== RUN TestSetClientTLSErrors/missing_key_file215=== PAUSE TestSetClientTLSErrors/missing_key_file216=== RUN TestSetClientTLSErrors/missing_ca_file217=== PAUSE TestSetClientTLSErrors/missing_ca_file218=== RUN TestSetClientTLSErrors/invalid_ca_file219=== PAUSE TestSetClientTLSErrors/invalid_ca_file220=== CONT TestCaseHackSuffix2212026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=server-test rate=52222026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58879223--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)224=== CONT TestSupersededNARStillUploadsListing225=== RUN TestSupersededNARStillUploadsListing/small_NAR226=== PAUSE TestSupersededNARStillUploadsListing/small_NAR227=== RUN TestSupersededNARStillUploadsListing/dump_cut_short228=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short229=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails230=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails231=== CONT TestShellSplit232--- PASS: TestShellSplit (0.00s)233=== CONT TestUploadMultipart_SupersededByPeer234=== RUN TestUploadMultipart_SupersededByPeer/exists235=== PAUSE TestUploadMultipart_SupersededByPeer/exists236=== RUN TestUploadMultipart_SupersededByPeer/missing237=== PAUSE TestUploadMultipart_SupersededByPeer/missing238=== CONT TestDoWithRetry_FinalResponseBodyReadable239--- PASS: TestResolveStorePath (0.00s)240=== CONT TestPartSizeForNAR241=== RUN TestPartSizeForNAR/zero_stays_at_minimum242=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum243=== RUN TestPartSizeForNAR/small_stays_at_minimum2442026/10/14 16:46:32 WARN Rate limiter backed off name=server-test rate=52452026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:58879246--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)247=== CONT TestConvertHashToNix32248=== RUN TestConvertHashToNix32/SRI_format_to_Nix32249=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32250=== RUN TestConvertHashToNix32/already_Nix32_format251=== PAUSE TestConvertHashToNix32/already_Nix32_format252=== RUN TestConvertHashToNix32/invalid_format253=== CONT TestParsePathInfoJSONMultiplePaths254=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths255=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths256=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths257=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2582026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=server-test rate=52592026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58884260=== CONT TestRegisterUploadedObjectReusesConnections261=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert262=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA263=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA264=== RUN TestSetClientTLS/preserves_debug_logging_transport265=== PAUSE TestSetClientTLS/preserves_debug_logging_transport266=== CONT TestGetStorePathHash267=== RUN TestGetStorePathHash/valid_store_path268=== PAUSE TestGetStorePathHash/valid_store_path269=== RUN TestGetStorePathHash/basename_without_hyphen_should_error270=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error271=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error272=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun273=== PAUSE TestFilterOversizedClosures/all_closures_skipped274=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry275=== CONT TestEncodeNixBase32WithRealHash276=== CONT TestStreamPushIsolatesFailures277=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error278=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error279=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error280--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)281--- PASS: TestScriptTokenEmptyToken (0.02s)282--- PASS: TestEncodeNixBase32WithRealHash (0.00s)283=== CONT TestRateLimiterFeedback/429_enables_limiter284=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2852026/10/14 16:46:32 ERROR Upload failed error="bad path" count=3286--- PASS: TestStreamPushIsolatesFailures (0.00s)287=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2882026/10/14 16:46:32 WARN Rate limiter backed off name=server-test rate=5289--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)290=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter291--- PASS: TestScriptTokenBadJSON (0.02s)292=== CONT TestRateLimiterFeedback/503_enables_limiter293=== PAUSE TestConvertHashToNix32/invalid_format294=== CONT TestPathInfoCACompatibility/null_ca_field295=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI296=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method297=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512298=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512299=== CONT TestPathInfoCACompatibility/new_structured_format_-_text300=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive3012026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=server-test rate=5302=== CONT TestEncodeNixBase32/test_string_hash303=== CONT TestPathInfoCACompatibility/old_string_format_-_text304--- PASS: TestPathInfoCACompatibility (0.00s)305 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)306 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)307 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)308 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)309 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)310=== CONT TestParsePathInfoJSON/Nix_format311=== CONT TestParsePathInfoJSON/invalid_JSON312=== CONT TestParsePathInfoJSON/empty_input313=== CONT TestParsePathInfoJSON/Lix_format314=== CONT TestParsePathInfoJSON/whitespace_only315--- PASS: TestParsePathInfoJSON (0.00s)316 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)317 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)318 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)319 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)320 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)321=== CONT TestEncodeNixBase32/empty_input322--- PASS: TestEncodeNixBase32 (0.01s)323 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)324 --- PASS: TestEncodeNixBase32/empty_input (0.00s)325=== CONT TestSetClientTLSErrors/missing_cert_file326=== PAUSE TestPartSizeForNAR/small_stays_at_minimum327=== CONT TestSetClientTLSErrors/missing_ca_file328=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum329=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum330=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts331--- PASS: TestStreamPushReportsSignatures (0.02s)332=== CONT TestSetClientTLSErrors/missing_key_file333=== CONT TestSetClientTLSErrors/invalid_ca_file334=== CONT TestSupersededNARStillUploadsListing/small_NAR3352026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=server-test rate=53362026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:589303372026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58955338=== CONT TestSupersededNARStillUploadsListing/dump_cut_short339=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts3402026/10/14 16:46:32 INFO Garbage collection started341=== RUN TestPartSizeForNAR/1_TiB342=== PAUSE TestPartSizeForNAR/1_TiB343=== RUN TestPartSizeForNAR/5_TiB_S3_max_object344=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object345=== RUN TestPartSizeForNAR/capped_at_5_GiB346=== PAUSE TestPartSizeForNAR/capped_at_5_GiB347=== CONT TestUploadMultipart_SupersededByPeer/exists348--- PASS: TestSetClientTLSErrors (0.01s)349 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)350 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)351 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)352 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)353=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails354=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths355=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths3562026/10/14 16:46:32 INFO Uploading abc-hello (1.0GB)357--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)358 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)359 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)360=== CONT TestSetClientTLS/rejects_connection_without_client_cert3612026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:58875362=== CONT TestUploadMultipart_SupersededByPeer/missing3632026/10/14 16:46:32 INFO Garbage collection started3642026/10/14 16:46:32 WARN Rate limiter backed off name=server-test rate=5365=== CONT TestSetClientTLS/preserves_debug_logging_transport3662026/10/14 16:46:32 WARN Rate limiter backed off name=server-test rate=5367--- PASS: TestStreamPushRequestLine (0.03s)368=== CONT TestFilterOversizedClosures/no_limit_keeps_everything369=== CONT TestFilterOversizedClosures/all_closures_skipped3702026/10/14 16:46:32 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=50371=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3722026/10/14 16:46:32 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=2000373--- PASS: TestFilterOversizedClosures (0.01s)374 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)375 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)376 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)377=== CONT TestGetStorePathHash/valid_store_path378=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error379=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error380=== CONT TestGetStorePathHash/basename_without_hyphen_should_error381--- PASS: TestGetStorePathHash (0.01s)382 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)383 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)384 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)385 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)386=== CONT TestConvertHashToNix32/invalid_format387=== CONT TestConvertHashToNix32/SRI_format_to_Nix32388=== CONT TestConvertHashToNix32/already_Nix32_format389--- PASS: TestConvertHashToNix32 (0.01s)390 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)391 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)392 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)393=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)394=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI395=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon396=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512397--- PASS: TestPathInfoHashCompatibility (0.01s)398 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)399 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)400 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)401 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)402=== CONT TestPartSizeForNAR/zero_stays_at_minimum403=== CONT TestPartSizeForNAR/capped_at_5_GiB404=== CONT TestPartSizeForNAR/5_TiB_S3_max_object405=== CONT TestPartSizeForNAR/1_TiB406=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts407=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum408=== CONT TestPartSizeForNAR/small_stays_at_minimum409--- PASS: TestPartSizeForNAR (0.02s)410 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)411 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)412 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)413 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)414 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)415 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)416 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)417=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA4182026/10/14 16:46:32 WARN Rate limiter enabled after throttle name=s3-test rate=54192026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58970420--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)4212026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:58875422--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)423--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)424 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)425 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)4262026/10/14 16:46:32 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=04272026/10/14 16:46:32 WARN Garbage collection finished on another replica. Its statistics are not available here428--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)4292026/10/14 16:46:32 INFO Uploading abc-hello (1.0GB)4302026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:58875431--- PASS: TestRateLimiterFeedback (0.00s)432 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)433 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)434 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)435 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.02s)4362026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:588754372026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:588754382026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:588754392026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:588754402026/10/14 16:46:32 http: TLS handshake error from 127.0.0.1:58967: read tcp 127.0.0.1:58881->127.0.0.1:58967: use of closed network connection4412026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:588754422026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:58875443--- PASS: TestSetClientTLS (0.01s)444 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)445 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)446 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)4472026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:588754482026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:588754492026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:58875450--- PASS: TestScriptTokenCachesUntilRefresh (0.07s)4512026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:58875452--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)4532026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:588754542026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:588754552026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:588754562026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:58875457--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.07s)4582026/10/14 16:46:32 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:58875459--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.08s)4602026/10/14 16:46:32 INFO Uploading abc-hello (1.0GB)461--- PASS: TestCaseHackSuffix (0.08s)462--- PASS: TestDumpPathSingleFile (0.08s)463--- PASS: TestDumpPathWriterError (0.09s)4642026/10/14 16:46:32 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:58981/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:58981/part/24652026/10/14 16:46:32 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:58981/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:58981/part/34662026/10/14 16:46:32 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"467--- PASS: TestDumpPathMatchesNix (0.11s)468--- PASS: TestStreamPushBatchesUnderLoad (0.12s)469--- PASS: TestSupersededNARStillUploadsListing (0.00s)470 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.02s)471 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.02s)472 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.57s)473--- PASS: TestUploadMultipart_PartsInParallel (0.61s)474--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4752026/10/14 16:46:33 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58882/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58882/api/uploads/complete4762026/10/14 16:46:33 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4772026/10/14 16:46:33 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58882/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58882/api/uploads/complete4782026/10/14 16:46:33 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4792026/10/14 16:46:33 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58882/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58882/api/uploads/complete4802026/10/14 16:46:33 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"481--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.01s)482PASS483Running server tests...484The files belonging to this database system will be owned by user "_tribuchetbld3".485This user must also own the server process.486487The database cluster will be initialized with locale "C".488The default database encoding has accordingly been set to "SQL_ASCII".489The default text search configuration will be set to "english".490491Data page checksums are enabled.492493creating directory /private/var/tb/3/scratch/641c288d84b756d0/build/postgres1348442706/data ... ok494creating subdirectories ... ok495selecting dynamic shared memory implementation ... posix496selecting default "max_connections" ... 100497selecting default "shared_buffers" ... 128MB498selecting default time zone ... UTC499creating configuration files ... ok500running bootstrap script ... ok501performing post-bootstrap initialization ... ok502syncing data to disk ... ok503504initdb: warning: enabling "trust" authentication for local connections505initdb: 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.506507Success. You can now start the database server using:508509 pg_ctl -D /private/var/tb/3/scratch/641c288d84b756d0/build/postgres1348442706/data -l logfile start510511/private/var/tb/3/scratch/641c288d84b756d0/build/postgres1348442706:5432 - no response5122026-10-14 16:46:33.651 UTC [21150] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5132026-10-14 16:46:33.652 UTC [21150] LOG: listening on Unix socket "/private/var/tb/3/scratch/641c288d84b756d0/build/postgres1348442706/.s.PGSQL.5432"5142026-10-14 16:46:33.654 UTC [21157] LOG: database system was shut down at 2026-10-14 16:46:33 UTC5152026-10-14 16:46:33.655 UTC [21150] LOG: database system is ready to accept connections516/private/var/tb/3/scratch/641c288d84b756d0/build/postgres1348442706:5432 - accepting connections517{"timestamp":"2026-10-14T16:46:33.875339Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"2fcc562a-8081-4978-9cb2-abb6a63b458b","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}518=== RUN TestService_AuthMiddleware519=== PAUSE TestService_AuthMiddleware520=== RUN TestService_AuthMiddleware_MTLSProxyHeader521=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader522=== RUN TestService_AuthMiddleware_MTLSBoundSubjects523=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects524=== RUN TestService_ReadAuthMiddleware525=== PAUSE TestService_ReadAuthMiddleware526=== RUN TestService_AuthMiddleware_OIDC527=== PAUSE TestService_AuthMiddleware_OIDC528=== RUN TestService_RequireScope_OIDC529=== PAUSE TestService_RequireScope_OIDC530=== RUN TestService_ReadScope_PublicByDefault531=== PAUSE TestService_ReadScope_PublicByDefault532=== RUN TestCacheConfigHandler533=== PAUSE TestCacheConfigHandler534=== RUN TestCacheStatsHandler535=== PAUSE TestCacheStatsHandler536=== RUN TestClientCADerivations537=== PAUSE TestClientCADerivations538=== RUN TestClientErrorHandling539=== PAUSE TestClientErrorHandling540=== RUN TestClientIntegration541=== PAUSE TestClientIntegration542=== RUN TestClientMultipleUploads543=== PAUSE TestClientMultipleUploads544=== RUN TestClientWithDependencies545=== PAUSE TestClientWithDependencies546=== RUN TestClientSharedPathCommittedMidPush547=== PAUSE TestClientSharedPathCommittedMidPush548=== RUN TestPinProtectsFromGC549=== PAUSE TestPinProtectsFromGC550=== RUN TestClientPushesUseOnePush551=== PAUSE TestClientPushesUseOnePush552=== RUN TestClientFallsBackToClosures553=== PAUSE TestClientFallsBackToClosures554=== RUN TestDeleteClosuresRacingPins555=== PAUSE TestDeleteClosuresRacingPins556=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock557=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock558=== RUN TestResolveDBConnectionString559=== PAUSE TestResolveDBConnectionString560=== RUN TestConnectWaitsForAPeerMigration561=== PAUSE TestConnectWaitsForAPeerMigration562=== RUN TestLeadElectsOneAndHandsOver563=== PAUSE TestLeadElectsOneAndHandsOver564=== RUN TestLeadIncumbentWinsAfterRestart5652026/10/14 16:46:34 INFO lead: acquired remote=192.0.2.1:12345662026/10/14 16:46:34 INFO lead: released remote=192.0.2.1:12345672026/10/14 16:46:34 INFO lead: acquired remote=192.0.2.1:12345682026/10/14 16:46:35 INFO lead: released remote=192.0.2.1:1234569--- PASS: TestLeadIncumbentWinsAfterRestart (1.95s)570=== RUN TestLeadIncumbentAnnouncesAtOnce571=== PAUSE TestLeadIncumbentAnnouncesAtOnce572=== RUN TestLeadEndsOnShutdown573=== PAUSE TestLeadEndsOnShutdown574=== RUN TestLeadEndsWhenItsConnectionHangs5752026/10/14 16:46:36 INFO lead: acquired remote=192.0.2.1:12345762026-10-14 16:46:37.545 UTC [21613] FATAL: terminating connection due to administrator command5772026/10/14 16:46:37 INFO lead: acquired remote=192.0.2.1:12345782026/10/14 16:46:38 WARN lead: lock connection lost error="timeout: context deadline exceeded"5792026/10/14 16:46:38 INFO lead: released remote=192.0.2.1:12345802026/10/14 16:46:38 INFO lead: released remote=192.0.2.1:1234581--- PASS: TestLeadEndsWhenItsConnectionHangs (3.02s)582=== RUN TestGCAdvisoryLockBlocksConcurrentRun583=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun584=== RUN TestGCBugBareHashReferences585=== PAUSE TestGCBugBareHashReferences586=== RUN TestGCMetrics587=== PAUSE TestGCMetrics588=== RUN TestPushDedupSurvivesConcurrentGC589=== PAUSE TestPushDedupSurvivesConcurrentGC590=== RUN TestDeduplicatedObjectsRecordedAsPending591=== PAUSE TestDeduplicatedObjectsRecordedAsPending592=== RUN TestGCSweepSkipsPendingObjects593=== PAUSE TestGCSweepSkipsPendingObjects594=== RUN TestTombstonedObjectOfferedWithoutWaiting595=== PAUSE TestTombstonedObjectOfferedWithoutWaiting596=== RUN TestGCSweepDeliversEachKeyOnce597=== PAUSE TestGCSweepDeliversEachKeyOnce598=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection599=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection600=== RUN TestForceGCDuringPushOffersSweptObject601=== PAUSE TestForceGCDuringPushOffersSweptObject602=== RUN TestFailedS3DeleteKeepsTombstone603=== PAUSE TestFailedS3DeleteKeepsTombstone604=== RUN TestSweepSkipsRowsLockedByPush605=== PAUSE TestSweepSkipsRowsLockedByPush606=== RUN TestRegisterCompletedObjectNeedsPendingRow607=== PAUSE TestRegisterCompletedObjectNeedsPendingRow608=== RUN TestGetExistingObjectsLocksRows609=== PAUSE TestGetExistingObjectsLocksRows610=== RUN TestSweepRechecksPendingAfterLocking611=== PAUSE TestSweepRechecksPendingAfterLocking612=== RUN TestPushWaitsForSweepHoldingRow613=== PAUSE TestPushWaitsForSweepHoldingRow614=== RUN TestCommitRacingPendingCleanupKeepsObjects615=== PAUSE TestCommitRacingPendingCleanupKeepsObjects616=== RUN TestGCEndsOnShutdown617=== PAUSE TestGCEndsOnShutdown618=== RUN TestGCTaskStore_StartNew619=== PAUSE TestGCTaskStore_StartNew620=== RUN TestGCTaskStore_DeduplicateSameParams621=== PAUSE TestGCTaskStore_DeduplicateSameParams622=== RUN TestGCTaskStore_ConflictDifferentParams623=== PAUSE TestGCTaskStore_ConflictDifferentParams624=== RUN TestGCTaskStore_GetEmpty625=== PAUSE TestGCTaskStore_GetEmpty626=== RUN TestGCTaskStore_GetReturnsLatest627=== PAUSE TestGCTaskStore_GetReturnsLatest628=== RUN TestGCTaskStore_CompletedAllowsNewTask629=== PAUSE TestGCTaskStore_CompletedAllowsNewTask630=== RUN TestGCTaskStore_PhaseUpdates631=== PAUSE TestGCTaskStore_PhaseUpdates632=== RUN TestGCTaskStore_Fail633=== PAUSE TestGCTaskStore_Fail634=== RUN TestGracefulShutdownDrainsInflight635=== PAUSE TestGracefulShutdownDrainsInflight636=== RUN TestService_healthCheckHandler637=== PAUSE TestService_healthCheckHandler638=== RUN TestService_readinessHandler639=== PAUSE TestService_readinessHandler640=== RUN TestGenerateLandingPage641=== PAUSE TestGenerateLandingPage642=== RUN TestCacheConfigHandlerMaxNarSize643=== PAUSE TestCacheConfigHandlerMaxNarSize644=== RUN TestCreatePendingClosureRejectsOversizedNAR645=== PAUSE TestCreatePendingClosureRejectsOversizedNAR646=== RUN TestNARDeduplicationMetadataUploadBug647=== PAUSE TestNARDeduplicationMetadataUploadBug648=== RUN TestMetricsInventory649=== PAUSE TestMetricsInventory650=== RUN TestMetricsCommit651=== PAUSE TestMetricsCommit652=== RUN TestService_NativeMTLS653=== PAUSE TestService_NativeMTLS654=== RUN TestServerTLSConfig655=== PAUSE TestServerTLSConfig656=== RUN TestMultipartCleanup657=== PAUSE TestMultipartCleanup658=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded659=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded660=== RUN TestPendingCleanupUsesOneCutoff661=== PAUSE TestPendingCleanupUsesOneCutoff662=== RUN TestObjectStatsTrigger663=== PAUSE TestObjectStatsTrigger664=== RUN TestObjectStatsLargeCommit665=== PAUSE TestObjectStatsLargeCommit666=== RUN TestOrphanedObjectsGC667=== PAUSE TestOrphanedObjectsGC668=== RUN TestOrphanedObjectsGCStressTest669=== PAUSE TestOrphanedObjectsGCStressTest670=== RUN TestCreatePin_ReservedPins671=== PAUSE TestCreatePin_ReservedPins672=== RUN TestPresentReportsOnlyClosureRoots673=== PAUSE TestPresentReportsOnlyClosureRoots674=== RUN TestPresentRefreshesOnlyStaleClosures675=== PAUSE TestPresentRefreshesOnlyStaleClosures676=== RUN TestPresentNotReportedWhileGCDeletesClosure677=== PAUSE TestPresentNotReportedWhileGCDeletesClosure678=== RUN TestParseSingleRange679=== PAUSE TestParseSingleRange680=== RUN TestProxyHeadersOnlyTrustedOnSocket6812026/10/14 16:46:39 INFO Starting HTTP server address=proxy.sock6822026/10/14 16:46:39 INFO Starting HTTP server address=127.0.0.1:590106832026/10/14 16:46:39 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6842026/10/14 16:46:39 INFO Shutdown signal received, draining in-flight requests timeout=10s685--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.21s)686=== RUN TestIsValidCachePath687=== PAUSE TestIsValidCachePath688=== RUN TestReadProxyNarinfo689=== PAUSE TestReadProxyNarinfo690=== RUN TestReadProxyNarinfoAlreadyDecompressed691=== PAUSE TestReadProxyNarinfoAlreadyDecompressed692=== RUN TestReadProxyContentNegotiation693=== PAUSE TestReadProxyContentNegotiation694=== RUN TestReadProxyNarStreaming695=== PAUSE TestReadProxyNarStreaming696=== RUN TestReadProxy404697=== PAUSE TestReadProxy404698=== RUN TestReadProxyInvalidPath699=== PAUSE TestReadProxyInvalidPath700=== RUN TestReadProxyHead701=== PAUSE TestReadProxyHead702=== RUN TestReadProxyOutlastsServerWriteTimeout703=== PAUSE TestReadProxyOutlastsServerWriteTimeout704=== RUN TestReadProxyConditionalGet705=== PAUSE TestReadProxyConditionalGet706=== RUN TestReadProxyRootRedirectsToIndexHTML707=== PAUSE TestReadProxyRootRedirectsToIndexHTML708=== RUN TestReadProxyDisabled709=== PAUSE TestReadProxyDisabled710=== RUN TestReadRedirectNar711=== PAUSE TestReadRedirectNar712=== RUN TestReadRedirectKeepsNarinfoProxied713=== PAUSE TestReadRedirectKeepsNarinfoProxied714=== RUN TestReadProxyRangeRequest715=== PAUSE TestReadProxyRangeRequest716=== RUN TestReadRedirectUsesPublicS3URL717=== PAUSE TestReadRedirectUsesPublicS3URL718=== RUN TestPush_OverlappingRootsStoreOneRowPerKey719=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey720=== RUN TestPush_CompleteCommitsEveryRoot721=== PAUSE TestPush_CompleteCommitsEveryRoot722=== RUN TestPush_RepeatedRootCommitsOnce723=== PAUSE TestPush_RepeatedRootCommitsOnce724=== RUN TestPush_CompleteWaitsForCleanupOfThePush725=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush726=== RUN TestPush_RootsAreLockedInByteOrder727=== PAUSE TestPush_RootsAreLockedInByteOrder728=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit729=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit730=== RUN TestPush_RejectsBadRequests731=== PAUSE TestPush_RejectsBadRequests732=== RUN TestPush_SignsNarinfosOfItsPendingObjects733=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects734=== RUN TestRedundantMultipartUpload735=== PAUSE TestRedundantMultipartUpload736=== RUN TestCompleteMultipartUpload_ErrorButObjectExists737=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists738=== RUN TestCompletedNarNotReofferedAcrossClosures739=== PAUSE TestCompletedNarNotReofferedAcrossClosures740=== RUN TestPresignedUploadRegisteredBeforeCommit741=== PAUSE TestPresignedUploadRegisteredBeforeCommit742=== RUN TestService_Rustfstest743=== PAUSE TestService_Rustfstest744=== RUN TestParseSize745=== PAUSE TestParseSize746=== RUN TestSkippedUploadsHandler747=== PAUSE TestSkippedUploadsHandler748=== RUN TestSystemdListenerNotActivated749--- PASS: TestSystemdListenerNotActivated (0.00s)750=== RUN TestWatchdogBeatsWhenHealthy751--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)752=== RUN TestWatchdogSkipsWhenUnhealthy7532026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7542026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7552026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7562026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/14 16:46:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"763--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)764=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle765=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle766=== RUN TestProxyWriteTimeout767=== PAUSE TestProxyWriteTimeout768=== RUN TestPendingClosureWriteTimeout769=== PAUSE TestPendingClosureWriteTimeout770=== RUN TestIsValidUploadKey771=== PAUSE TestIsValidUploadKey772=== RUN TestUploadHandlersRejectInvalidKeys773=== PAUSE TestUploadHandlersRejectInvalidKeys774=== RUN TestUploadHandlersRejectOversizedBody775=== PAUSE TestUploadHandlersRejectOversizedBody776=== RUN TestService_cleanupPendingClosuresHandler777=== PAUSE TestService_cleanupPendingClosuresHandler778=== RUN TestService_createPendingClosureHandler779=== PAUSE TestService_createPendingClosureHandler780=== RUN TestService_verifyS3Integrity781=== PAUSE TestService_verifyS3Integrity782=== RUN TestCompleteMultipartUnregistered783=== PAUSE TestCompleteMultipartUnregistered784=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT785=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT786=== CONT TestRedundantMultipartUpload787=== CONT TestPush_OverlappingRootsStoreOneRowPerKey788=== CONT TestReadProxyHead789=== CONT TestPresentReportsOnlyClosureRoots790=== CONT TestGCTaskStore_GetReturnsLatest791--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)792=== CONT TestPush_SignsNarinfosOfItsPendingObjects793=== CONT TestPush_RejectsBadRequests794=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit795=== CONT TestPush_RootsAreLockedInByteOrder796=== CONT TestPush_CompleteWaitsForCleanupOfThePush797=== CONT TestPush_RepeatedRootCommitsOnce798=== CONT TestPush_CompleteCommitsEveryRoot799=== CONT TestReadRedirectUsesPublicS3URL800=== CONT TestReadProxyRangeRequest801=== CONT TestReadRedirectKeepsNarinfoProxied802=== CONT TestService_AuthMiddleware803=== CONT TestReadRedirectNar804=== CONT TestReadProxyDisabled805=== CONT TestReadProxyRootRedirectsToIndexHTML806=== CONT TestGCTaskStore_CompletedAllowsNewTask807--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)808=== CONT TestLeadElectsOneAndHandsOver809=== CONT TestReadProxyConditionalGet810=== CONT TestReadProxyOutlastsServerWriteTimeout811=== CONT TestLeadIncumbentAnnouncesAtOnce812=== CONT TestGCTaskStore_PhaseUpdates813=== CONT TestLeadEndsOnShutdown814--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)815=== CONT TestConnectWaitsForAPeerMigration8162026/10/14 16:46:40 INFO Received push request method=POST path=/api/pushes8172026/10/14 16:46:40 INFO Received complete push request method=POST path=/api/pushes/1/complete8182026/10/14 16:46:40 INFO Completed push id=1 objects=6 duration=48.609625ms819--- PASS: TestPush_CompleteCommitsEveryRoot (1.02s)820=== CONT TestGCTaskStore_GetEmpty821--- PASS: TestGCTaskStore_GetEmpty (0.00s)822=== CONT TestResolveDBConnectionString823=== RUN TestResolveDBConnectionString/flag_wins824=== PAUSE TestResolveDBConnectionString/flag_wins825=== RUN TestResolveDBConnectionString/file_when_flag_empty826=== PAUSE TestResolveDBConnectionString/file_when_flag_empty827=== RUN TestResolveDBConnectionString/missing_file_is_an_error828=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error829=== RUN TestResolveDBConnectionString/PGHOST_allows_empty830=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty831=== RUN TestResolveDBConnectionString/nothing_configured832=== PAUSE TestResolveDBConnectionString/nothing_configured833=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock8342026/10/14 16:46:40 INFO Received push request method=POST path=/api/pushes835--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.30s)836=== CONT TestGCTaskStore_ConflictDifferentParams837--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)838=== CONT TestGCTaskStore_DeduplicateSameParams839--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)840=== CONT TestDeleteClosuresRacingPins841--- PASS: TestPresentReportsOnlyClosureRoots (1.63s)842=== CONT TestGCTaskStore_StartNew843--- PASS: TestGCTaskStore_StartNew (0.00s)844=== CONT TestClientFallsBackToClosures845--- PASS: TestReadProxyHead (1.81s)846=== CONT TestGCEndsOnShutdown847=== RUN TestGCEndsOnShutdown/before_the_run848=== PAUSE TestGCEndsOnShutdown/before_the_run849=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete850=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete851=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark852=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark853=== CONT TestCommitRacingPendingCleanupKeepsObjects8542026/10/14 16:46:41 INFO Received push request method=POST path=/api/pushes8552026/10/14 16:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8562026/10/14 16:46:41 INFO Signed narinfos id=1 count=18572026/10/14 16:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8582026/10/14 16:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8592026/10/14 16:46:41 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8602026/10/14 16:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8612026/10/14 16:46:41 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8622026/10/14 16:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8632026/10/14 16:46:41 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18642026/10/14 16:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8652026/10/14 16:46:41 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo866--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.20s)867=== CONT TestPushWaitsForSweepHoldingRow8682026/10/14 16:46:41 INFO Received uploads request method=POST path=/api/pending_closures8692026/10/14 16:46:42 INFO Received uploads request method=POST path=/api/pending_closures870=== RUN TestPush_RejectsBadRequests/bad_root871=== PAUSE TestPush_RejectsBadRequests/bad_root872=== RUN TestPush_RejectsBadRequests/root_not_in_objects873=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects874=== RUN TestPush_RejectsBadRequests/no_roots875=== PAUSE TestPush_RejectsBadRequests/no_roots876=== RUN TestPush_RejectsBadRequests/no_objects877=== PAUSE TestPush_RejectsBadRequests/no_objects878=== CONT TestSweepRechecksPendingAfterLocking8792026/10/14 16:46:42 INFO lead: acquired remote=192.0.2.1:12348802026/10/14 16:46:42 INFO lead: released remote=192.0.2.1:1234881--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.98s)882=== CONT TestGetExistingObjectsLocksRows8832026/10/14 16:46:42 INFO Received push request method=POST path=/api/pushes8842026/10/14 16:46:42 INFO Received complete push request method=POST path=/api/pushes/1/complete8852026/10/14 16:46:42 INFO Completed push id=1 objects=4 duration=24.877625ms8862026/10/14 16:46:42 INFO Received push request method=POST path=/api/pushes8872026/10/14 16:46:42 INFO Aborted multipart uploads count=0 kept=08882026/10/14 16:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period8892026/10/14 16:46: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=08902026/10/14 16:46:43 INFO Vacuumed table table=pending_closures8912026/10/14 16:46:43 INFO Vacuumed table table=pending_objects8922026/10/14 16:46:43 INFO Vacuumed table table=multipart_uploads8932026/10/14 16:46:43 INFO Vacuumed table table=closures8942026/10/14 16:46:43 INFO Vacuumed table table=objects8952026/10/14 16:46:43 INFO Received complete push request method=POST path=/api/pushes/2/complete8962026/10/14 16:46:43 INFO Completed push id=2 objects=4 duration=7.443959ms897--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.78s)898=== CONT TestPendingClosureWriteTimeout899=== RUN TestPendingClosureWriteTimeout/empty900=== PAUSE TestPendingClosureWriteTimeout/empty901=== RUN TestPendingClosureWriteTimeout/400_objects902=== PAUSE TestPendingClosureWriteTimeout/400_objects903=== RUN TestPendingClosureWriteTimeout/670k_objects904=== PAUSE TestPendingClosureWriteTimeout/670k_objects905=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline906=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline907=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT9082026/10/14 16:46:43 INFO Received push request method=POST path=/api/pushes9092026/10/14 16:46:43 INFO Received complete push request method=POST path=/api/pushes/1/complete9102026/10/14 16:46:43 INFO Completed push id=1 objects=4 duration=66.4795ms911--- PASS: TestPush_RepeatedRootCommitsOnce (4.07s)912=== CONT TestCompleteMultipartUnregistered9132026/10/14 16:46:43 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"914--- PASS: TestService_AuthMiddleware (4.15s)915=== CONT TestClientPushesUseOnePush9162026/10/14 16:46:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9172026/10/14 16:46:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTFmOTI1MmUtNmY0ZS00N2MzLTg1MTUtMjg3ZGUxNjkzMDdjLjRkYThkYTkxLTlmOWUtNGNiMC04ZDJmLTFkMDVhYjNjYTFjOXgxNzkxOTk2NDAxOTg1MTM1MDAw parts=129182026/10/14 16:46:43 INFO Received uploads request method=POST path=/api/pending_closures9192026/10/14 16:46:43 INFO Received uploads request method=POST path=/api/pending_closures920--- PASS: TestReadRedirectNar (4.51s)921=== CONT TestService_verifyS3Integrity922--- PASS: TestReadRedirectUsesPublicS3URL (4.79s)923=== CONT TestRegisterCompletedObjectNeedsPendingRow9242026/10/14 16:46:44 INFO Received push request method=POST path=/api/pushes925--- PASS: TestReadProxyRangeRequest (5.31s)926=== CONT TestService_createPendingClosureHandler9272026-10-14 16:46:44.802 UTC [21917] ERROR: Push does not exist: id=19282026-10-14 16:46:44.802 UTC [21917] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9292026-10-14 16:46:44.802 UTC [21917] STATEMENT: SELECT commit_push($1)930--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (5.40s)931=== CONT TestPinProtectsFromGC9322026/10/14 16:46:44 INFO lead: acquired remote=192.0.2.1:1234933--- PASS: TestReadProxyRootRedirectsToIndexHTML (5.84s)934=== CONT TestSweepSkipsRowsLockedByPush9352026/10/14 16:46:45 INFO lead: acquired remote=192.0.2.1:12349362026/10/14 16:46:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9372026/10/14 16:46:45 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTFmOTI1MmUtNmY0ZS00N2MzLTg1MTUtMjg3ZGUxNjkzMDdjLmI4NThkN2ZmLWEyODktNGU4OS04NmE2LTlkY2QyYjg4ZDYxN3gxNzkxOTk2NDAzODQxMzgxMDAw error="Get \"http://127.0.0.1:1/bucket9/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9382026/10/14 16:46:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTFmOTI1MmUtNmY0ZS00N2MzLTg1MTUtMjg3ZGUxNjkzMDdjLmMxNGRmNmI1LTgxMzEtNDE1Ny04ZjFlLTczY2U5MzMxZTJlMHgxNzkxOTk2NDAzNzk4NzQxMDAw parts=129392026/10/14 16:46:45 INFO Received cleanup request method=DELETE path=/api/pending_closures9402026/10/14 16:46:45 INFO Aborted multipart uploads count=1 kept=0941--- PASS: TestRedundantMultipartUpload (6.24s)942=== CONT TestService_cleanupPendingClosuresHandler943--- PASS: TestReadProxyConditionalGet (6.55s)944=== CONT TestClientSharedPathCommittedMidPush9452026/10/14 16:46:46 INFO lead: released remote=192.0.2.1:12349462026/10/14 16:46:46 INFO Received push request method=POST path=/api/pushes9472026/10/14 16:46:46 INFO lead: acquired remote=192.0.2.1:12349482026-10-14 16:46:46.385 UTC [21940] ERROR: could not obtain lock on row in relation "closures"9492026-10-14 16:46:46.385 UTC [21940] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9502026-10-14 16:46:46.392 UTC [21940] ERROR: could not obtain lock on row in relation "closures"9512026-10-14 16:46:46.392 UTC [21940] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9522026-10-14 16:46:46.394 UTC [21940] ERROR: could not obtain lock on row in relation "closures"9532026-10-14 16:46:46.394 UTC [21940] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9542026-10-14 16:46:46.400 UTC [21940] ERROR: could not obtain lock on row in relation "closures"9552026-10-14 16:46:46.400 UTC [21940] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9562026-10-14 16:46:46.402 UTC [21940] ERROR: could not obtain lock on row in relation "closures"9572026-10-14 16:46:46.402 UTC [21940] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT958--- PASS: TestPush_RootsAreLockedInByteOrder (7.02s)959=== CONT TestUploadHandlersRejectOversizedBody960=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure961=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure962=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart963=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart964=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts965=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts966=== CONT TestFailedS3DeleteKeepsTombstone967--- PASS: TestReadProxyDisabled (7.16s)968=== CONT TestClientWithDependencies9692026/10/14 16:46:46 INFO lead: released remote=192.0.2.1:1234970--- PASS: TestLeadEndsOnShutdown (7.18s)971=== CONT TestUploadHandlersRejectInvalidKeys972=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info973=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info974=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal975=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal976=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key977=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key978=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key979=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key980=== CONT TestForceGCDuringPushOffersSweptObject981=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows982=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows983=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check984=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check985=== CONT TestIsValidUploadKey986=== RUN TestIsValidUploadKey/narinfo987=== PAUSE TestIsValidUploadKey/narinfo988=== RUN TestIsValidUploadKey/nar_zst989=== PAUSE TestIsValidUploadKey/nar_zst990=== RUN TestIsValidUploadKey/nar_xz991=== PAUSE TestIsValidUploadKey/nar_xz992=== RUN TestIsValidUploadKey/nar_plain993=== PAUSE TestIsValidUploadKey/nar_plain994=== RUN TestIsValidUploadKey/listing995=== PAUSE TestIsValidUploadKey/listing996=== RUN TestIsValidUploadKey/build_log997=== PAUSE TestIsValidUploadKey/build_log998=== RUN TestIsValidUploadKey/build_log_home-manager_file999=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1000=== RUN TestIsValidUploadKey/build_log_plus_in_name1001=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1002=== RUN TestIsValidUploadKey/build_log_question_mark1003=== PAUSE TestIsValidUploadKey/build_log_question_mark1004=== RUN TestIsValidUploadKey/build_log_equals1005=== PAUSE TestIsValidUploadKey/build_log_equals1006=== RUN TestIsValidUploadKey/realisation1007=== PAUSE TestIsValidUploadKey/realisation1008=== RUN TestIsValidUploadKey/realisation_plus_in_output1009=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1010=== RUN TestIsValidUploadKey/nix-cache-info1011=== PAUSE TestIsValidUploadKey/nix-cache-info1012=== RUN TestIsValidUploadKey/index.html1013=== PAUSE TestIsValidUploadKey/index.html1014=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1015=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1016=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1017=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1018=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1019=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1020=== RUN TestIsValidUploadKey/traversal1021=== PAUSE TestIsValidUploadKey/traversal1022=== RUN TestIsValidUploadKey/traversal_nar1023=== PAUSE TestIsValidUploadKey/traversal_nar1024=== RUN TestIsValidUploadKey/absolute1025=== PAUSE TestIsValidUploadKey/absolute1026=== RUN TestIsValidUploadKey/empty_key1027=== PAUSE TestIsValidUploadKey/empty_key1028=== RUN TestIsValidUploadKey/unknown_type1029=== PAUSE TestIsValidUploadKey/unknown_type1030=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1031--- PASS: TestReadRedirectKeepsNarinfoProxied (7.57s)1032=== CONT TestReadProxyNarinfoAlreadyDecompressed1033--- PASS: TestConnectWaitsForAPeerMigration (7.77s)1034=== CONT TestGCSweepDeliversEachKeyOnce1035--- PASS: TestReadProxyOutlastsServerWriteTimeout (7.91s)1036=== CONT TestReadProxyInvalidPath10372026/10/14 16:46:47 INFO lead: released remote=192.0.2.1:12341038--- PASS: TestLeadElectsOneAndHandsOver (7.93s)1039=== CONT TestTombstonedObjectOfferedWithoutWaiting10402026/10/14 16:46:48 INFO Received uploads request method=POST path=/api/pending_closures10412026/10/14 16:46:48 INFO Received uploads request method=POST path=/api/pending_closures10422026/10/14 16:46:48 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10432026/10/14 16:46:48 INFO Uploading yh7dz4c9rfhgxix6majj5f5b0m80ydvp-shared-dep (136B)10442026/10/14 16:46:48 INFO Uploading 0a0pbnfmhqi895bbkx5f4j7mgqr4v17f-b (256B)10452026/10/14 16:46:48 WARN Failed to register uploaded object key=yh7dz4c9rfhgxix6majj5f5b0m80ydvp.ls error="server returned 404: 404 page not found\n"10462026/10/14 16:46:48 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10472026/10/14 16:46:48 WARN Failed to register uploaded object key=vcm46a5dx284bslpszrw7cdd3g57r73a.ls error="server returned 404: 404 page not found\n"10482026/10/14 16:46:48 WARN Failed to register uploaded object key=nar/0k58y7079yg4mdns8ri9v2rw0a1i10rf6gss4dlxnlbq5x0dakb7.nar.zst error="server returned 404: 404 page not found\n"10492026/10/14 16:46:48 INFO Aborted multipart uploads count=0 kept=010502026/10/14 16:46:48 WARN Failed to register uploaded object key=0a0pbnfmhqi895bbkx5f4j7mgqr4v17f.ls error="server returned 404: 404 page not found\n"10512026/10/14 16:46:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10522026/10/14 16:46:48 INFO Signed narinfos id=2 count=210532026/10/14 16:46:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10542026/10/14 16:46:48 INFO Signed narinfos id=1 count=210552026/10/14 16:46:48 INFO Uploading 4 narinfos10562026/10/14 16:46:48 WARN Force mode enabled - objects will be deleted immediately without grace period10572026/10/14 16:46:48 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010582026/10/14 16:46:48 WARN Failed to register uploaded object key=0a0pbnfmhqi895bbkx5f4j7mgqr4v17f.narinfo error="server returned 404: 404 page not found\n"10592026/10/14 16:46:48 WARN Failed to register uploaded object key=yh7dz4c9rfhgxix6majj5f5b0m80ydvp.narinfo error="server returned 404: 404 page not found\n"10602026/10/14 16:46:48 WARN Failed to register uploaded object key=vcm46a5dx284bslpszrw7cdd3g57r73a.narinfo error="server returned 404: 404 page not found\n"10612026/10/14 16:46:48 INFO Vacuumed table table=pending_closures10622026/10/14 16:46:48 INFO Vacuumed table table=pending_objects10632026/10/14 16:46:48 INFO Vacuumed table table=multipart_uploads10642026/10/14 16:46:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10652026/10/14 16:46:48 WARN Failed to register uploaded object key=yh7dz4c9rfhgxix6majj5f5b0m80ydvp.narinfo error="server returned 404: 404 page not found\n"10662026/10/14 16:46:48 INFO Vacuumed table table=closures10672026/10/14 16:46:48 INFO Completed upload id=1 objects=6 duration=41.121084ms10682026/10/14 16:46:48 INFO Vacuumed table table=objects10692026/10/14 16:46:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10702026/10/14 16:46:48 INFO Completed upload id=2 objects=6 duration=2.905417ms10712026/10/14 16:46:48 INFO Upload complete. (479ms)10722026/10/14 16:46:48 INFO Received uploads request method=POST path=/api/pending_closures1073=== NAME TestClientFallsBackToClosures1074 client_pushes_test.go:112: Retrieved narinfo from S3:1075 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientFallsBackToClosures2004560719/001/store/yh7dz4c9rfhgxix6majj5f5b0m80ydvp-shared-dep1076 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1077 Compression: zstd1078 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821079 NarSize: 1361080 References: 1081 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1082 client_pushes_test.go:112: Retrieved narinfo from S3:1083 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientFallsBackToClosures2004560719/001/store/vcm46a5dx284bslpszrw7cdd3g57r73a-a1084--- PASS: TestCommitRacingPendingCleanupKeepsObjects (7.65s)1085=== CONT TestReadProxy4041086=== NAME TestClientFallsBackToClosures1087 URL: nar/0k58y7079yg4mdns8ri9v2rw0a1i10rf6gss4dlxnlbq5x0dakb7.nar.zst1088 Compression: zstd1089 NarHash: sha256:0k58y7079yg4mdns8ri9v2rw0a1i10rf6gss4dlxnlbq5x0dakb71090 NarSize: 2561091 References: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientFallsBackToClosures2004560719/001/store/yh7dz4c9rfhgxix6majj5f5b0m80ydvp-shared-dep1092 CA: text:sha256:0xxbfjn5xwwbpk9s0n8jmq7bliik0j3mbj1x91zb1lj09nrhwi7z1093 client_pushes_test.go:112: Retrieved narinfo from S3:1094 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientFallsBackToClosures2004560719/001/store/0a0pbnfmhqi895bbkx5f4j7mgqr4v17f-b1095 URL: nar/0k58y7079yg4mdns8ri9v2rw0a1i10rf6gss4dlxnlbq5x0dakb7.nar.zst1096 Compression: zstd1097 NarHash: sha256:0k58y7079yg4mdns8ri9v2rw0a1i10rf6gss4dlxnlbq5x0dakb71098 NarSize: 2561099 References: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientFallsBackToClosures2004560719/001/store/yh7dz4c9rfhgxix6majj5f5b0m80ydvp-shared-dep1100 CA: text:sha256:0xxbfjn5xwwbpk9s0n8jmq7bliik0j3mbj1x91zb1lj09nrhwi7z1101--- PASS: TestClientFallsBackToClosures (7.93s)1102=== CONT TestReadProxyNarStreaming11032026/10/14 16:46:49 INFO Aborted multipart uploads count=0 kept=011042026/10/14 16:46:49 WARN Force mode enabled - objects will be deleted immediately without grace period11052026/10/14 16:46:49 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=011062026/10/14 16:46:49 INFO Vacuumed table table=pending_closures11072026/10/14 16:46:49 INFO Vacuumed table table=pending_objects11082026/10/14 16:46:49 INFO Vacuumed table table=multipart_uploads11092026/10/14 16:46:49 INFO Vacuumed table table=closures11102026/10/14 16:46:49 INFO Vacuumed table table=objects1111--- PASS: TestSweepRechecksPendingAfterLocking (7.18s)1112--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (8.87s)1113=== CONT TestReadProxyContentNegotiation1114=== CONT TestGCMetrics1115--- PASS: TestPushWaitsForSweepHoldingRow (7.74s)1116=== CONT TestDeduplicatedObjectsRecordedAsPending1117--- PASS: TestGetExistingObjectsLocksRows (7.08s)1118=== CONT TestPushDedupSurvivesConcurrentGC11192026/10/14 16:46:49 INFO Received uploads request method=POST path=/api/pending_closures1120--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (6.53s)1121=== CONT TestGCSweepSkipsPendingObjects11222026/10/14 16:46:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11232026/10/14 16:46:50 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1124--- PASS: TestCompleteMultipartUnregistered (6.64s)1125=== CONT TestGCBugBareHashReferences11262026/10/14 16:46:50 INFO Received uploads request method=POST path=/api/pending_closures11272026/10/14 16:46:50 INFO Received push request method=POST path=/api/pushes11282026/10/14 16:46:50 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11292026/10/14 16:46:50 INFO Uploading w2ndnk3l6qz281m1qv281hng4ri5k8xz-shared-dep (136B)11302026/10/14 16:46:50 INFO Uploading zkyxb17nhxnjgsh0nb6qyz17g3j6lsdy-b (256B)11312026/10/14 16:46:50 WARN Failed to register uploaded object key=zkyxb17nhxnjgsh0nb6qyz17g3j6lsdy.ls error="server returned 404: 404 page not found\n"11322026/10/14 16:46:50 WARN Failed to register uploaded object key=w2ndnk3l6qz281m1qv281hng4ri5k8xz.ls error="server returned 404: 404 page not found\n"11332026/10/14 16:46:50 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11342026/10/14 16:46:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11352026/10/14 16:46:50 WARN Failed to register uploaded object key=nar/0i9m9gyc2rxsv1i3wzqsfd9bja6xrnnp7ahzyavg81rhyliwabxk.nar.zst error="server returned 404: 404 page not found\n"11362026/10/14 16:46:50 WARN Failed to register uploaded object key=7iaybnscc1bfhja13s9s7xhgb28cizv0.ls error="server returned 404: 404 page not found\n"11372026/10/14 16:46:50 INFO Signed narinfos id=1 count=311382026/10/14 16:46:50 INFO Uploading 3 narinfos11392026/10/14 16:46:50 WARN Failed to register uploaded object key=zkyxb17nhxnjgsh0nb6qyz17g3j6lsdy.narinfo error="server returned 404: 404 page not found\n"11402026/10/14 16:46:50 WARN Failed to register uploaded object key=7iaybnscc1bfhja13s9s7xhgb28cizv0.narinfo error="server returned 404: 404 page not found\n"11412026/10/14 16:46:50 INFO Received complete push request method=POST path=/api/pushes/1/complete11422026/10/14 16:46:50 WARN Failed to register uploaded object key=w2ndnk3l6qz281m1qv281hng4ri5k8xz.narinfo error="server returned 404: 404 page not found\n"11432026/10/14 16:46:50 INFO Completed push id=1 objects=8 duration=39.128666ms11442026/10/14 16:46:50 INFO Upload complete. (362ms)1145=== NAME TestClientPushesUseOnePush1146 client_pushes_test.go:97: Retrieved narinfo from S3:1147 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientPushesUseOnePush782827990/001/store/w2ndnk3l6qz281m1qv281hng4ri5k8xz-shared-dep1148 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1149 Compression: zstd1150 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821151 NarSize: 1361152 References: 1153 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1154 client_pushes_test.go:97: Retrieved narinfo from S3:1155 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientPushesUseOnePush782827990/001/store/7iaybnscc1bfhja13s9s7xhgb28cizv0-a1156 URL: nar/0i9m9gyc2rxsv1i3wzqsfd9bja6xrnnp7ahzyavg81rhyliwabxk.nar.zst1157 Compression: zstd1158 NarHash: sha256:0i9m9gyc2rxsv1i3wzqsfd9bja6xrnnp7ahzyavg81rhyliwabxk1159 NarSize: 2561160 References: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientPushesUseOnePush782827990/001/store/w2ndnk3l6qz281m1qv281hng4ri5k8xz-shared-dep1161 CA: text:sha256:07ziyh549gk7g2n5xsg4rh9jw6ihlgj4ymwyadww0wasq4wbhan01162 client_pushes_test.go:97: Retrieved narinfo from S3:1163 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientPushesUseOnePush782827990/001/store/zkyxb17nhxnjgsh0nb6qyz17g3j6lsdy-b1164 URL: nar/0i9m9gyc2rxsv1i3wzqsfd9bja6xrnnp7ahzyavg81rhyliwabxk.nar.zst1165 Compression: zstd1166 NarHash: sha256:0i9m9gyc2rxsv1i3wzqsfd9bja6xrnnp7ahzyavg81rhyliwabxk1167 NarSize: 2561168 References: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientPushesUseOnePush782827990/001/store/w2ndnk3l6qz281m1qv281hng4ri5k8xz-shared-dep1169 CA: text:sha256:07ziyh549gk7g2n5xsg4rh9jw6ihlgj4ymwyadww0wasq4wbhan01170--- PASS: TestRegisterCompletedObjectNeedsPendingRow (6.68s)1171=== CONT TestService_ReadScope_PublicByDefault1172--- PASS: TestClientPushesUseOnePush (7.35s)1173=== CONT TestClientIntegration11742026/10/14 16:46:51 INFO Received uploads request method=POST path=/api/pending_closures11752026/10/14 16:46:51 INFO Received uploads request method=POST path=/api/pending_closures11762026/10/14 16:46:51 INFO Received uploads request method=POST path=/api/pending_closures1177--- PASS: TestDeleteClosuresRacingPins (10.57s)1178=== CONT TestGCAdvisoryLockBlocksConcurrentRun11792026/10/14 16:46:51 INFO Aborted multipart uploads count=0 kept=011802026/10/14 16:46:52 WARN Force mode enabled - objects will be deleted immediately without grace period11812026/10/14 16:46:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011822026/10/14 16:46:52 INFO Vacuumed table table=pending_closures11832026/10/14 16:46:52 INFO Vacuumed table table=pending_objects11842026/10/14 16:46:52 INFO Vacuumed table table=multipart_uploads11852026/10/14 16:46:52 INFO Vacuumed table table=closures1186=== NAME TestPinProtectsFromGC1187 client_integration_test.go:731: Pinned store path: /private/var/tb/3/scratch/641c288d84b756d0/build/TestPinProtectsFromGC1000115381/001/store/3k4y5mkp2jbrcwnzinsim4rhi8jvyxc0-pinned-file.txt1188 client_integration_test.go:732: Unpinned store path: /private/var/tb/3/scratch/641c288d84b756d0/build/TestPinProtectsFromGC1000115381/001/store/j4vqvyllmbbf1sn9lvrm80xygm4bxa09-unpinned-file.txt11892026/10/14 16:46:52 INFO Vacuumed table table=objects11902026/10/14 16:46:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11912026/10/14 16:46:52 INFO Aborted multipart uploads count=0 kept=011922026/10/14 16:46:52 WARN Force mode enabled - objects will be deleted immediately without grace period11932026/10/14 16:46:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=011942026/10/14 16:46:52 INFO Vacuumed table table=pending_closures11952026/10/14 16:46:52 INFO Vacuumed table table=pending_objects11962026/10/14 16:46:52 INFO Vacuumed table table=multipart_uploads11972026/10/14 16:46:52 INFO Vacuumed table table=closures11982026/10/14 16:46:52 INFO Vacuumed table table=objects11992026/10/14 16:46:52 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTFmOTI1MmUtNmY0ZS00N2MzLTg1MTUtMjg3ZGUxNjkzMDdjLjZlY2QwOTU0LWU2NDgtNGIyNi05NmQ4LTdkOWI0YWVjYjUyNngxNzkxOTk2NDEwNTE4MDM2MDAw parts=1012002026/10/14 16:46:52 INFO Received push request method=POST path=/api/pushes12012026/10/14 16:46:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1202--- PASS: TestSweepSkipsRowsLockedByPush (6.98s)1203=== CONT TestClientErrorHandling1204=== RUN TestClientErrorHandling/InvalidStorePath1205=== PAUSE TestClientErrorHandling/InvalidStorePath1206=== RUN TestClientErrorHandling/InvalidAuthToken1207=== PAUSE TestClientErrorHandling/InvalidAuthToken1208=== RUN TestClientErrorHandling/ServerNotAvailable1209=== PAUSE TestClientErrorHandling/ServerNotAvailable1210=== CONT TestClientCADerivations12112026/10/14 16:46:52 INFO Completed upload id=1 objects=2 duration=3.567041ms12122026/10/14 16:46:52 INFO Received uploads request method=POST path=/api/pending_closures12132026/10/14 16:46:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12142026/10/14 16:46:52 INFO Uploading 3k4y5mkp2jbrcwnzinsim4rhi8jvyxc0-pinned-file.txt (128B)12152026/10/14 16:46:52 INFO Received uploads request method=POST path=/api/pending_closures12162026/10/14 16:46:52 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12172026/10/14 16:46:52 WARN Found objects in DB but missing from S3, will re-upload count=11218--- PASS: TestService_verifyS3Integrity (8.35s)1219=== CONT TestCacheStatsHandler12202026/10/14 16:46:52 INFO Received cleanup request method=DELETE path=/api/pending_closures12212026/10/14 16:46:52 INFO Aborted multipart uploads count=0 kept=012222026/10/14 16:46:52 INFO Received uploads request method=POST path=/api/pending_closures12232026/10/14 16:46:52 WARN Failed to register uploaded object key=3k4y5mkp2jbrcwnzinsim4rhi8jvyxc0.ls error="server returned 404: 404 page not found\n"12242026/10/14 16:46:52 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12252026/10/14 16:46:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12262026/10/14 16:46:52 INFO Signed narinfos id=1 count=112272026/10/14 16:46:52 INFO Uploading 1 narinfos12282026/10/14 16:46:52 INFO Received complete push request method=POST path=/api/pushes/1/complete12292026/10/14 16:46:52 WARN Failed to register uploaded object key=3k4y5mkp2jbrcwnzinsim4rhi8jvyxc0.narinfo error="server returned 404: 404 page not found\n"12302026/10/14 16:46:52 INFO Received cleanup request method=DELETE path=/api/pending_closures12312026/10/14 16:46:52 INFO Aborted multipart uploads count=1 kept=012322026/10/14 16:46:52 INFO Completed push id=1 objects=3 duration=46.187875ms12332026/10/14 16:46:52 INFO Upload complete. (330ms)12342026/10/14 16:46:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12352026-10-14 16:46:52.483 UTC [21964] ERROR: Closure does not exist: id=112362026-10-14 16:46:52.483 UTC [21964] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE12372026-10-14 16:46:52.483 UTC [21964] STATEMENT: -- name: CommitPendingClosure :one1238 SELECT commit_pending_closure($1::bigint)::bigint1239 1240--- PASS: TestService_cleanupPendingClosuresHandler (6.83s)1241=== CONT TestCacheConfigHandler1242=== RUN TestCacheConfigHandler/full_config,_no_issuer1243=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1244=== RUN TestCacheConfigHandler/no_cache_url_configured1245=== PAUSE TestCacheConfigHandler/no_cache_url_configured1246=== RUN TestCacheConfigHandler/no_signing_keys1247=== PAUSE TestCacheConfigHandler/no_signing_keys1248=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1249=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1250=== CONT TestService_ReadAuthMiddleware12512026/10/14 16:46:52 INFO Received push request method=POST path=/api/pushes12522026/10/14 16:46:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12532026/10/14 16:46:52 INFO Uploading j4vqvyllmbbf1sn9lvrm80xygm4bxa09-unpinned-file.txt (128B)12542026/10/14 16:46:52 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12552026/10/14 16:46:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12562026/10/14 16:46:52 WARN Failed to register uploaded object key=j4vqvyllmbbf1sn9lvrm80xygm4bxa09.ls error="server returned 404: 404 page not found\n"12572026/10/14 16:46:52 INFO Signed narinfos id=2 count=112582026/10/14 16:46:52 INFO Uploading 1 narinfos12592026/10/14 16:46:52 INFO Received complete push request method=POST path=/api/pushes/2/complete12602026/10/14 16:46:52 WARN Failed to register uploaded object key=j4vqvyllmbbf1sn9lvrm80xygm4bxa09.narinfo error="server returned 404: 404 page not found\n"12612026/10/14 16:46:52 INFO Completed push id=2 objects=3 duration=1.03025ms12622026/10/14 16:46:52 INFO Upload complete. (221ms)12632026/10/14 16:46:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures12642026/10/14 16:46:52 INFO Garbage collection started12652026/10/14 16:46:52 INFO Aborted multipart uploads count=0 kept=012662026/10/14 16:46:52 WARN Force mode enabled - objects will be deleted immediately without grace period12672026/10/14 16:46:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=012682026/10/14 16:46:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12692026/10/14 16:46:53 INFO Vacuumed table table=pending_closures12702026/10/14 16:46:53 INFO Vacuumed table table=pending_objects12712026/10/14 16:46:53 INFO Vacuumed table table=multipart_uploads12722026/10/14 16:46:53 INFO Received uploads request method=POST path=/api/pending_closures12732026/10/14 16:46:53 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTFmOTI1MmUtNmY0ZS00N2MzLTg1MTUtMjg3ZGUxNjkzMDdjLjc3ZTVjNDc3LTYwZDAtNDlmMS1iNTBhLTQ0ZjFiYjVhNDZiN3gxNzkxOTk2NDExMjQ1MzAyMDAw parts=1012742026/10/14 16:46:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12752026/10/14 16:46:53 INFO Vacuumed table table=closures12762026/10/14 16:46:53 INFO Vacuumed table table=objects12772026/10/14 16:46:53 INFO Completed upload id=1 objects=2 duration=26.564042ms12782026/10/14 16:46:53 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012792026/10/14 16:46:53 INFO Received uploads request method=POST path=/api/pending_closures12802026/10/14 16:46:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures12812026/10/14 16:46:53 INFO Aborted multipart uploads count=0 kept=012822026/10/14 16:46:53 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=012832026/10/14 16:46:53 INFO Vacuumed table table=pending_closures12842026/10/14 16:46:53 INFO Vacuumed table table=pending_objects12852026/10/14 16:46:53 INFO Vacuumed table table=multipart_uploads12862026/10/14 16:46:53 INFO Vacuumed table table=closures12872026/10/14 16:46:53 INFO Vacuumed table table=objects12882026/10/14 16:46:53 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001289--- PASS: TestService_createPendingClosureHandler (8.67s)1290=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12912026/10/14 16:46:53 INFO Received uploads request method=POST path=/api/pending_closures1292--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.81s)1293=== CONT TestService_AuthMiddleware_MTLSProxyHeader12942026/10/14 16:46:53 INFO Received push request method=POST path=/api/pushes12952026/10/14 16:46:53 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12962026/10/14 16:46:53 INFO Uploading x9slr0qrxz8c80n615lsabqhw1vvmq6p-shared-dep (136B)12972026/10/14 16:46:53 INFO Uploading 3yzrv9rakcbl3lv9my8m9cp1ifqh9s0b-top (264B)12982026/10/14 16:46:53 WARN Failed to register uploaded object key=3yzrv9rakcbl3lv9my8m9cp1ifqh9s0b.ls error="server returned 404: 404 page not found\n"12992026/10/14 16:46:53 WARN Failed to register uploaded object key=nar/06bcwrgw9jq7fnj4c64j9lvr22mzx6957bwm8vs4vlnwaal9qwws.nar.zst error="server returned 404: 404 page not found\n"13002026/10/14 16:46:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13012026/10/14 16:46:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13022026/10/14 16:46:53 WARN Failed to register uploaded object key=x9slr0qrxz8c80n615lsabqhw1vvmq6p.ls error="server returned 404: 404 page not found\n"13032026/10/14 16:46:53 INFO Signed narinfos id=1 count=213042026/10/14 16:46:53 INFO Uploading 2 narinfos13052026/10/14 16:46:53 WARN Failed to register uploaded object key=x9slr0qrxz8c80n615lsabqhw1vvmq6p.narinfo error="server returned 404: 404 page not found\n"13062026/10/14 16:46:53 INFO Received complete push request method=POST path=/api/pushes/1/complete13072026/10/14 16:46:53 WARN Failed to register uploaded object key=3yzrv9rakcbl3lv9my8m9cp1ifqh9s0b.narinfo error="server returned 404: 404 page not found\n"13082026/10/14 16:46:53 INFO Completed push id=1 objects=6 duration=32.451125ms13092026/10/14 16:46:53 INFO Upload complete. (369ms)1310=== NAME TestClientSharedPathCommittedMidPush1311 client_integration_test.go:680: Retrieved narinfo from S3:1312 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientSharedPathCommittedMidPush604016832/001/store/x9slr0qrxz8c80n615lsabqhw1vvmq6p-shared-dep1313 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1314 Compression: zstd1315 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821316 NarSize: 1361317 References: 1318 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1319 client_integration_test.go:680: Retrieved narinfo from S3:1320 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientSharedPathCommittedMidPush604016832/001/store/3yzrv9rakcbl3lv9my8m9cp1ifqh9s0b-top1321 URL: nar/06bcwrgw9jq7fnj4c64j9lvr22mzx6957bwm8vs4vlnwaal9qwws.nar.zst1322 Compression: zstd1323 NarHash: sha256:06bcwrgw9jq7fnj4c64j9lvr22mzx6957bwm8vs4vlnwaal9qwws1324 NarSize: 2641325 References: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientSharedPathCommittedMidPush604016832/001/store/x9slr0qrxz8c80n615lsabqhw1vvmq6p-shared-dep1326 CA: text:sha256:083c3hk6rs0f2i9lsbv150z93dkgv205ks0pqh9zkxa0gidz635y13272026/10/14 16:46:53 INFO Aborted multipart uploads count=0 kept=013282026/10/14 16:46:53 WARN Force mode enabled - objects will be deleted immediately without grace period13292026/10/14 16:46:53 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13302026/10/14 16:46:53 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1331--- PASS: TestFailedS3DeleteKeepsTombstone (7.35s)1332=== CONT TestService_RequireScope_OIDC1333--- PASS: TestClientSharedPathCommittedMidPush (7.89s)1334=== CONT TestClientMultipleUploads13352026/10/14 16:46:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59223/oidc1336--- PASS: TestReadProxyNarinfoAlreadyDecompressed (7.24s)1337=== CONT TestService_AuthMiddleware_OIDC13382026/10/14 16:46:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59230/oidc1339=== NAME TestClientWithDependencies1340 client_integration_test.go:613: Built derivation: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientWithDependencies613589040/001/store/9p4y43jf2k5iwy1d1nzxpn7l2j3biz19-test-script1341 client_integration_test.go:615: Found 1 dependencies (including self)1342--- PASS: TestReadProxyInvalidPath (7.16s)1343=== CONT TestParseSize1344--- PASS: TestParseSize (0.00s)1345=== CONT TestProxyWriteTimeout1346=== RUN TestProxyWriteTimeout/narinfo1347=== PAUSE TestProxyWriteTimeout/narinfo1348=== RUN TestProxyWriteTimeout/1_GiB_nar1349=== PAUSE TestProxyWriteTimeout/1_GiB_nar1350=== RUN TestProxyWriteTimeout/10_GiB_nar1351=== PAUSE TestProxyWriteTimeout/10_GiB_nar1352=== RUN TestProxyWriteTimeout/unknown_size1353=== PAUSE TestProxyWriteTimeout/unknown_size1354=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle13552026/10/14 16:46:54 INFO Received push request method=POST path=/api/pushes13562026/10/14 16:46:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13572026/10/14 16:46:54 INFO Uploading 9p4y43jf2k5iwy1d1nzxpn7l2j3biz19-test-script (136B)13582026/10/14 16:46:54 WARN Failed to register uploaded object key=9p4y43jf2k5iwy1d1nzxpn7l2j3biz19.ls error="server returned 404: 404 page not found\n"13592026/10/14 16:46:54 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13602026/10/14 16:46:54 WARN Failed to register uploaded object key=log/pqv5hj6iqx7w9gy9v80s7wbj7wbn1fq8-test-script.drv error="server returned 404: 404 page not found\n"13612026/10/14 16:46:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13622026/10/14 16:46:54 INFO Signed narinfos id=1 count=113632026/10/14 16:46:54 INFO Uploading 1 narinfos13642026/10/14 16:46:54 INFO Received uploads request method=POST path=/api/pending_closures13652026/10/14 16:46:54 INFO Received complete push request method=POST path=/api/pushes/1/complete13662026/10/14 16:46:54 WARN Failed to register uploaded object key=9p4y43jf2k5iwy1d1nzxpn7l2j3biz19.narinfo error="server returned 404: 404 page not found\n"13672026/10/14 16:46:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=013682026/10/14 16:46:54 INFO Received create pin request method=POST path=/api/pins/myapp13692026/10/14 16:46:54 INFO Completed push id=1 objects=4 duration=52.03375ms1370--- PASS: TestTombstonedObjectOfferedWithoutWaiting (7.48s)1371=== CONT TestSkippedUploadsHandler13722026/10/14 16:46:54 INFO Upload complete. (327ms)13732026/10/14 16:46:54 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001374--- PASS: TestSkippedUploadsHandler (0.00s)1375=== CONT TestService_healthCheckHandler1376=== NAME TestClientWithDependencies1377 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/3/scratch/641c288d84b756d0/build/TestClientWithDependencies613589040/001/store) requires matching store prefix13782026/10/14 16:46:54 INFO Created/updated pin name=myapp store_path=/private/var/tb/3/scratch/641c288d84b756d0/build/TestPinProtectsFromGC1000115381/001/store/3k4y5mkp2jbrcwnzinsim4rhi8jvyxc0-pinned-file.txt narinfo_key=3k4y5mkp2jbrcwnzinsim4rhi8jvyxc0.narinfo13792026/10/14 16:46:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures13802026/10/14 16:46:54 INFO Garbage collection started13812026/10/14 16:46:54 INFO Aborted multipart uploads count=0 kept=013822026/10/14 16:46:54 WARN Force mode enabled - objects will be deleted immediately without grace period13832026/10/14 16:46:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013842026/10/14 16:46:54 INFO Vacuumed table table=pending_closures13852026/10/14 16:46:54 INFO Vacuumed table table=pending_objects13862026/10/14 16:46:54 INFO Vacuumed table table=multipart_uploads13872026/10/14 16:46:54 INFO Vacuumed table table=closures13882026/10/14 16:46:54 INFO Vacuumed table table=objects1389--- PASS: TestClientWithDependencies (8.33s)1390=== CONT TestService_NativeMTLS13912026/10/14 16:46:55 INFO Aborted multipart uploads count=0 kept=013922026/10/14 16:46:55 WARN Force mode enabled - objects will be deleted immediately without grace period13932026/10/14 16:46:55 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=013942026/10/14 16:46:55 INFO Vacuumed table table=pending_closures13952026/10/14 16:46:55 INFO Vacuumed table table=pending_objects13962026/10/14 16:46:55 INFO Vacuumed table table=multipart_uploads13972026/10/14 16:46:55 INFO Vacuumed table table=closures1398--- PASS: TestReadProxyNarStreaming (6.52s)1399=== CONT TestGenerateLandingPage1400--- PASS: TestGenerateLandingPage (0.00s)1401=== CONT TestCreatePin_ReservedPins14022026/10/14 16:46:55 INFO Vacuumed table table=objects1403--- PASS: TestGCSweepDeliversEachKeyOnce (8.32s)1404=== CONT TestCacheConfigHandlerMaxNarSize1405--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1406=== CONT TestService_readinessHandler14072026/10/14 16:46:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59253/oidc1408--- PASS: TestReadProxy404 (6.99s)1409=== CONT TestMetricsCommit1410--- PASS: TestReadProxyContentNegotiation (6.84s)1411=== CONT TestOrphanedObjectsGCStressTest14122026/10/14 16:46:56 INFO Aborted multipart uploads count=0 kept=014132026/10/14 16:46:56 WARN Force mode enabled - objects will be deleted immediately without grace period14142026/10/14 16:46:56 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=014152026/10/14 16:46:56 INFO Vacuumed table table=pending_closures14162026/10/14 16:46:56 INFO Vacuumed table table=pending_objects14172026/10/14 16:46:56 INFO Vacuumed table table=multipart_uploads14182026/10/14 16:46:56 INFO Vacuumed table table=closures14192026/10/14 16:46:56 INFO Vacuumed table table=objects1420--- PASS: TestGCMetrics (7.10s)1421=== CONT TestPendingCleanupUsesOneCutoff14222026/10/14 16:46:56 INFO Received uploads request method=POST path=/api/pending_closures1423--- PASS: TestDeduplicatedObjectsRecordedAsPending (7.28s)1424=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1425=== NAME TestPinProtectsFromGC1426 client_integration_test.go:840: Pin successfully protected closure from garbage collection1427--- PASS: TestPinProtectsFromGC (12.15s)1428=== CONT TestOrphanedObjectsGC14292026/10/14 16:46:57 INFO Received uploads request method=POST path=/api/pending_closures14302026/10/14 16:46:57 INFO Aborted multipart uploads count=0 kept=014312026/10/14 16:46:57 INFO Received uploads request method=POST path=/api/pending_closures14322026/10/14 16:46:57 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=014332026/10/14 16:46:57 INFO Vacuumed table table=pending_closures14342026/10/14 16:46:57 INFO Vacuumed table table=pending_objects14352026/10/14 16:46:57 INFO Vacuumed table table=multipart_uploads14362026/10/14 16:46:57 INFO Vacuumed table table=closures14372026/10/14 16:46:57 INFO Aborted multipart uploads count=0 kept=014382026/10/14 16:46:57 INFO Vacuumed table table=objects14392026/10/14 16:46:57 WARN Force mode enabled - objects will be deleted immediately without grace period14402026/10/14 16:46:57 INFO Aborted multipart uploads count=0 kept=014412026/10/14 16:46:57 WARN Force mode enabled - objects will be deleted immediately without grace period14422026/10/14 16:46:57 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=014432026/10/14 16:46:57 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=014442026/10/14 16:46:57 INFO Vacuumed table table=pending_closures14452026/10/14 16:46:57 INFO Vacuumed table table=pending_closures14462026/10/14 16:46:57 INFO Vacuumed table table=pending_objects14472026/10/14 16:46:57 INFO Vacuumed table table=multipart_uploads14482026/10/14 16:46:57 INFO Vacuumed table table=pending_objects14492026/10/14 16:46:57 INFO Vacuumed table table=closures14502026/10/14 16:46:57 INFO Vacuumed table table=multipart_uploads14512026/10/14 16:46:57 INFO Vacuumed table table=objects14522026/10/14 16:46:57 INFO Vacuumed table table=closures1453--- PASS: TestPushDedupSurvivesConcurrentGC (7.97s)1454=== CONT TestMultipartCleanup14552026/10/14 16:46:57 INFO Vacuumed table table=objects1456--- PASS: TestGCSweepSkipsPendingObjects (7.76s)1457=== CONT TestObjectStatsLargeCommit1458--- PASS: TestService_ReadScope_PublicByDefault (6.84s)1459=== CONT TestMetricsInventory1460--- PASS: TestGCBugBareHashReferences (7.67s)1461=== CONT TestServerTLSConfig1462=== RUN TestServerTLSConfig/no_client_CA1463=== PAUSE TestServerTLSConfig/no_client_CA1464=== RUN TestServerTLSConfig/missing_CA_file1465=== PAUSE TestServerTLSConfig/missing_CA_file1466=== RUN TestServerTLSConfig/not_a_PEM_file1467=== PAUSE TestServerTLSConfig/not_a_PEM_file1468=== CONT TestObjectStatsTrigger1469=== NAME TestClientIntegration1470 client_integration_test.go:286: Created store path: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientIntegration2093460076/002/store/i6m75vvsx53sa0szsybarip92a2yvjkd-test-file.txt14712026/10/14 16:46:58 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld3 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1472--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (6.93s)1473=== CONT TestNARDeduplicationMetadataUploadBug14742026/10/14 16:46:58 INFO Received push request method=POST path=/api/pushes14752026/10/14 16:46:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14762026/10/14 16:46:58 INFO Uploading i6m75vvsx53sa0szsybarip92a2yvjkd-test-file.txt (152B)14772026/10/14 16:46:58 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14782026/10/14 16:46:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14792026/10/14 16:46:58 WARN Failed to register uploaded object key=i6m75vvsx53sa0szsybarip92a2yvjkd.ls error="server returned 404: 404 page not found\n"14802026/10/14 16:46:58 INFO Signed narinfos id=1 count=114812026/10/14 16:46:58 INFO Uploading 1 narinfos14822026/10/14 16:46:58 INFO Received complete push request method=POST path=/api/pushes/1/complete14832026/10/14 16:46:58 WARN Failed to register uploaded object key=i6m75vvsx53sa0szsybarip92a2yvjkd.narinfo error="server returned 404: 404 page not found\n"14842026/10/14 16:46:58 INFO Completed push id=1 objects=3 duration=22.948291ms14852026/10/14 16:46:58 INFO Upload complete. (248ms)14862026/10/14 16:46:58 INFO All 1 paths already cached1487=== NAME TestClientIntegration1488 client_integration_test.go:312: Retrieved narinfo from S3:1489 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientIntegration2093460076/002/store/i6m75vvsx53sa0szsybarip92a2yvjkd-test-file.txt1490 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1491 Compression: zstd1492 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11493 NarSize: 1521494 References: 1495 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11496 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1497 client_integration_test.go:313: Decompressed .ls content (64 bytes):1498 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1499 client_integration_test.go:316: Testing garbage collection...15002026/10/14 16:46:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures15012026/10/14 16:46:58 INFO Garbage collection started15022026/10/14 16:46:58 INFO Aborted multipart uploads count=0 kept=015032026/10/14 16:46:58 WARN Force mode enabled - objects will be deleted immediately without grace period1504--- PASS: TestCacheStatsHandler (6.42s)1505=== CONT TestPresignedUploadRegisteredBeforeCommit15062026/10/14 16:46:58 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=015072026/10/14 16:46:58 INFO Vacuumed table table=pending_closures1508--- PASS: TestService_ReadAuthMiddleware (6.35s)1509=== CONT TestCreatePendingClosureRejectsOversizedNAR15102026/10/14 16:46:58 INFO Received uploads request method=POST path=/api/pending_closures1511--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1512=== CONT TestService_Rustfstest15132026/10/14 16:46:58 INFO Vacuumed table table=pending_objects15142026/10/14 16:46:58 INFO Vacuumed table table=multipart_uploads15152026/10/14 16:46:58 INFO Vacuumed table table=closures15162026/10/14 16:46:58 INFO Vacuumed table table=objects15172026/10/14 16:46:59 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15182026/10/14 16:46:59 WARN mTLS auth: bound subjects configured but subject DN unavailable15192026/10/14 16:46:59 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1520--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (6.13s)1521=== CONT TestGracefulShutdownDrainsInflight15222026/10/14 16:46:59 INFO Starting HTTP server address=127.0.0.1:5929715232026/10/14 16:46:59 INFO Shutdown signal received, draining in-flight requests timeout=10s1524--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1525=== CONT TestGCTaskStore_Fail1526--- PASS: TestGCTaskStore_Fail (0.00s)1527=== CONT TestParseSingleRange1528=== RUN TestParseSingleRange/none1529=== PAUSE TestParseSingleRange/none1530=== RUN TestParseSingleRange/unknown_unit1531=== PAUSE TestParseSingleRange/unknown_unit1532=== RUN TestParseSingleRange/multi-range_ignored1533=== PAUSE TestParseSingleRange/multi-range_ignored1534=== RUN TestParseSingleRange/malformed_no_dash1535=== PAUSE TestParseSingleRange/malformed_no_dash1536=== RUN TestParseSingleRange/malformed_both_empty1537=== PAUSE TestParseSingleRange/malformed_both_empty1538=== RUN TestParseSingleRange/malformed_end_before_start1539=== PAUSE TestParseSingleRange/malformed_end_before_start1540=== RUN TestParseSingleRange/closed1541=== PAUSE TestParseSingleRange/closed1542=== RUN TestParseSingleRange/open-ended1543=== PAUSE TestParseSingleRange/open-ended1544=== RUN TestParseSingleRange/end_clamped_to_size1545=== PAUSE TestParseSingleRange/end_clamped_to_size1546=== RUN TestParseSingleRange/suffix1547=== PAUSE TestParseSingleRange/suffix1548=== RUN TestParseSingleRange/suffix_exceeds_size1549=== PAUSE TestParseSingleRange/suffix_exceeds_size1550=== RUN TestParseSingleRange/single_byte1551=== PAUSE TestParseSingleRange/single_byte1552=== RUN TestParseSingleRange/start_past_EOF1553=== PAUSE TestParseSingleRange/start_past_EOF1554=== RUN TestParseSingleRange/start_far_past_EOF1555=== PAUSE TestParseSingleRange/start_far_past_EOF1556=== CONT TestReadProxyNarinfo1557--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (6.36s)1558=== CONT TestIsValidCachePath1559=== RUN TestIsValidCachePath/narinfo1560=== PAUSE TestIsValidCachePath/narinfo1561=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1562=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1563=== RUN TestIsValidCachePath/nar_zst1564=== PAUSE TestIsValidCachePath/nar_zst1565=== RUN TestIsValidCachePath/nar_xz1566=== PAUSE TestIsValidCachePath/nar_xz1567=== RUN TestIsValidCachePath/nar_bz21568=== PAUSE TestIsValidCachePath/nar_bz21569=== RUN TestIsValidCachePath/nar_uncompressed1570=== PAUSE TestIsValidCachePath/nar_uncompressed1571=== RUN TestIsValidCachePath/ls1572=== PAUSE TestIsValidCachePath/ls1573=== RUN TestIsValidCachePath/log1574=== PAUSE TestIsValidCachePath/log1575=== RUN TestIsValidCachePath/realisation1576=== PAUSE TestIsValidCachePath/realisation1577=== RUN TestIsValidCachePath/nix-cache-info1578=== PAUSE TestIsValidCachePath/nix-cache-info1579=== RUN TestIsValidCachePath/index.html1580=== PAUSE TestIsValidCachePath/index.html1581=== RUN TestIsValidCachePath/traversal_parent1582=== PAUSE TestIsValidCachePath/traversal_parent1583=== RUN TestIsValidCachePath/traversal_in_middle1584=== PAUSE TestIsValidCachePath/traversal_in_middle1585=== RUN TestIsValidCachePath/invalid_char_e1586=== PAUSE TestIsValidCachePath/invalid_char_e1587=== RUN TestIsValidCachePath/invalid_char_u1588=== PAUSE TestIsValidCachePath/invalid_char_u1589=== RUN TestIsValidCachePath/random_path1590=== PAUSE TestIsValidCachePath/random_path1591=== RUN TestIsValidCachePath/empty1592=== PAUSE TestIsValidCachePath/empty1593=== RUN TestIsValidCachePath/leading_slash1594=== PAUSE TestIsValidCachePath/leading_slash1595=== RUN TestIsValidCachePath/wrong_extension1596=== PAUSE TestIsValidCachePath/wrong_extension1597=== RUN TestIsValidCachePath/short_hash1598=== PAUSE TestIsValidCachePath/short_hash1599=== CONT TestPresentNotReportedWhileGCDeletesClosure1600=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1601=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1602=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1603=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1604=== CONT TestPresentRefreshesOnlyStaleClosures1605=== NAME TestClientCADerivations1606 client_ca_test.go:136: Built CA derivation: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientCADerivations639370764/001/store/zsfzbk8pnwds1763l4cp2cq5kjb3ky95-ca-test1607 client_ca_test.go:139: Found 1 dependencies (including self)16082026/10/14 16:47:00 INFO Received push request method=POST path=/api/pushes16092026/10/14 16:47:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16102026/10/14 16:47:00 INFO Uploading zsfzbk8pnwds1763l4cp2cq5kjb3ky95-ca-test (144B)16112026/10/14 16:47:00 WARN Failed to register uploaded object key=zsfzbk8pnwds1763l4cp2cq5kjb3ky95.ls error="server returned 404: 404 page not found\n"16122026/10/14 16:47:00 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16132026/10/14 16:47:00 WARN Failed to register uploaded object key=log/apigd2xi6wjmj1zh2j1yyxi0lr3hsk5c-ca-test.drv error="server returned 404: 404 page not found\n"16142026/10/14 16:47:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16152026/10/14 16:47:00 INFO Signed narinfos id=1 count=116162026/10/14 16:47:00 INFO Uploading 1 narinfos16172026/10/14 16:47:00 INFO Received complete push request method=POST path=/api/pushes/1/complete16182026/10/14 16:47:00 WARN Failed to register uploaded object key=zsfzbk8pnwds1763l4cp2cq5kjb3ky95.narinfo error="server returned 404: 404 page not found\n"16192026/10/14 16:47:00 INFO Completed push id=1 objects=4 duration=27.459208ms16202026/10/14 16:47:00 INFO Upload complete. (362ms)1621 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientCADerivations639370764/001/store/zsfzbk8pnwds1763l4cp2cq5kjb3ky95-ca-test1622 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1623 Compression: zstd1624 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1625 NarSize: 1441626 References: 1627 Deriver: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientCADerivations639370764/001/store/apigd2xi6wjmj1zh2j1yyxi0lr3hsk5c-ca-test.drv1628 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1629 client_ca_test.go:185: Checking for realisation files in S3...1630 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1631 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1632=== NAME TestClientMultipleUploads1633 client_integration_test.go:358: Created store path 0: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientMultipleUploads2289584858/001/store/izn7454pfyz6sv1wi8mllci53bvbybsb-test-file-0.txt1634=== RUN TestService_RequireScope_OIDC/builder_may_write1635=== PAUSE TestService_RequireScope_OIDC/builder_may_write1636=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1637=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1638=== RUN TestService_RequireScope_OIDC/ops_may_admin1639=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1640=== RUN TestService_RequireScope_OIDC/ops_may_not_write1641=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1642=== RUN TestService_RequireScope_OIDC/reader_may_not_write1643=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1644=== RUN TestService_RequireScope_OIDC/static_token_may_admin1645=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1646=== RUN TestService_RequireScope_OIDC/static_token_may_write1647=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1648=== RUN TestService_RequireScope_OIDC/reader_may_read1649=== PAUSE TestService_RequireScope_OIDC/reader_may_read1650=== RUN TestService_RequireScope_OIDC/writer_implies_read1651=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1652=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1653=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1654=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1655=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1656=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1657=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1658=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1659=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1660=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1661=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1662=== CONT TestCompletedNarNotReofferedAcrossClosures1663=== NAME TestClientCADerivations1664 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket64?endpoint=http://localhost:58990®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/3/scratch/641c288d84b756d0/build/TestClientCADerivations639370764/001/store'1665 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11666=== NAME TestClientMultipleUploads1667 client_integration_test.go:358: Created store path 1: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientMultipleUploads2289584858/001/store/iqmcmyb3xczzzdnbjfkinpk1a0vana56-test-file-1.txt1668--- PASS: TestClientCADerivations (8.28s)1669=== CONT TestCompleteMultipartUpload_ErrorButObjectExists16702026/10/14 16:47:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01671=== NAME TestClientIntegration1672 client_integration_test.go:323: Objects in database after GC:1673 client_integration_test.go:323: Successfully deleted all objects with GC --force1674=== NAME TestClientMultipleUploads1675 client_integration_test.go:358: Created store path 2: /private/var/tb/3/scratch/641c288d84b756d0/build/TestClientMultipleUploads2289584858/001/store/kj2npdm49dmfxhg6akrizfdmxy98nzr6-test-file-2.txt1676--- PASS: TestClientIntegration (9.76s)1677=== CONT TestResolveDBConnectionString/flag_wins1678=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1679=== CONT TestResolveDBConnectionString/nothing_configured1680=== CONT TestResolveDBConnectionString/missing_file_is_an_error1681=== CONT TestResolveDBConnectionString/file_when_flag_empty1682=== CONT TestGCEndsOnShutdown/before_the_run1683--- PASS: TestResolveDBConnectionString (0.03s)1684 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1685 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1686 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1687 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1688 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)16892026/10/14 16:47:00 INFO Received push request method=POST path=/api/pushes1690=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1691=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1692=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1693=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1694=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1695=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1696=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1697=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1698=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16992026/10/14 16:47:00 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17002026/10/14 16:47:00 INFO Uploading izn7454pfyz6sv1wi8mllci53bvbybsb-test-file-0.txt (160B)17012026/10/14 16:47:00 INFO Uploading iqmcmyb3xczzzdnbjfkinpk1a0vana56-test-file-1.txt (160B)17022026/10/14 16:47:00 INFO Uploading kj2npdm49dmfxhg6akrizfdmxy98nzr6-test-file-2.txt (160B)17032026/10/14 16:47:00 WARN Failed to register uploaded object key=izn7454pfyz6sv1wi8mllci53bvbybsb.ls error="server returned 404: 404 page not found\n"17042026/10/14 16:47:00 WARN Failed to register uploaded object key=kj2npdm49dmfxhg6akrizfdmxy98nzr6.ls error="server returned 404: 404 page not found\n"17052026/10/14 16:47:00 WARN Failed to register uploaded object key=iqmcmyb3xczzzdnbjfkinpk1a0vana56.ls error="server returned 404: 404 page not found\n"17062026/10/14 16:47:00 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17072026/10/14 16:47:00 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17082026/10/14 16:47:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17092026/10/14 16:47:00 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17102026/10/14 16:47:00 INFO Signed narinfos id=1 count=317112026/10/14 16:47:00 INFO Uploading 3 narinfos17122026/10/14 16:47:00 WARN Failed to register uploaded object key=kj2npdm49dmfxhg6akrizfdmxy98nzr6.narinfo error="server returned 404: 404 page not found\n"17132026/10/14 16:47:00 WARN Failed to register uploaded object key=izn7454pfyz6sv1wi8mllci53bvbybsb.narinfo error="server returned 404: 404 page not found\n"17142026/10/14 16:47:00 INFO Received complete push request method=POST path=/api/pushes/1/complete17152026/10/14 16:47:00 WARN Failed to register uploaded object key=iqmcmyb3xczzzdnbjfkinpk1a0vana56.narinfo error="server returned 404: 404 page not found\n"17162026/10/14 16:47:00 INFO Completed push id=1 objects=9 duration=33.292208ms17172026/10/14 16:47:00 INFO Upload complete. (314ms)1718=== NAME TestClientMultipleUploads1719 client_integration_test.go:369: Uploaded 3 paths in 358.861ms1720--- PASS: TestClientMultipleUploads (7.23s)1721=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17222026/10/14 16:47:01 INFO Received uploads request method=POST path=/api/pending_closures1723--- PASS: TestService_healthCheckHandler (6.65s)1724=== CONT TestPush_RejectsBadRequests/bad_root17252026/10/14 16:47:01 INFO Received push request method=POST path=/api/pushes1726=== CONT TestPush_RejectsBadRequests/no_roots17272026/10/14 16:47:01 INFO Received push request method=POST path=/api/pushes1728=== CONT TestPush_RejectsBadRequests/no_objects17292026/10/14 16:47:01 INFO Received push request method=POST path=/api/pushes1730=== CONT TestPush_RejectsBadRequests/root_not_in_objects17312026/10/14 16:47:01 INFO Received push request method=POST path=/api/pushes1732--- PASS: TestPush_RejectsBadRequests (2.73s)1733 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1734 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1735 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1736 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1737=== CONT TestPendingClosureWriteTimeout/empty1738=== CONT TestPendingClosureWriteTimeout/670k_objects1739=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17402026/10/14 16:47:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17412026/10/14 16:47:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17422026/10/14 16:47:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1743--- PASS: TestService_NativeMTLS (6.94s)1744=== CONT TestPendingClosureWriteTimeout/400_objects1745=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17462026/10/14 16:47:01 INFO Received uploads request method=POST path=/17472026/10/14 16:47:02 WARN readiness check failed error="closed pool"1748--- PASS: TestService_readinessHandler (6.62s)1749=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17502026/10/14 16:47:02 INFO Received request for more parts method=POST path=/1751=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17522026/10/14 16:47:02 INFO Received complete multipart upload request method=POST path=/1753=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17542026/10/14 16:47:02 INFO Received uploads request method=POST path=/1755=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17562026/10/14 16:47:02 INFO Received complete multipart upload request method=POST path=/1757=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17582026/10/14 16:47:02 INFO Received uploads request method=POST path=/1759=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17602026/10/14 16:47:02 INFO Received request for more parts method=POST path=/1761--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1762 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1763 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.01s)1764 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1765 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1766=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1767--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)1768 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1769 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1770 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.32s)1771=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17722026/10/14 16:47:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17732026/10/14 16:47:02 WARN Refused reserved pin name=worker-x86_64-linux17742026/10/14 16:47:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17752026/10/14 16:47:02 INFO Received create pin request method=POST path=/api/pins/my-app17762026/10/14 16:47:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1777--- PASS: TestCreatePin_ReservedPins (6.95s)1778=== CONT TestIsValidUploadKey/narinfo1779=== CONT TestIsValidUploadKey/realisation_plus_in_output1780=== CONT TestIsValidUploadKey/unknown_type1781=== CONT TestIsValidUploadKey/empty_key1782=== CONT TestIsValidUploadKey/absolute1783=== CONT TestIsValidUploadKey/traversal_nar1784=== CONT TestIsValidUploadKey/traversal1785=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1786=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1787=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1788=== CONT TestIsValidUploadKey/index.html1789=== CONT TestIsValidUploadKey/nix-cache-info1790=== CONT TestIsValidUploadKey/build_log_home-manager_file1791=== CONT TestIsValidUploadKey/realisation1792=== CONT TestIsValidUploadKey/build_log_equals1793=== CONT TestIsValidUploadKey/build_log_question_mark1794=== CONT TestIsValidUploadKey/build_log_plus_in_name1795=== CONT TestIsValidUploadKey/nar_plain1796=== CONT TestIsValidUploadKey/build_log1797=== CONT TestIsValidUploadKey/listing1798=== CONT TestIsValidUploadKey/nar_zst1799=== CONT TestIsValidUploadKey/nar_xz1800--- PASS: TestIsValidUploadKey (0.02s)1801 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1802 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1803 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1804 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1805 --- PASS: TestIsValidUploadKey/absolute (0.00s)1806 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1807 --- PASS: TestIsValidUploadKey/traversal (0.00s)1808 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1809 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1810 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1811 --- PASS: TestIsValidUploadKey/index.html (0.00s)1812 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1813 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1814 --- PASS: TestIsValidUploadKey/realisation (0.00s)1815 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1816 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1817 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1818 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1819 --- PASS: TestIsValidUploadKey/build_log (0.00s)1820 --- PASS: TestIsValidUploadKey/listing (0.00s)1821 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1822 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1823=== CONT TestClientErrorHandling/InvalidStorePath18242026/10/14 16:47:02 INFO Received push request method=POST path=/api/pushes18252026/10/14 16:47:02 INFO Received complete push request method=POST path=/api/pushes/1/complete18262026/10/14 16:47:02 INFO Completed push id=1 objects=4 duration=43.777834ms18272026/10/14 16:47:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18282026/10/14 16:47:03 INFO Completed upload id=2 objects=2 duration=4.072416ms1829--- PASS: TestMetricsCommit (7.13s)1830=== CONT TestClientErrorHandling/ServerNotAvailable18312026/10/14 16:47:03 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/present18322026/10/14 16:47:03 INFO Received uploads request method=POST path=/api/pending_closures18332026/10/14 16:47:03 WARN Request failed, retrying attempt=2 backoff=185.891258ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18342026/10/14 16:47:03 INFO Received uploads request method=POST path=/api/pending_closures18352026/10/14 16:47:03 WARN Request failed, retrying attempt=3 backoff=367.650466ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18362026/10/14 16:47:03 INFO Received cleanup request method=DELETE path=/api/pending_closures18372026/10/14 16:47:03 INFO Received uploads request method=POST path=/api/pending_closures18382026/10/14 16:47:04 WARN Request failed, retrying attempt=4 backoff=842.492232ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1839--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (7.45s)1840=== CONT TestClientErrorHandling/InvalidAuthToken18412026/10/14 16:47:04 INFO Received uploads request method=POST path=/api/pending_closures18422026/10/14 16:47:04 WARN Request failed, retrying attempt=5 backoff=1.646436437s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18432026/10/14 16:47:05 INFO Received cleanup request method=DELETE path=/api/pending_closures18442026/10/14 16:47:05 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket80/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18452026/10/14 16:47:05 INFO Aborted multipart uploads count=0 kept=118462026/10/14 16:47:05 INFO Received cleanup request method=DELETE path=/api/pending_closures18472026/10/14 16:47:05 INFO Aborted multipart uploads count=1 kept=01848--- PASS: TestMultipartCleanup (7.77s)1849=== CONT TestCacheConfigHandler/full_config,_no_issuer1850=== CONT TestCacheConfigHandler/no_signing_keys1851=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1852=== CONT TestCacheConfigHandler/no_cache_url_configured1853--- PASS: TestCacheConfigHandler (0.00s)1854 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1855 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1856 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1857 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1858=== CONT TestProxyWriteTimeout/narinfo1859=== CONT TestProxyWriteTimeout/10_GiB_nar1860=== CONT TestProxyWriteTimeout/unknown_size1861=== CONT TestProxyWriteTimeout/1_GiB_nar1862--- PASS: TestProxyWriteTimeout (0.00s)1863 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1864 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1865 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1866 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1867=== CONT TestServerTLSConfig/no_client_CA1868=== CONT TestServerTLSConfig/not_a_PEM_file1869=== CONT TestServerTLSConfig/missing_CA_file1870--- PASS: TestServerTLSConfig (0.00s)1871 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1872 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1873 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1874=== CONT TestParseSingleRange/none1875=== CONT TestParseSingleRange/open-ended1876=== CONT TestParseSingleRange/start_far_past_EOF1877=== CONT TestParseSingleRange/start_past_EOF1878=== CONT TestParseSingleRange/single_byte1879=== CONT TestParseSingleRange/suffix_exceeds_size1880=== CONT TestParseSingleRange/suffix1881=== CONT TestParseSingleRange/end_clamped_to_size1882=== CONT TestParseSingleRange/malformed_both_empty1883=== CONT TestParseSingleRange/closed1884=== CONT TestParseSingleRange/malformed_end_before_start1885=== CONT TestParseSingleRange/multi-range_ignored1886=== CONT TestParseSingleRange/malformed_no_dash1887=== CONT TestParseSingleRange/unknown_unit1888--- PASS: TestParseSingleRange (0.01s)1889 --- PASS: TestParseSingleRange/none (0.00s)1890 --- PASS: TestParseSingleRange/open-ended (0.00s)1891 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1892 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1893 --- PASS: TestParseSingleRange/single_byte (0.00s)1894 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1895 --- PASS: TestParseSingleRange/suffix (0.00s)1896 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1897 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1898 --- PASS: TestParseSingleRange/closed (0.00s)1899 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1900 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1901 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1902 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1903=== CONT TestIsValidCachePath/narinfo1904=== CONT TestIsValidCachePath/index.html1905=== CONT TestIsValidCachePath/short_hash1906=== CONT TestIsValidCachePath/wrong_extension1907=== CONT TestIsValidCachePath/leading_slash1908=== CONT TestIsValidCachePath/empty1909=== CONT TestIsValidCachePath/random_path1910=== CONT TestIsValidCachePath/invalid_char_u1911=== CONT TestIsValidCachePath/invalid_char_e1912=== CONT TestIsValidCachePath/traversal_in_middle1913=== CONT TestIsValidCachePath/traversal_parent1914=== CONT TestIsValidCachePath/nar_uncompressed1915=== CONT TestIsValidCachePath/nix-cache-info1916=== CONT TestIsValidCachePath/realisation1917=== CONT TestIsValidCachePath/log1918=== CONT TestIsValidCachePath/ls1919=== CONT TestIsValidCachePath/nar_xz1920=== CONT TestIsValidCachePath/nar_bz21921=== CONT TestIsValidCachePath/nar_zst1922=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1923--- PASS: TestIsValidCachePath (0.00s)1924 --- PASS: TestIsValidCachePath/narinfo (0.00s)1925 --- PASS: TestIsValidCachePath/index.html (0.00s)1926 --- PASS: TestIsValidCachePath/short_hash (0.00s)1927 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1928 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1929 --- PASS: TestIsValidCachePath/empty (0.00s)1930 --- PASS: TestIsValidCachePath/random_path (0.00s)1931 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1932 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1933 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1934 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1935 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1936 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1937 --- PASS: TestIsValidCachePath/realisation (0.00s)1938 --- PASS: TestIsValidCachePath/log (0.00s)1939 --- PASS: TestIsValidCachePath/ls (0.00s)1940 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1941 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1942 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1943 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1944=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale19452026/10/14 16:47:05 WARN Rate limiter enabled after throttle name=s3-test rate=519462026/10/14 16:47:05 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1947=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1948 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101949 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001950--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (11.26s)1951=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1952--- PASS: TestMetricsInventory (8.38s)1953=== CONT TestService_RequireScope_OIDC/builder_may_write1954=== NAME TestOrphanedObjectsGC1955 orphaned_objects_gc_test.go:287: GC Test Summary:1956 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1957 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1958 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1959 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1960 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1961--- PASS: TestOrphanedObjectsGC (9.16s)1962=== CONT TestService_RequireScope_OIDC/static_token_may_write1963=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1964=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19652026/10/14 16:47:06 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]1966=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1967=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1968=== CONT TestService_RequireScope_OIDC/writer_implies_read1969=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1970=== CONT TestService_RequireScope_OIDC/reader_may_read1971=== CONT TestService_RequireScope_OIDC/reader_may_not_write1972=== CONT TestService_RequireScope_OIDC/static_token_may_admin1973=== CONT TestService_RequireScope_OIDC/ops_may_admin1974=== CONT TestService_RequireScope_OIDC/ops_may_not_write1975=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1976=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1977=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19782026/10/14 16:47:06 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]1979=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1980=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1981--- PASS: TestService_RequireScope_OIDC (6.62s)1982 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1983 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1984 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1985 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1986 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1987 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1988 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1989 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1990 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1991 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1992 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1993 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1994 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1995 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19962026/10/14 16:47:06 WARN Authentication failed token_preview=eyJhbGciOi...Prnkr85mVw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1997--- PASS: TestService_AuthMiddleware_OIDC (6.51s)1998 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1999 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2000 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.01s)2001 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2002--- PASS: TestObjectStatsTrigger (8.73s)20032026/10/14 16:47:06 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-config20042026/10/14 16:47:06 WARN Request failed, retrying attempt=2 backoff=212.67717ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20052026/10/14 16:47:06 WARN Request failed, retrying attempt=3 backoff=426.679159ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20062026/10/14 16:47:07 INFO Received uploads request method=POST path=/api/pending_closures2007=== NAME TestNARDeduplicationMetadataUploadBug2008 metadata_upload_test.go:48: First store path: /private/var/tb/3/scratch/641c288d84b756d0/build/TestNARDeduplicationMetadataUploadBug2215959505/001/store/7rx6l5ab29xwzmyj4rf83pxcgpj710c0-file1.txt20092026/10/14 16:47:07 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst20102026/10/14 16:47:07 INFO Received uploads request method=POST path=/api/pending_closures2011--- PASS: TestPresignedUploadRegisteredBeforeCommit (8.66s)20122026/10/14 16:47:07 WARN Request failed, retrying attempt=4 backoff=725.604846ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20132026/10/14 16:47:07 INFO Received push request method=POST path=/api/pushes20142026/10/14 16:47:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20152026/10/14 16:47:07 INFO Uploading 7rx6l5ab29xwzmyj4rf83pxcgpj710c0-file1.txt (160B)20162026/10/14 16:47:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20172026/10/14 16:47:07 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"20182026/10/14 16:47:07 WARN Failed to register uploaded object key=7rx6l5ab29xwzmyj4rf83pxcgpj710c0.ls error="server returned 404: 404 page not found\n"20192026/10/14 16:47:07 INFO Signed narinfos id=1 count=120202026/10/14 16:47:07 INFO Uploading 1 narinfos2021--- PASS: TestService_Rustfstest (8.72s)20222026/10/14 16:47:07 INFO Received complete push request method=POST path=/api/pushes/1/complete20232026/10/14 16:47:07 WARN Failed to register uploaded object key=7rx6l5ab29xwzmyj4rf83pxcgpj710c0.narinfo error="server returned 404: 404 page not found\n"20242026/10/14 16:47:07 INFO Completed push id=1 objects=3 duration=32.093208ms20252026/10/14 16:47:07 INFO Upload complete. (300ms)2026=== NAME TestNARDeduplicationMetadataUploadBug2027 metadata_upload_test.go:54: Retrieved narinfo from S3:2028 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestNARDeduplicationMetadataUploadBug2215959505/001/store/7rx6l5ab29xwzmyj4rf83pxcgpj710c0-file1.txt2029 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2030 Compression: zstd2031 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2032 NarSize: 1602033 References: 2034 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2035 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2036 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2037 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2038 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/3/scratch/641c288d84b756d0/build/TestNARDeduplicationMetadataUploadBug2215959505/001/store/5ydky7zcgb3795vqj5m0ffrr2pbcfclv-file2.txt20392026/10/14 16:47:07 INFO Received push request method=POST path=/api/pushes20402026/10/14 16:47:07 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20412026/10/14 16:47:08 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20422026/10/14 16:47:08 WARN Failed to register uploaded object key=5ydky7zcgb3795vqj5m0ffrr2pbcfclv.ls error="server returned 404: 404 page not found\n"20432026/10/14 16:47:08 INFO Signed narinfos id=2 count=120442026/10/14 16:47:08 INFO Uploading 1 narinfos20452026/10/14 16:47:08 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>2046--- PASS: TestReadProxyNarinfo (8.42s)20472026/10/14 16:47:08 INFO Received complete push request method=POST path=/api/pushes/2/complete20482026/10/14 16:47:08 WARN Failed to register uploaded object key=5ydky7zcgb3795vqj5m0ffrr2pbcfclv.narinfo error="server returned 404: 404 page not found\n"20492026/10/14 16:47:08 INFO Completed push id=2 objects=3 duration=697.25µs20502026/10/14 16:47:08 INFO Upload complete. (183ms)2051=== NAME TestNARDeduplicationMetadataUploadBug2052 metadata_upload_test.go:76: Retrieved narinfo from S3:2053 StorePath: /private/var/tb/3/scratch/641c288d84b756d0/build/TestNARDeduplicationMetadataUploadBug2215959505/001/store/5ydky7zcgb3795vqj5m0ffrr2pbcfclv-file2.txt2054 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2055 Compression: zstd2056 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2057 NarSize: 1602058 References: 2059 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2060 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2061 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2062 {"version":1,"root":{"type":"regular","size":44}}20632026/10/14 16:47:08 WARN Request failed, retrying attempt=5 backoff=1.463395912s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2064--- PASS: TestNARDeduplicationMetadataUploadBug (9.96s)2065--- PASS: TestPresentRefreshesOnlyStaleClosures (8.50s)20662026/10/14 16:47:08 INFO Received uploads request method=POST path=/api/pending_closures20672026/10/14 16:47:08 INFO Received uploads request method=POST path=/api/pending_closures20682026/10/14 16:47:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20692026/10/14 16:47:09 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTFmOTI1MmUtNmY0ZS00N2MzLTg1MTUtMjg3ZGUxNjkzMDdjLmY0ZDEwMmJkLWI4OTMtNDA1OS04ZjYyLTZkNWJkZjAyYTdkMHgxNzkxOTk2NDI4NjQzNTcxMDAw20702026/10/14 16:47:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTFmOTI1MmUtNmY0ZS00N2MzLTg1MTUtMjg3ZGUxNjkzMDdjLmY0ZDEwMmJkLWI4OTMtNDA1OS04ZjYyLTZkNWJkZjAyYTdkMHgxNzkxOTk2NDI4NjQzNTcxMDAw parts=12071--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (8.55s)20722026/10/14 16:47:09 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"20732026/10/14 16:47:09 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-config20742026/10/14 16:47:09 WARN Request failed, retrying attempt=2 backoff=199.609398ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20752026/10/14 16:47:09 INFO Aborted multipart uploads count=1 kept=020762026/10/14 16:47:09 INFO Received cleanup request method=DELETE path=/api/pending_closures20772026/10/14 16:47:09 INFO Aborted multipart uploads count=1 kept=02078--- PASS: TestPendingCleanupUsesOneCutoff (13.36s)20792026/10/14 16:47:09 INFO Aborted multipart uploads count=0 kept=020802026/10/14 16:47:09 WARN Force mode enabled - objects will be deleted immediately without grace period20812026-10-14 16:47:09.878 UTC [22312] ERROR: canceling statement due to user request20822026-10-14 16:47:09.878 UTC [22312] CONTEXT: SQL statement "UPDATE object_stats s2083 SET object_count = s.object_count + n.n - o.n,2084 total_bytes = s.total_bytes + n.bytes - o.bytes2085 FROM (2086 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2087 FROM new_rows WHERE deleted_at IS NULL2088 ) AS n,2089 (2090 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2091 FROM old_rows WHERE deleted_at IS NULL2092 ) AS o2093 WHERE s.id AND (n.n <> o.n OR n.bytes <> o.bytes)"2094 PL/pgSQL function object_stats_update() line 3 at SQL statement20952026-10-14 16:47:09.878 UTC [22312] STATEMENT: -- name: MarkStaleObjects :execrows2096 WITH RECURSIVE ct AS (2097 SELECT timezone('UTC', now()) AS now2098 ),2099 closure_reach AS (2100 -- Start with all closure keys2101 SELECT o.key, o.refs2102 FROM objects o2103 INNER JOIN closures c ON o.key = c.key2104 UNION2105 -- Recursively add all referenced objects2106 SELECT o.key, o.refs2107 FROM objects o2108 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2109 ),2110 reachable_objects AS (2111 SELECT DISTINCT key FROM closure_reach2112 ),2113 stale_objects AS (2114 SELECT o.key2115 FROM objects AS o, ct2116 WHERE2117 NOT EXISTS (2118 SELECT 12119 FROM reachable_objects ro2120 WHERE ro.key = o.key2121 )2122 AND NOT EXISTS (2123 SELECT 12124 FROM pending_objects AS po2125 WHERE po.key = o.key2126 )2127 AND o.deleted_at IS NULL -- Only mark fresh objects2128 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2129 FOR UPDATE2130 )2131 UPDATE objects2132 SET2133 deleted_at = ct.now,2134 first_deleted_at = COALESCE(first_deleted_at, ct.now)2135 FROM stale_objects, ct2136 WHERE objects.key = stale_objects.key2137 21382026/10/14 16:47:09 WARN Request failed, retrying attempt=3 backoff=434.90358ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21392026/10/14 16:47:10 INFO Aborted multipart uploads count=0 kept=021402026/10/14 16:47:10 WARN Force mode enabled - objects will be deleted immediately without grace period21412026/10/14 16:47:10 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:58990/bucket93/?delete=\": context canceled"2142--- PASS: TestGCEndsOnShutdown (0.00s)2143 --- PASS: TestGCEndsOnShutdown/before_the_run (8.74s)2144 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (9.17s)2145 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (9.11s)21462026/10/14 16:47:10 WARN Request failed, retrying attempt=4 backoff=745.062878ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21472026/10/14 16:47:10 INFO Received uploads request method=POST path=/api/pending_closures21482026/10/14 16:47:10 INFO Received uploads request method=POST path=/api/pending_closures21492026/10/14 16:47:10 INFO Aborted multipart uploads count=0 kept=021502026/10/14 16:47:10 WARN Force mode enabled - objects will be deleted immediately without grace period21512026/10/14 16:47:11 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=021522026/10/14 16:47:11 INFO Vacuumed table table=pending_closures21532026/10/14 16:47:11 INFO Vacuumed table table=pending_objects21542026/10/14 16:47:11 INFO Vacuumed table table=multipart_uploads21552026/10/14 16:47:11 INFO Vacuumed table table=closures21562026/10/14 16:47:11 INFO Vacuumed table table=objects21572026/10/14 16:47:11 WARN Request failed, retrying attempt=5 backoff=1.604379269s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21582026/10/14 16:47:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2159--- PASS: TestPendingClosureWriteTimeout (0.00s)2160 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2161 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2162 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2163 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (9.71s)21642026/10/14 16:47:11 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTFmOTI1MmUtNmY0ZS00N2MzLTg1MTUtMjg3ZGUxNjkzMDdjLjA1NTVjODZjLTU1YTYtNDcxMi05NmQzLTdmZWE4MzcxZTRkZHgxNzkxOTk2NDI4OTk5Mjk1MDAw parts=1221652026/10/14 16:47:11 INFO Received uploads request method=POST path=/api/pending_closures2166--- PASS: TestCompletedNarNotReofferedAcrossClosures (10.87s)21672026/10/14 16:47:11 INFO Received uploads request method=POST path=/api/pending_closures21682026/10/14 16:47:11 INFO Aborted multipart uploads count=0 kept=021692026/10/14 16:47:11 WARN Force mode enabled - objects will be deleted immediately without grace period21702026/10/14 16:47:11 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=021712026/10/14 16:47:11 INFO Vacuumed table table=pending_closures21722026/10/14 16:47:11 INFO Vacuumed table table=pending_objects21732026/10/14 16:47:11 INFO Vacuumed table table=multipart_uploads21742026/10/14 16:47:11 INFO Vacuumed table table=closures21752026/10/14 16:47:11 INFO Vacuumed table table=objects2176--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2177 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (8.95s)2178 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (9.66s)21792026/10/14 16:47:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21802026/10/14 16:47:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21812026/10/14 16:47:12 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_closures21822026/10/14 16:47:12 WARN Request failed, retrying attempt=2 backoff=199.378024ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2183--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2184 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (7.34s)2185 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (7.12s)21862026/10/14 16:47:13 WARN Request failed, retrying attempt=3 backoff=411.029095ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21872026/10/14 16:47:13 WARN Request failed, retrying attempt=4 backoff=765.016358ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21882026/10/14 16:47:14 WARN Request failed, retrying attempt=5 backoff=1.456277923s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21892026-10-14 16:47:14.312 UTC [21155] LOG: checkpoint starting: wal2190--- PASS: TestObjectStatsLargeCommit (17.54s)2191=== NAME TestOrphanedObjectsGCStressTest2192 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2193 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2194--- PASS: TestClientErrorHandling (0.00s)2195 --- PASS: TestClientErrorHandling/InvalidStorePath (8.76s)2196 --- PASS: TestClientErrorHandling/InvalidAuthToken (8.25s)2197 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.65s)2198=== NAME TestOrphanedObjectsGCStressTest2199 orphaned_objects_gc_test.go:503: Stress test completed successfully:2200 orphaned_objects_gc_test.go:504: - Active objects preserved: 202201 orphaned_objects_gc_test.go:505: - Objects deleted: 2102202 orphaned_objects_gc_test.go:506: - Total GC'd: 2102203--- PASS: TestOrphanedObjectsGCStressTest (20.12s)2204PASS22052026-10-14 16:47:16.445 UTC [21150] LOG: received smart shutdown request22062026-10-14 16:47:16.446 UTC [21150] LOG: background worker "logical replication launcher" (PID 21160) exited with exit code 122072026-10-14 16:47:17.654 UTC [21155] LOG: checkpoint complete: wrote 13083 buffers (79.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=2.589 s, sync=0.627 s, total=3.342 s; sync files=34045, longest=0.001 s, average=0.001 s; distance=533048 kB, estimate=533048 kB; lsn=0/22C4B450, redo lsn=0/2201B20022082026-10-14 16:47:17.655 UTC [21155] LOG: shutting down22092026-10-14 16:47:17.655 UTC [21155] LOG: checkpoint starting: shutdown immediate22102026-10-14 16:47:17.657 UTC [21155] LOG: checkpoint complete: wrote 206 buffers (1.3%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.002 s; sync files=7, longest=0.001 s, average=0.001 s; distance=12480 kB, estimate=480991 kB; lsn=0/22C4B4C8, redo lsn=0/22C4B4C822112026-10-14 16:47:17.663 UTC [21150] LOG: database system is shut down2212Running OIDC tests...2213=== RUN TestAudienceForIssuer2214=== PAUSE TestAudienceForIssuer2215=== RUN TestGlobMatch2216=== PAUSE TestGlobMatch2217=== RUN TestValidateToken_ValidToken2218=== PAUSE TestValidateToken_ValidToken2219=== RUN TestValidateToken_WrongAudience2220=== PAUSE TestValidateToken_WrongAudience2221=== RUN TestValidateToken_Expired2222=== PAUSE TestValidateToken_Expired2223=== RUN TestValidateToken_BoundClaimsMismatch2224=== PAUSE TestValidateToken_BoundClaimsMismatch2225=== RUN TestValidateToken_BoundSubjectMismatch2226=== PAUSE TestValidateToken_BoundSubjectMismatch2227=== RUN TestValidateToken_MultipleProviders2228=== PAUSE TestValidateToken_MultipleProviders2229=== RUN TestValidateToken_NoMatchingProvider2230=== PAUSE TestValidateToken_NoMatchingProvider2231=== RUN TestValidateToken_KubernetesServiceAccount2232=== PAUSE TestValidateToken_KubernetesServiceAccount2233=== RUN TestNewValidator_KubernetesRequiresCA2234=== PAUSE TestNewValidator_KubernetesRequiresCA2235=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2236=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2237=== RUN TestPins_ReservedForMatchingRule2238=== PAUSE TestPins_ReservedForMatchingRule2239=== RUN TestPins_TopLevelShorthand2240=== PAUSE TestPins_TopLevelShorthand2241=== RUN TestPins_ConfigValidation2242=== PAUSE TestPins_ConfigValidation2243=== RUN TestScopes_LegacyProviderDefaultsToWrite2244=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2245=== RUN TestScopes_Rules2246=== PAUSE TestScopes_Rules2247=== RUN TestScopes_ConfigValidation2248=== PAUSE TestScopes_ConfigValidation2249=== CONT TestAudienceForIssuer2250--- PASS: TestAudienceForIssuer (0.00s)2251=== CONT TestScopes_Rules2252=== CONT TestValidateToken_WrongAudience2253=== CONT TestValidateToken_NoMatchingProvider2254=== CONT TestScopes_ConfigValidation2255=== CONT TestValidateToken_MultipleProviders2256=== CONT TestValidateToken_ValidToken2257=== CONT TestGlobMatch2258=== RUN TestGlobMatch/foo_foo2259=== PAUSE TestGlobMatch/foo_foo2260=== RUN TestGlobMatch/foo_bar2261=== PAUSE TestGlobMatch/foo_bar2262=== RUN TestGlobMatch/*_2263=== PAUSE TestGlobMatch/*_2264=== CONT TestValidateToken_KubernetesServiceAccount2265=== CONT TestPins_TopLevelShorthand2266=== CONT TestScopes_LegacyProviderDefaultsToWrite2267=== CONT TestPins_ConfigValidation2268--- PASS: TestScopes_ConfigValidation (0.00s)2269=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2270--- PASS: TestPins_ConfigValidation (0.00s)2271=== CONT TestPins_ReservedForMatchingRule2272=== CONT TestNewValidator_KubernetesRequiresCA2273=== CONT TestValidateToken_BoundClaimsMismatch2274=== CONT TestValidateToken_BoundSubjectMismatch2275=== CONT TestValidateToken_Expired2276=== RUN TestGlobMatch/*_anything2277=== PAUSE TestGlobMatch/*_anything2278=== RUN TestGlobMatch/foo*_foo2279=== PAUSE TestGlobMatch/foo*_foo2280=== RUN TestGlobMatch/foo*_foobar2281=== PAUSE TestGlobMatch/foo*_foobar2282=== RUN TestGlobMatch/foo*_bar2283=== PAUSE TestGlobMatch/foo*_bar2284=== RUN TestGlobMatch/*bar_bar2285=== PAUSE TestGlobMatch/*bar_bar2286=== RUN TestGlobMatch/*bar_foobar2287=== PAUSE TestGlobMatch/*bar_foobar2288=== RUN TestGlobMatch/*bar_foo2289=== PAUSE TestGlobMatch/*bar_foo2290=== RUN TestGlobMatch/foo*bar_foobar2291=== PAUSE TestGlobMatch/foo*bar_foobar2292=== RUN TestGlobMatch/foo*bar_foo123bar2293=== PAUSE TestGlobMatch/foo*bar_foo123bar2294=== RUN TestGlobMatch/foo*bar_foobarbaz2295=== PAUSE TestGlobMatch/foo*bar_foobarbaz2296=== RUN TestGlobMatch/*/*_foo/bar2297=== PAUSE TestGlobMatch/*/*_foo/bar2298=== RUN TestGlobMatch/*/*_foo2299=== PAUSE TestGlobMatch/*/*_foo2300=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2301=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2302=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02303=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02304=== RUN TestGlobMatch/refs/*/main_refs/heads/main2305=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2306=== RUN TestGlobMatch/fo?_foo2307=== PAUSE TestGlobMatch/fo?_foo2308=== RUN TestGlobMatch/fo?_fo2309=== PAUSE TestGlobMatch/fo?_fo2310=== RUN TestGlobMatch/fo?_fooo2311=== PAUSE TestGlobMatch/fo?_fooo2312=== RUN TestGlobMatch/?oo_foo2313=== PAUSE TestGlobMatch/?oo_foo2314=== RUN TestGlobMatch/?oo_boo2315=== PAUSE TestGlobMatch/?oo_boo2316=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2317=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2318=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2319=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2320=== CONT TestGlobMatch/foo_foo2321=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2322=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2323=== CONT TestGlobMatch/?oo_boo2324=== CONT TestGlobMatch/?oo_foo2325=== CONT TestGlobMatch/fo?_fooo2326=== CONT TestGlobMatch/fo?_fo2327=== CONT TestGlobMatch/fo?_foo2328=== CONT TestGlobMatch/refs/*/main_refs/heads/main2329=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02330=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2331=== CONT TestGlobMatch/*/*_foo2332=== CONT TestGlobMatch/*/*_foo/bar2333=== CONT TestGlobMatch/foo*bar_foobarbaz2334=== CONT TestGlobMatch/foo*bar_foo123bar2335=== CONT TestGlobMatch/foo*bar_foobar2336=== CONT TestGlobMatch/*bar_foo2337=== CONT TestGlobMatch/*bar_foobar2338=== CONT TestGlobMatch/*bar_bar2339=== CONT TestGlobMatch/foo*_bar2340=== CONT TestGlobMatch/foo*_foobar2341=== CONT TestGlobMatch/foo*_foo2342=== CONT TestGlobMatch/*_anything2343=== CONT TestGlobMatch/*_2344=== CONT TestGlobMatch/foo_bar2345--- PASS: TestGlobMatch (0.01s)2346 --- PASS: TestGlobMatch/foo_foo (0.00s)2347 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2348 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2349 --- PASS: TestGlobMatch/?oo_boo (0.00s)2350 --- PASS: TestGlobMatch/?oo_foo (0.00s)2351 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2352 --- PASS: TestGlobMatch/fo?_fo (0.00s)2353 --- PASS: TestGlobMatch/fo?_foo (0.00s)2354 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2355 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2356 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2357 --- PASS: TestGlobMatch/*/*_foo (0.00s)2358 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2359 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2360 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2361 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2362 --- PASS: TestGlobMatch/*bar_foo (0.00s)2363 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2364 --- PASS: TestGlobMatch/*bar_bar (0.00s)2365 --- PASS: TestGlobMatch/foo*_bar (0.00s)2366 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2367 --- PASS: TestGlobMatch/foo*_foo (0.00s)2368 --- PASS: TestGlobMatch/*_anything (0.00s)2369 --- PASS: TestGlobMatch/*_ (0.00s)2370 --- PASS: TestGlobMatch/foo_bar (0.00s)23712026/10/14 16:47:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59484/oidc23722026/10/14 16:47:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59486/oidc2373--- PASS: TestValidateToken_WrongAudience (0.05s)23742026/10/14 16:47:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59488/oidc2375--- PASS: TestValidateToken_ValidToken (0.05s)23762026/10/14 16:47:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59491/oidc23772026/10/14 16:47:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59489/oidc23782026/10/14 16:47:18 http: TLS handshake error from 127.0.0.1:59482: read tcp 127.0.0.1:59481->127.0.0.1:59482: use of closed network connection2379--- PASS: TestNewValidator_KubernetesRequiresCA (0.05s)2380--- PASS: TestScopes_Rules (0.05s)2381--- PASS: TestPins_TopLevelShorthand (0.05s)2382--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)23832026/10/14 16:47:18 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59483/oidc2384--- PASS: TestValidateToken_NoMatchingProvider (0.06s)23852026/10/14 16:47:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59497/oidc23862026/10/14 16:47:18 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323872026/10/14 16:47:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59500/oidc2388--- PASS: TestValidateToken_Expired (0.07s)2389--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)2390--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)23912026/10/14 16:47:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59503/oidc23922026/10/14 16:47:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59505/oidc2393--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)2394--- PASS: TestPins_ReservedForMatchingRule (0.08s)23952026/10/14 16:47:19 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:595082396--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)23972026/10/14 16:47:19 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59507/oidc23982026/10/14 16:47:19 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59510/oidc2399--- PASS: TestValidateToken_MultipleProviders (0.13s)2400PASS2401Running hook tests...2402=== RUN TestSendPathsEmpty2403=== PAUSE TestSendPathsEmpty2404=== RUN TestQueueEnqueueAndFetch2405=== PAUSE TestQueueEnqueueAndFetch2406=== RUN TestQueueDeduplication2407=== PAUSE TestQueueDeduplication2408=== RUN TestQueueRemove2409=== PAUSE TestQueueRemove2410=== RUN TestQueueFetchBatchLimit2411=== PAUSE TestQueueFetchBatchLimit2412=== RUN TestQueueRetryMovesToBack2413=== PAUSE TestQueueRetryMovesToBack2414=== RUN TestQueueFetchRemoveLifecycle2415=== PAUSE TestQueueFetchRemoveLifecycle2416=== RUN TestQueueConcurrentWriters2417=== PAUSE TestQueueConcurrentWriters2418=== RUN TestQueueRemoveLargeClosure2419=== PAUSE TestQueueRemoveLargeClosure2420=== RUN TestServerClientIntegration2421--- PASS: TestServerClientIntegration (0.00s)2422=== RUN TestServerQueueError24232026/10/14 16:47:19 ERROR Failed to queue paths error="permission denied" count=12424--- PASS: TestServerQueueError (0.00s)2425=== RUN TestGetListenerSocketActivation2426 server_test.go:146: systemd socket activation does not exist on darwin2427--- SKIP: TestGetListenerSocketActivation (0.00s)2428=== RUN TestDrainIsolatesPoisonPath2429=== PAUSE TestDrainIsolatesPoisonPath2430=== RUN TestRunNotBlockedByPoisonHead2431=== PAUSE TestRunNotBlockedByPoisonHead2432=== RUN TestDrainGivesUpWhenServerDown2433=== PAUSE TestDrainGivesUpWhenServerDown2434=== RUN TestFailedPathPrunedByLaterClosure2435=== PAUSE TestFailedPathPrunedByLaterClosure2436=== RUN TestWorkerUploadsAndRemoves2437=== PAUSE TestWorkerUploadsAndRemoves2438=== RUN TestWorkerSkipsGCdPaths2439=== PAUSE TestWorkerSkipsGCdPaths2440=== RUN TestWorkerPrunesClosureDeps2441=== PAUSE TestWorkerPrunesClosureDeps2442=== RUN TestDrainTimeout2443=== PAUSE TestDrainTimeout2444=== CONT TestSendPathsEmpty2445--- PASS: TestSendPathsEmpty (0.00s)2446=== CONT TestDrainIsolatesPoisonPath2447=== CONT TestQueueRemoveLargeClosure2448=== CONT TestQueueConcurrentWriters2449=== CONT TestQueueFetchRemoveLifecycle2450=== CONT TestQueueRetryMovesToBack2451=== CONT TestQueueFetchBatchLimit2452=== CONT TestQueueRemove2453=== CONT TestQueueDeduplication2454=== CONT TestQueueEnqueueAndFetch2455=== CONT TestWorkerUploadsAndRemoves2456=== CONT TestDrainTimeout2457=== CONT TestWorkerPrunesClosureDeps2458=== CONT TestWorkerSkipsGCdPaths2459=== CONT TestDrainGivesUpWhenServerDown2460=== CONT TestFailedPathPrunedByLaterClosure2461=== CONT TestRunNotBlockedByPoisonHead24622026/10/14 16:47:19 INFO Upload queue status pending=224632026/10/14 16:47:19 INFO Uploading batch count=124642026/10/14 16:47:19 INFO Uploading batch count=224652026/10/14 16:47:19 INFO Upload queue status pending=224662026/10/14 16:47:19 INFO Uploading batch count=224672026/10/14 16:47:19 INFO Upload queue status pending=324682026/10/14 16:47:19 INFO Uploading batch count=124692026/10/14 16:47:19 ERROR Upload failed error="upload failed" count=12470--- PASS: TestQueueDeduplication (0.01s)24712026/10/14 16:47:19 INFO Uploading batch count=424722026/10/14 16:47:19 ERROR Upload failed error="upload failed" count=424732026/10/14 16:47:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/641c288d84b756d0/build/TestDrainIsolatesPoisonPath693267594/002/bbb2474--- PASS: TestQueueEnqueueAndFetch (0.01s)2475--- PASS: TestQueueFetchRemoveLifecycle (0.01s)24762026/10/14 16:47:19 INFO Uploading batch count=124772026/10/14 16:47:19 ERROR Upload failed error="upload failed" count=124782026/10/14 16:47:19 INFO Upload queue status pending=22479--- PASS: TestQueueFetchBatchLimit (0.01s)24802026/10/14 16:47:19 INFO Uploading batch count=124812026/10/14 16:47:19 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/641c288d84b756d0/build/TestWorkerSkipsGCdPaths2612627430/002/nonexistent2482--- PASS: TestQueueRemove (0.01s)24832026/10/14 16:47:19 INFO Uploading batch count=124842026/10/14 16:47:19 INFO Uploading batch count=124852026/10/14 16:47:19 INFO Uploading batch count=224862026/10/14 16:47:19 ERROR Upload failed error="upload failed" count=224872026/10/14 16:47:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/641c288d84b756d0/build/TestDrainGivesUpWhenServerDown661612521/002/a24882026/10/14 16:47:19 INFO Uploading batch count=124892026/10/14 16:47:19 ERROR Upload failed error="upload failed" count=12490--- PASS: TestQueueRetryMovesToBack (0.01s)24912026/10/14 16:47:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/641c288d84b756d0/build/TestDrainGivesUpWhenServerDown661612521/002/b24922026/10/14 16:47:19 INFO Uploading batch count=124932026/10/14 16:47:19 ERROR Upload failed error="upload failed" count=124942026/10/14 16:47:19 INFO Uploading batch count=224952026/10/14 16:47:19 INFO Uploading batch count=124962026/10/14 16:47:19 ERROR Upload failed error="upload failed" count=124972026/10/14 16:47:19 ERROR Upload failed error="upload failed" count=224982026/10/14 16:47:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/641c288d84b756d0/build/TestDrainGivesUpWhenServerDown661612521/002/c24992026/10/14 16:47:19 ERROR Drain finished with paths left in queue remaining=125002026/10/14 16:47:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/641c288d84b756d0/build/TestDrainGivesUpWhenServerDown661612521/002/d2501--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)25022026/10/14 16:47:19 INFO Uploading batch count=225032026/10/14 16:47:19 ERROR Upload failed error="upload failed" count=225042026/10/14 16:47:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/641c288d84b756d0/build/TestDrainGivesUpWhenServerDown661612521/002/e25052026/10/14 16:47:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/641c288d84b756d0/build/TestDrainGivesUpWhenServerDown661612521/002/f25062026/10/14 16:47:19 ERROR Drain finished with paths left in queue remaining=102507--- PASS: TestDrainIsolatesPoisonPath (0.01s)2508--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2509--- PASS: TestWorkerPrunesClosureDeps (0.03s)2510--- PASS: TestWorkerUploadsAndRemoves (0.03s)2511--- PASS: TestWorkerSkipsGCdPaths (0.03s)2512--- PASS: TestQueueRemoveLargeClosure (0.03s)2513--- PASS: TestQueueConcurrentWriters (0.12s)25142026/10/14 16:47:19 ERROR Upload failed error="context deadline exceeded" count=225152026/10/14 16:47:19 ERROR Drain finished with paths left in queue remaining=42516--- PASS: TestDrainTimeout (0.21s)25172026/10/14 16:47:20 INFO Uploading batch count=125182026/10/14 16:47:20 INFO Uploading batch count=125192026/10/14 16:47:20 INFO Uploading batch count=125202026/10/14 16:47:20 ERROR Upload failed error="upload failed" count=125212026/10/14 16:47:20 INFO Uploading batch count=125222026/10/14 16:47:20 ERROR Upload failed error="upload failed" count=125232026/10/14 16:47:20 INFO Uploading batch count=125242026/10/14 16:47:20 ERROR Upload failed error="upload failed" count=125252026/10/14 16:47:20 INFO Uploading batch count=125262026/10/14 16:47:20 ERROR Upload failed error="upload failed" count=125272026/10/14 16:47:20 ERROR Drain finished with paths left in queue remaining=12528--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2529PASS2530Running signing tests...2531=== RUN TestExternalSigner2532=== PAUSE TestExternalSigner2533=== RUN TestExternalSignerWrongPublicKey2534=== PAUSE TestExternalSignerWrongPublicKey2535=== RUN TestExternalSignerErrors2536=== PAUSE TestExternalSignerErrors2537=== RUN TestExternalSignerRestartsAfterCrash2538=== PAUSE TestExternalSignerRestartsAfterCrash2539=== RUN TestExternalSignerProgramErrorKeepsProcess2540=== PAUSE TestExternalSignerProgramErrorKeepsProcess2541=== RUN TestExternalSignerClose2542=== PAUSE TestExternalSignerClose2543=== RUN TestExternalSignerRejectsInvalidPublicKey2544=== PAUSE TestExternalSignerRejectsInvalidPublicKey2545=== RUN TestExternalSignerCancellation2546=== PAUSE TestExternalSignerCancellation2547=== RUN TestGenerateFingerprint2548=== PAUSE TestGenerateFingerprint2549=== RUN TestParseSigningKey2550=== PAUSE TestParseSigningKey2551=== RUN TestSign2552=== PAUSE TestSign2553=== RUN TestSignBatch2554=== PAUSE TestSignBatch2555=== RUN TestNilKeyPublicKey2556=== PAUSE TestNilKeyPublicKey2557=== RUN TestSignErrors2558=== PAUSE TestSignErrors2559=== CONT TestExternalSigner2560=== CONT TestExternalSignerCancellation2561=== CONT TestSignBatch2562=== CONT TestParseSigningKey2563=== RUN TestParseSigningKey/valid_32-byte_key2564=== CONT TestSignErrors2565=== PAUSE TestParseSigningKey/valid_32-byte_key2566=== CONT TestSign2567=== CONT TestExternalSignerRejectsInvalidPublicKey2568=== RUN TestExternalSignerRejectsInvalidPublicKey/#002569=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002570=== CONT TestExternalSignerErrors2571=== RUN TestExternalSignerErrors/exit_at_startup2572=== CONT TestExternalSignerRestartsAfterCrash2573=== CONT TestNilKeyPublicKey2574--- PASS: TestNilKeyPublicKey (0.00s)2575=== CONT TestExternalSignerWrongPublicKey2576=== CONT TestExternalSignerClose2577=== CONT TestGenerateFingerprint2578=== RUN TestGenerateFingerprint/basic_with_references2579=== PAUSE TestGenerateFingerprint/basic_with_references2580=== CONT TestExternalSignerProgramErrorKeepsProcess2581=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2582=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2583=== RUN TestParseSigningKey/no_colon2584=== PAUSE TestParseSigningKey/no_colon2585=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2586=== PAUSE TestExternalSignerErrors/exit_at_startup2587=== RUN TestExternalSignerErrors/wrong_id2588=== PAUSE TestExternalSignerErrors/wrong_id2589=== RUN TestGenerateFingerprint/no_references2590=== PAUSE TestGenerateFingerprint/no_references2591=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2592=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2593=== RUN TestParseSigningKey/empty_name2594=== PAUSE TestParseSigningKey/empty_name2595=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2596=== RUN TestExternalSignerErrors/missing_signature_name2597=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2598=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2599=== PAUSE TestExternalSignerErrors/missing_signature_name2600=== RUN TestExternalSignerErrors/program_error2601=== RUN TestParseSigningKey/invalid_base642602=== PAUSE TestParseSigningKey/invalid_base642603=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2604=== PAUSE TestExternalSignerErrors/program_error2605=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2606=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2607=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2608=== RUN TestExternalSignerErrors/wrong_shape2609=== PAUSE TestExternalSignerErrors/wrong_shape2610=== RUN TestExternalSignerErrors/null_signatures2611=== PAUSE TestExternalSignerErrors/null_signatures2612=== RUN TestExternalSignerErrors/wrong_signatures_shape2613=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2614=== RUN TestExternalSignerErrors/unrequested_key2615=== PAUSE TestExternalSignerErrors/unrequested_key2616=== RUN TestExternalSignerErrors/wrong_signature_name2617=== PAUSE TestExternalSignerErrors/wrong_signature_name2618=== RUN TestExternalSignerErrors/invalid_signature_base642619=== PAUSE TestExternalSignerErrors/invalid_signature_base642620=== RUN TestExternalSignerErrors/wrong_signature_length2621=== PAUSE TestExternalSignerErrors/wrong_signature_length2622=== RUN TestExternalSignerErrors/null2623=== PAUSE TestExternalSignerErrors/null2624=== RUN TestExternalSignerErrors/exit_on_request2625=== PAUSE TestExternalSignerErrors/exit_on_request2626=== RUN TestExternalSignerErrors/invalid_JSON2627=== PAUSE TestExternalSignerErrors/invalid_JSON2628=== RUN TestGenerateFingerprint/invalid_nar_hash_length2629=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2630=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2631=== RUN TestParseSigningKey/wrong_length2632=== PAUSE TestParseSigningKey/wrong_length2633=== CONT TestParseSigningKey/valid_32-byte_key2634=== CONT TestParseSigningKey/empty_name2635=== CONT TestParseSigningKey/invalid_base642636=== CONT TestParseSigningKey/no_colon2637=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2638=== RUN TestExternalSignerErrors/missing_signatures2639=== CONT TestExternalSignerRejectsInvalidPublicKey/#002640=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2641=== PAUSE TestExternalSignerErrors/missing_signatures2642=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2643=== RUN TestExternalSignerErrors/too_few_signatures2644=== PAUSE TestExternalSignerErrors/too_few_signatures2645=== CONT TestExternalSignerErrors/exit_at_startup2646=== RUN TestSignErrors/nil_key2647=== PAUSE TestSignErrors/nil_key2648=== RUN TestSignErrors/nil_narinfo2649=== PAUSE TestSignErrors/nil_narinfo2650=== RUN TestSignErrors/invalid_narinfo2651=== PAUSE TestSignErrors/invalid_narinfo2652=== RUN TestSignErrors/canceled2653=== PAUSE TestSignErrors/canceled2654=== CONT TestSignErrors/nil_key2655--- PASS: TestSign (0.00s)2656=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2657=== CONT TestExternalSignerErrors/too_few_signatures2658=== CONT TestSignErrors/invalid_narinfo2659=== CONT TestSignErrors/canceled2660=== CONT TestExternalSignerErrors/unrequested_key2661=== CONT TestExternalSignerErrors/exit_on_request2662--- PASS: TestSignBatch (0.00s)2663=== CONT TestExternalSignerErrors/null_signatures2664=== CONT TestExternalSignerErrors/wrong_signature_length2665=== CONT TestExternalSignerErrors/missing_signature_name2666=== CONT TestExternalSignerErrors/null2667=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2668=== CONT TestSignErrors/nil_narinfo2669=== CONT TestExternalSignerErrors/program_error2670--- PASS: TestSignErrors (0.00s)2671 --- PASS: TestSignErrors/nil_key (0.00s)2672 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2673 --- PASS: TestSignErrors/canceled (0.00s)2674 --- PASS: TestSignErrors/nil_narinfo (0.00s)2675=== CONT TestExternalSignerErrors/wrong_signature_name2676=== CONT TestParseSigningKey/wrong_length2677--- PASS: TestParseSigningKey (0.00s)2678 --- PASS: TestParseSigningKey/empty_name (0.00s)2679 --- PASS: TestParseSigningKey/no_colon (0.00s)2680 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2681 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2682 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2683 --- PASS: TestParseSigningKey/wrong_length (0.00s)2684=== CONT TestExternalSignerErrors/missing_signatures2685=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2686=== RUN TestGenerateFingerprint/invalid_store_path_prefix2687=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2688=== RUN TestGenerateFingerprint/invalid_reference_prefix2689=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2690=== CONT TestGenerateFingerprint/basic_with_references2691--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2692 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2693 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2694 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2695 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2696 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2697=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2698=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2699=== CONT TestExternalSignerErrors/invalid_signature_base642700=== CONT TestExternalSignerErrors/wrong_id2701=== CONT TestExternalSignerErrors/invalid_JSON2702=== CONT TestExternalSignerErrors/wrong_shape2703=== CONT TestExternalSignerErrors/wrong_signatures_shape2704=== CONT TestGenerateFingerprint/no_references2705=== CONT TestGenerateFingerprint/invalid_store_path_prefix2706=== CONT TestGenerateFingerprint/invalid_nar_hash_length2707=== CONT TestGenerateFingerprint/invalid_reference_prefix2708--- PASS: TestGenerateFingerprint (0.00s)2709 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2710 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2711 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2712 --- PASS: TestGenerateFingerprint/no_references (0.00s)2713 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2714 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2715 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2716--- PASS: TestExternalSigner (0.17s)2717--- PASS: TestExternalSignerRestartsAfterCrash (0.48s)2718/private/var/tb/3/scratch/641c288d84b756d0/build/TestExternalSignerRestartsAfterCrash2743878518/001/sign program: line 7: /private/var/tb/3/scratch/641c288d84b756d0/build/TestExternalSignerRestartsAfterCrash2743878518/001/sign program.starts: No such file or directory2719--- PASS: TestExternalSignerWrongPublicKey (0.61s)2720--- PASS: TestExternalSignerClose (0.84s)2721--- PASS: TestExternalSignerCancellation (1.01s)2722--- PASS: TestExternalSignerProgramErrorKeepsProcess (1.23s)2723--- PASS: TestExternalSignerErrors (0.00s)2724 --- PASS: TestExternalSignerErrors/null_signatures (0.23s)2725 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.31s)2726 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.38s)2727 --- PASS: TestExternalSignerErrors/wrong_shape (0.53s)2728 --- PASS: TestExternalSignerErrors/program_error (0.69s)2729 --- PASS: TestExternalSignerErrors/invalid_JSON (0.76s)2730 --- PASS: TestExternalSignerErrors/too_few_signatures (0.91s)2731 --- PASS: TestExternalSignerErrors/exit_at_startup (1.07s)2732 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.15s)2733 --- PASS: TestExternalSignerErrors/wrong_id (1.30s)2734 --- PASS: TestExternalSignerErrors/missing_signature_name (1.38s)2735 --- PASS: TestExternalSignerErrors/unrequested_key (1.45s)2736 --- PASS: TestExternalSignerErrors/null (1.53s)2737 --- PASS: TestExternalSignerErrors/missing_signatures (1.61s)2738 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.68s)2739 --- PASS: TestExternalSignerErrors/exit_on_request (1.77s)2740PASS2741Running OpenBao signer tests...2742=== RUN TestSign2743=== PAUSE TestSign2744=== RUN TestSignErrors2745=== PAUSE TestSignErrors2746=== RUN TestServe2747=== PAUSE TestServe2748=== RUN TestServeRejectsGarbage2749=== PAUSE TestServeRejectsGarbage2750=== CONT TestSign2751=== CONT TestServeRejectsGarbage2752--- PASS: TestServeRejectsGarbage (0.00s)2753=== CONT TestServe2754=== CONT TestSignErrors2755=== RUN TestSignErrors/invalid_base642756--- PASS: TestServe (0.00s)2757=== PAUSE TestSignErrors/invalid_base642758=== RUN TestSignErrors/http_error2759=== PAUSE TestSignErrors/http_error2760=== RUN TestSignErrors/invalid_json2761=== PAUSE TestSignErrors/invalid_json2762=== RUN TestSignErrors/no_prefix2763=== PAUSE TestSignErrors/no_prefix2764=== CONT TestSignErrors/invalid_base642765=== CONT TestSignErrors/no_prefix2766=== CONT TestSignErrors/http_error2767=== CONT TestSignErrors/invalid_json2768--- PASS: TestSign (0.00s)2769--- PASS: TestSignErrors (0.00s)2770 --- PASS: TestSignErrors/invalid_base64 (0.00s)2771 --- PASS: TestSignErrors/invalid_json (0.00s)2772 --- PASS: TestSignErrors/http_error (0.00s)2773 --- PASS: TestSignErrors/no_prefix (0.00s)2774PASS