niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #380
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestEncodeNixBase32102=== CONT TestResolveStorePath103=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess104=== CONT TestRateLimiterFeedback105=== RUN TestRateLimiterFeedback/429_enables_limiter106=== PAUSE TestRateLimiterFeedback/429_enables_limiter107=== RUN TestRateLimiterFeedback/503_enables_limiter108=== PAUSE TestRateLimiterFeedback/503_enables_limiter109=== CONT TestPathInfoCACompatibility110=== CONT TestParsePathInfoJSONMultiplePaths111=== CONT TestParsePathInfoJSON112=== CONT TestPathInfoHashCompatibility113=== CONT TestGetStorePathHash1142026/10/06 21:12:32 WARN Rate limiter enabled after throttle name=server-test rate=5115=== CONT TestConvertHashToNix32116=== CONT TestEncodeNixBase32WithRealHash117=== CONT TestSetClientTLSErrors118--- PASS: TestEncodeNixBase32WithRealHash (0.00s)119=== CONT TestScriptTokenScriptFails120=== CONT TestScriptTokenBadJSON121=== CONT TestScriptTokenEmptyToken122=== CONT TestScriptTokenCachesUntilRefresh123=== CONT TestScriptTokenNoExpiryRerunsEveryCall124--- PASS: TestResolveStorePath (0.00s)125=== CONT TestDumpPathWriterError126=== CONT TestFileTokenEmpty127=== CONT TestFileTokenMissing128=== CONT TestFileTokenReadsAndCaches129=== CONT TestStaticToken130--- PASS: TestStaticToken (0.00s)131=== CONT TestDumpPathSingleFile132=== RUN TestEncodeNixBase32/test_string_hash133=== CONT TestUploadMultipart_PartsInParallel134=== CONT TestScriptTokenEmptyCommand135=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter136=== RUN TestPathInfoCACompatibility/null_ca_field137=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths138=== RUN TestParsePathInfoJSON/Nix_format139=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)140=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)141=== RUN TestGetStorePathHash/valid_store_path142=== RUN TestConvertHashToNix32/SRI_format_to_Nix32143=== PAUSE TestEncodeNixBase32/test_string_hash144--- PASS: TestScriptTokenScriptFails (0.00s)145=== CONT TestDumpPathMatchesNix146=== CONT TestPartSizeForNAR147=== RUN TestPartSizeForNAR/zero_stays_at_minimum148=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun149=== CONT TestFilterOversizedClosures150=== RUN TestFilterOversizedClosures/no_limit_keeps_everything151=== CONT TestCaseHackSuffix152=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter153=== PAUSE TestPathInfoCACompatibility/null_ca_field154=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths155=== PAUSE TestParsePathInfoJSON/Nix_format156=== CONT TestUploadMultipart_SupersededByPeer157=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon158=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon159=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI160=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32161=== RUN TestConvertHashToNix32/already_Nix32_format162--- PASS: TestFileTokenMissing (0.00s)163=== PAUSE TestGetStorePathHash/valid_store_path164=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum165=== RUN TestEncodeNixBase32/empty_input1662026/10/06 21:12:32 WARN Rate limiter enabled after throttle name=server-test rate=5167=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything168=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter169=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1702026/10/06 21:12:32 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35259171=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped172=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error173=== RUN TestPathInfoCACompatibility/old_string_format_-_text174=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1752026/10/06 21:12:32 WARN Rate limiter backed off name=server-test rate=51762026/10/06 21:12:32 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35259177=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths178=== RUN TestParsePathInfoJSON/Lix_format179=== PAUSE TestParsePathInfoJSON/Lix_format180=== RUN TestParsePathInfoJSON/empty_input181=== RUN TestUploadMultipart_SupersededByPeer/exists182=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI183=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5121842026/10/06 21:12:32 INFO Garbage collection started185=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512186=== CONT TestStreamPushGivesUpOnDeadServer187=== CONT TestClientSignaturesByStorePath188=== CONT TestStreamPushReportsSignatures189--- PASS: TestFileTokenEmpty (0.00s)190--- PASS: TestScriptTokenBadJSON (0.00s)191--- PASS: TestScriptTokenEmptyCommand (0.00s)192=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica193=== PAUSE TestConvertHashToNix32/already_Nix32_format1942026/10/06 21:12:32 ERROR Upload failed error="connection refused" count=201952026/10/06 21:12:32 ERROR Server seems unavailable, giving up on batch untried=17196=== PAUSE TestEncodeNixBase32/empty_input197=== RUN TestPartSizeForNAR/small_stays_at_minimum1982026/10/06 21:12:32 ERROR Upload failed error=boom count=1199=== PAUSE TestPartSizeForNAR/small_stays_at_minimum200=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter201=== CONT TestStreamPushIsolatesFailures202=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2032026/10/06 21:12:32 ERROR Upload failed error="bad path" count=3204=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error205=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text206=== CONT TestSetClientTLSDoesNotMutateDefaultTransport207=== PAUSE TestParsePathInfoJSON/empty_input208=== PAUSE TestUploadMultipart_SupersededByPeer/exists209=== CONT TestSetClientTLS210--- PASS: TestFileTokenReadsAndCaches (0.00s)211--- PASS: TestDoServerRequestAttachesToken (0.01s)212=== RUN TestSetClientTLSErrors/missing_cert_file213--- PASS: TestScriptTokenEmptyToken (0.04s)214--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)2152026/10/06 21:12:32 INFO Garbage collection started216--- PASS: TestClientSignaturesByStorePath (0.00s)217--- PASS: TestStreamPushReportsSignatures (0.00s)218--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)219--- PASS: TestStreamPushIsolatesFailures (0.00s)220=== RUN TestConvertHashToNix32/invalid_format221=== CONT TestStreamPushRequestLine222=== CONT TestStreamPushReportsEveryPath223=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum224=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum225=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts226=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts227=== RUN TestPartSizeForNAR/1_TiB228=== CONT TestStreamPushBatchesUnderLoad2292026/10/06 21:12:32 ERROR Upload failed error=boom count=1230--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.04s)231=== CONT TestRegisterUploadedObjectReusesConnections232--- PASS: TestStreamPushReportsEveryPath (0.00s)233=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error234=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive235=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive236=== RUN TestPathInfoCACompatibility/new_structured_format_-_text237=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text238=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method239=== RUN TestUploadMultipart_SupersededByPeer/missing240=== PAUSE TestUploadMultipart_SupersededByPeer/missing241=== RUN TestParsePathInfoJSON/whitespace_only242=== PAUSE TestParsePathInfoJSON/whitespace_only243=== RUN TestParsePathInfoJSON/invalid_JSON244=== PAUSE TestParsePathInfoJSON/invalid_JSON245=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths246=== PAUSE TestSetClientTLSErrors/missing_cert_file247=== RUN TestSetClientTLSErrors/missing_key_file248=== PAUSE TestSetClientTLSErrors/missing_key_file249=== RUN TestSetClientTLSErrors/missing_ca_file250=== PAUSE TestSetClientTLSErrors/missing_ca_file251=== RUN TestSetClientTLSErrors/invalid_ca_file252=== PAUSE TestSetClientTLSErrors/invalid_ca_file253=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths254--- PASS: TestParsePathInfoJSONMultiplePaths (0.05s)255 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)256 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)257=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)258=== PAUSE TestConvertHashToNix32/invalid_format259=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512260=== CONT TestEncodeNixBase32/empty_input261=== CONT TestRateLimiterFeedback/429_enables_limiter262=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon263=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter264=== PAUSE TestPartSizeForNAR/1_TiB265=== RUN TestPartSizeForNAR/5_TiB_S3_max_object266=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object267=== RUN TestPartSizeForNAR/capped_at_5_GiB268=== PAUSE TestPartSizeForNAR/capped_at_5_GiB269=== CONT TestEncodeNixBase32/test_string_hash270=== CONT TestUploadMultipart_SupersededByPeer/exists271=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI272=== CONT TestParsePathInfoJSON/Nix_format273=== CONT TestUploadMultipart_SupersededByPeer/missing274--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)275=== RUN TestFilterOversizedClosures/all_closures_skipped276=== PAUSE TestFilterOversizedClosures/all_closures_skipped277--- PASS: TestEncodeNixBase32 (0.05s)278 --- PASS: TestEncodeNixBase32/empty_input (0.00s)279 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)280=== CONT TestShellSplit281=== RUN TestSetClientTLS/rejects_connection_without_client_cert282=== CONT TestShellSplitErrors283=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method284=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter285=== CONT TestRateLimiterFeedback/503_enables_limiter2862026/10/06 21:12:32 WARN Rate limiter enabled after throttle name=server-test rate=52872026/10/06 21:12:32 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:413272882026/10/06 21:12:32 WARN Rate limiter backed off name=server-test rate=5289=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert290=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA291=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA292=== RUN TestSetClientTLS/preserves_debug_logging_transport293=== PAUSE TestSetClientTLS/preserves_debug_logging_transport294=== CONT TestParsePathInfoJSON/Lix_format295=== CONT TestConvertHashToNix32/SRI_format_to_Nix32296=== CONT TestPartSizeForNAR/zero_stays_at_minimum297=== CONT TestSetClientTLSErrors/missing_ca_file298=== CONT TestParsePathInfoJSON/whitespace_only299=== CONT TestSetClientTLSErrors/missing_key_file300=== CONT TestPartSizeForNAR/capped_at_5_GiB301=== CONT TestConvertHashToNix32/invalid_format302=== CONT TestPartSizeForNAR/5_TiB_S3_max_object303=== CONT TestPartSizeForNAR/1_TiB304=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts305=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum306=== CONT TestPartSizeForNAR/small_stays_at_minimum307=== CONT TestFilterOversizedClosures/no_limit_keeps_everything3082026/10/06 21:12: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=0309=== CONT TestFilterOversizedClosures/all_closures_skipped3102026/10/06 21:12: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=50311=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped312=== CONT TestSetClientTLS/rejects_connection_without_client_cert3132026/10/06 21:12: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=2000314=== CONT TestPathInfoCACompatibility/null_ca_field315--- PASS: TestShellSplit (0.00s)316--- PASS: TestPathInfoHashCompatibility (0.04s)317 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)318 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)319 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)320 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)321=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method322=== CONT TestParsePathInfoJSON/empty_input323=== CONT TestConvertHashToNix32/already_Nix32_format324=== CONT TestSetClientTLSErrors/invalid_ca_file325=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error326=== CONT TestPathInfoCACompatibility/old_string_format_-_text327=== CONT TestPathInfoCACompatibility/new_structured_format_-_text328=== CONT TestSetClientTLSErrors/missing_cert_file3292026/10/06 21:12:32 WARN Garbage collection finished on another replica. Its statistics are not available here330=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive3312026/10/06 21:12:32 WARN Rate limiter enabled after throttle name=server-test rate=5332=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3332026/10/06 21:12:32 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43749334=== CONT TestSetClientTLS/preserves_debug_logging_transport3352026/10/06 21:12:32 WARN Rate limiter backed off name=server-test rate=5336--- PASS: TestShellSplitErrors (0.00s)337=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error338=== CONT TestGetStorePathHash/valid_store_path339=== CONT TestParsePathInfoJSON/invalid_JSON340=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error341=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error342=== CONT TestGetStorePathHash/basename_without_hyphen_should_error343--- PASS: TestGetStorePathHash (0.06s)344 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)345 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)347 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)348--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)349--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)350--- PASS: TestDumpPathSingleFile (0.05s)351--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)352--- PASS: TestParsePathInfoJSON (0.05s)353 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)354 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)355 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)356 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)357 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)358--- PASS: TestPartSizeForNAR (0.04s)359 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)360 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)361 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)362 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)363 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)364 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)365 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)366--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)367 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)368 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)369--- PASS: TestFilterOversizedClosures (0.04s)370 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)371 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)372 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)373--- PASS: TestConvertHashToNix32 (0.05s)374 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)375 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)376 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)377--- PASS: TestPathInfoCACompatibility (0.05s)378 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)379 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)380 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)381 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)382 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)383--- PASS: TestRateLimiterFeedback (0.05s)384 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)385 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)386 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)387 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)388--- PASS: TestSetClientTLSErrors (0.05s)389 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)392 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3932026/10/06 21:12:32 http: TLS handshake error from 127.0.0.1:38054: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.00s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)397 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)398--- PASS: TestStreamPushRequestLine (0.04s)399--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)400--- PASS: TestCaseHackSuffix (0.09s)401--- PASS: TestDumpPathWriterError (0.10s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.16s)404--- PASS: TestUploadMultipart_PartsInParallel (0.68s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres1461373245/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: 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.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres1461373245/data -l logfile start434435/build/postgres1461373245:5432 - no response4362026-10-06 21:12:34.624 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 21:12:34.625 UTC [128] LOG: listening on Unix socket "/build/postgres1461373245/.s.PGSQL.5432"4382026-10-06 21:12:34.629 UTC [135] LOG: database system was shut down at 2026-10-06 21:12:34 UTC4392026-10-06 21:12:34.633 UTC [128] LOG: database system is ready to accept connections440/build/postgres1461373245:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== RUN TestResolveDBConnectionString480=== PAUSE TestResolveDBConnectionString481=== RUN TestConnectWaitsForAPeerMigration482=== PAUSE TestConnectWaitsForAPeerMigration483=== RUN TestLeadElectsOneAndHandsOver484=== PAUSE TestLeadElectsOneAndHandsOver485=== RUN TestLeadIncumbentWinsAfterRestart4862026/10/06 21:12:35 INFO lead: acquired remote=192.0.2.1:12344872026/10/06 21:12:35 INFO lead: released remote=192.0.2.1:12344882026/10/06 21:12:35 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 21:12:36 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/06 21:12:37 INFO lead: acquired remote=192.0.2.1:12344972026-10-06 21:12:38.443 UTC [575] FATAL: terminating connection due to administrator command4982026/10/06 21:12:38 INFO lead: acquired remote=192.0.2.1:12344992026/10/06 21:12:39 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/06 21:12:39 INFO lead: released remote=192.0.2.1:12345012026/10/06 21:12:39 INFO lead: released remote=192.0.2.1:1234502--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)503=== RUN TestGCAdvisoryLockBlocksConcurrentRun504=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun505=== RUN TestGCBugBareHashReferences506=== PAUSE TestGCBugBareHashReferences507=== RUN TestGCMetrics508=== PAUSE TestGCMetrics509=== RUN TestPushDedupSurvivesConcurrentGC510=== PAUSE TestPushDedupSurvivesConcurrentGC511=== RUN TestDeduplicatedObjectsRecordedAsPending512=== PAUSE TestDeduplicatedObjectsRecordedAsPending513=== RUN TestGCSweepSkipsPendingObjects514=== PAUSE TestGCSweepSkipsPendingObjects515=== RUN TestTombstonedObjectOfferedWithoutWaiting516=== PAUSE TestTombstonedObjectOfferedWithoutWaiting517=== RUN TestGCSweepDeliversEachKeyOnce518=== PAUSE TestGCSweepDeliversEachKeyOnce519=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection520=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== RUN TestForceGCDuringPushOffersSweptObject522=== PAUSE TestForceGCDuringPushOffersSweptObject523=== RUN TestFailedS3DeleteKeepsTombstone524=== PAUSE TestFailedS3DeleteKeepsTombstone525=== RUN TestSweepSkipsRowsLockedByPush526=== PAUSE TestSweepSkipsRowsLockedByPush527=== RUN TestRegisterCompletedObjectNeedsPendingRow528=== PAUSE TestRegisterCompletedObjectNeedsPendingRow529=== RUN TestGetExistingObjectsLocksRows530=== PAUSE TestGetExistingObjectsLocksRows531=== RUN TestSweepRechecksPendingAfterLocking532=== PAUSE TestSweepRechecksPendingAfterLocking533=== RUN TestPushWaitsForSweepHoldingRow534=== PAUSE TestPushWaitsForSweepHoldingRow535=== RUN TestCommitRacingPendingCleanupKeepsObjects536=== PAUSE TestCommitRacingPendingCleanupKeepsObjects537=== RUN TestGCEndsOnShutdown538=== PAUSE TestGCEndsOnShutdown539=== RUN TestGCTaskStore_StartNew540=== PAUSE TestGCTaskStore_StartNew541=== RUN TestGCTaskStore_DeduplicateSameParams542=== PAUSE TestGCTaskStore_DeduplicateSameParams543=== RUN TestGCTaskStore_ConflictDifferentParams544=== PAUSE TestGCTaskStore_ConflictDifferentParams545=== RUN TestGCTaskStore_GetEmpty546=== PAUSE TestGCTaskStore_GetEmpty547=== RUN TestGCTaskStore_GetReturnsLatest548=== PAUSE TestGCTaskStore_GetReturnsLatest549=== RUN TestGCTaskStore_CompletedAllowsNewTask550=== PAUSE TestGCTaskStore_CompletedAllowsNewTask551=== RUN TestGCTaskStore_PhaseUpdates552=== PAUSE TestGCTaskStore_PhaseUpdates553=== RUN TestGCTaskStore_Fail554=== PAUSE TestGCTaskStore_Fail555=== RUN TestGracefulShutdownDrainsInflight556=== PAUSE TestGracefulShutdownDrainsInflight557=== RUN TestService_healthCheckHandler558=== PAUSE TestService_healthCheckHandler559=== RUN TestService_readinessHandler560=== PAUSE TestService_readinessHandler561=== RUN TestGenerateLandingPage562=== PAUSE TestGenerateLandingPage563=== RUN TestCacheConfigHandlerMaxNarSize564=== PAUSE TestCacheConfigHandlerMaxNarSize565=== RUN TestCreatePendingClosureRejectsOversizedNAR566=== PAUSE TestCreatePendingClosureRejectsOversizedNAR567=== RUN TestNARDeduplicationMetadataUploadBug568=== PAUSE TestNARDeduplicationMetadataUploadBug569=== RUN TestMetricsInventory570=== PAUSE TestMetricsInventory571=== RUN TestService_NativeMTLS572=== PAUSE TestService_NativeMTLS573=== RUN TestServerTLSConfig574=== PAUSE TestServerTLSConfig575=== RUN TestMultipartCleanup576=== PAUSE TestMultipartCleanup577=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded578=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== RUN TestPendingCleanupUsesOneCutoff580=== PAUSE TestPendingCleanupUsesOneCutoff581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentNotReportedWhileGCDeletesClosure592=== PAUSE TestPresentNotReportedWhileGCDeletesClosure593=== RUN TestParseSingleRange594=== PAUSE TestParseSingleRange595=== RUN TestProxyHeadersOnlyTrustedOnSocket596=== PAUSE TestProxyHeadersOnlyTrustedOnSocket597=== RUN TestIsValidCachePath598=== PAUSE TestIsValidCachePath599=== RUN TestReadProxyNarinfo600=== PAUSE TestReadProxyNarinfo601=== RUN TestReadProxyNarinfoAlreadyDecompressed602=== PAUSE TestReadProxyNarinfoAlreadyDecompressed603=== RUN TestReadProxyContentNegotiation604=== PAUSE TestReadProxyContentNegotiation605=== RUN TestReadProxyNarStreaming606=== PAUSE TestReadProxyNarStreaming607=== RUN TestReadProxy404608=== PAUSE TestReadProxy404609=== RUN TestReadProxyInvalidPath610=== PAUSE TestReadProxyInvalidPath611=== RUN TestReadProxyHead612=== PAUSE TestReadProxyHead613=== RUN TestReadProxyOutlastsServerWriteTimeout614=== PAUSE TestReadProxyOutlastsServerWriteTimeout615=== RUN TestReadProxyConditionalGet616=== PAUSE TestReadProxyConditionalGet617=== RUN TestReadProxyRootRedirectsToIndexHTML618=== PAUSE TestReadProxyRootRedirectsToIndexHTML619=== RUN TestReadProxyDisabled620=== PAUSE TestReadProxyDisabled621=== RUN TestReadRedirectNar622=== PAUSE TestReadRedirectNar623=== RUN TestReadRedirectKeepsNarinfoProxied624=== PAUSE TestReadRedirectKeepsNarinfoProxied625=== RUN TestReadProxyRangeRequest626=== PAUSE TestReadProxyRangeRequest627=== RUN TestReadRedirectUsesPublicS3URL628=== PAUSE TestReadRedirectUsesPublicS3URL629=== RUN TestPush_OverlappingRootsStoreOneRowPerKey630=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey631=== RUN TestPush_CompleteCommitsEveryRoot632=== PAUSE TestPush_CompleteCommitsEveryRoot633=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit634=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit635=== RUN TestPush_RejectsBadRequests636=== PAUSE TestPush_RejectsBadRequests637=== RUN TestPush_SignsNarinfosOfItsPendingObjects638=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects639=== RUN TestRedundantMultipartUpload640=== PAUSE TestRedundantMultipartUpload641=== RUN TestCompleteMultipartUpload_ErrorButObjectExists642=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists643=== RUN TestCompletedNarNotReofferedAcrossClosures644=== PAUSE TestCompletedNarNotReofferedAcrossClosures645=== RUN TestPresignedUploadRegisteredBeforeCommit646=== PAUSE TestPresignedUploadRegisteredBeforeCommit647=== RUN TestService_Rustfstest648=== PAUSE TestService_Rustfstest649=== RUN TestParseSize650=== PAUSE TestParseSize651=== RUN TestSkippedUploadsHandler652=== PAUSE TestSkippedUploadsHandler653=== RUN TestSystemdListenerNotActivated654--- PASS: TestSystemdListenerNotActivated (0.00s)655=== RUN TestWatchdogBeatsWhenHealthy656--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)657=== RUN TestWatchdogSkipsWhenUnhealthy6582026/10/06 21:12:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/06 21:12:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 21:12:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 21:12:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 21:12:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 21:12:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 21:12:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 21:12:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 21:12:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 21:12:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"668--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)669=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle670=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== RUN TestProxyWriteTimeout672=== PAUSE TestProxyWriteTimeout673=== RUN TestPendingClosureWriteTimeout674=== PAUSE TestPendingClosureWriteTimeout675=== RUN TestIsValidUploadKey676=== PAUSE TestIsValidUploadKey677=== RUN TestUploadHandlersRejectInvalidKeys678=== PAUSE TestUploadHandlersRejectInvalidKeys679=== RUN TestUploadHandlersRejectOversizedBody680=== PAUSE TestUploadHandlersRejectOversizedBody681=== RUN TestService_cleanupPendingClosuresHandler682=== PAUSE TestService_cleanupPendingClosuresHandler683=== RUN TestService_createPendingClosureHandler684=== PAUSE TestService_createPendingClosureHandler685=== RUN TestService_verifyS3Integrity686=== PAUSE TestService_verifyS3Integrity687=== RUN TestCompleteMultipartUnregistered688=== PAUSE TestCompleteMultipartUnregistered689=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT690=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT691=== CONT TestService_AuthMiddleware692=== CONT TestProxyHeadersOnlyTrustedOnSocket693=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT694=== CONT TestCompleteMultipartUnregistered695=== CONT TestService_verifyS3Integrity696=== CONT TestService_createPendingClosureHandler697=== CONT TestService_cleanupPendingClosuresHandler698=== CONT TestUploadHandlersRejectOversizedBody699=== CONT TestUploadHandlersRejectInvalidKeys700=== CONT TestIsValidUploadKey701=== RUN TestIsValidUploadKey/narinfo702=== CONT TestPendingClosureWriteTimeout703=== CONT TestProxyWriteTimeout704=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle705=== CONT TestSkippedUploadsHandler706=== CONT TestParseSize707=== CONT TestService_Rustfstest708=== CONT TestPresignedUploadRegisteredBeforeCommit709=== CONT TestCompletedNarNotReofferedAcrossClosures710=== CONT TestCompleteMultipartUpload_ErrorButObjectExists711=== CONT TestRedundantMultipartUpload712=== CONT TestPush_SignsNarinfosOfItsPendingObjects713=== CONT TestPush_RejectsBadRequests714=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit715=== CONT TestPush_CompleteCommitsEveryRoot716=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info717=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info718=== RUN TestProxyWriteTimeout/narinfo719=== PAUSE TestProxyWriteTimeout/narinfo720=== RUN TestProxyWriteTimeout/1_GiB_nar721=== RUN TestPendingClosureWriteTimeout/empty722=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal723--- PASS: TestParseSize (0.00s)724=== CONT TestPush_OverlappingRootsStoreOneRowPerKey725=== PAUSE TestIsValidUploadKey/narinfo7262026/10/06 21:12:40 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000727=== RUN TestIsValidUploadKey/nar_zst728=== PAUSE TestIsValidUploadKey/nar_zst729=== RUN TestIsValidUploadKey/nar_xz730=== PAUSE TestIsValidUploadKey/nar_xz731=== RUN TestIsValidUploadKey/nar_plain732=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal733=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key734=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key735=== PAUSE TestProxyWriteTimeout/1_GiB_nar736=== RUN TestProxyWriteTimeout/10_GiB_nar737=== PAUSE TestProxyWriteTimeout/10_GiB_nar738=== RUN TestProxyWriteTimeout/unknown_size739=== PAUSE TestProxyWriteTimeout/unknown_size740=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key741=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key742=== PAUSE TestIsValidUploadKey/nar_plain743=== RUN TestIsValidUploadKey/listing744=== PAUSE TestPendingClosureWriteTimeout/empty745=== CONT TestReadRedirectUsesPublicS3URL746=== RUN TestPendingClosureWriteTimeout/400_objects747=== PAUSE TestPendingClosureWriteTimeout/400_objects748=== RUN TestPendingClosureWriteTimeout/670k_objects749=== PAUSE TestPendingClosureWriteTimeout/670k_objects750=== CONT TestReadProxyRangeRequest751=== PAUSE TestIsValidUploadKey/listing752=== RUN TestIsValidUploadKey/build_log753=== PAUSE TestIsValidUploadKey/build_log754=== RUN TestIsValidUploadKey/build_log_home-manager_file755=== PAUSE TestIsValidUploadKey/build_log_home-manager_file756=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline757=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline758=== RUN TestIsValidUploadKey/build_log_plus_in_name759=== PAUSE TestIsValidUploadKey/build_log_plus_in_name760=== RUN TestIsValidUploadKey/build_log_question_mark761=== PAUSE TestIsValidUploadKey/build_log_question_mark762=== RUN TestIsValidUploadKey/build_log_equals763=== PAUSE TestIsValidUploadKey/build_log_equals764=== RUN TestIsValidUploadKey/realisation765=== CONT TestReadRedirectKeepsNarinfoProxied766=== PAUSE TestIsValidUploadKey/realisation767=== RUN TestIsValidUploadKey/realisation_plus_in_output768=== PAUSE TestIsValidUploadKey/realisation_plus_in_output769=== RUN TestIsValidUploadKey/nix-cache-info770=== PAUSE TestIsValidUploadKey/nix-cache-info771=== RUN TestIsValidUploadKey/index.html772=== PAUSE TestIsValidUploadKey/index.html773=== RUN TestIsValidUploadKey/narinfo_key,_nar_type774=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type775=== RUN TestIsValidUploadKey/nar_key,_narinfo_type776=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type777=== RUN TestIsValidUploadKey/listing_key,_narinfo_type778=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type779=== RUN TestIsValidUploadKey/traversal780=== PAUSE TestIsValidUploadKey/traversal781=== RUN TestIsValidUploadKey/traversal_nar782=== PAUSE TestIsValidUploadKey/traversal_nar783=== RUN TestIsValidUploadKey/absolute784=== PAUSE TestIsValidUploadKey/absolute785=== RUN TestIsValidUploadKey/empty_key786=== PAUSE TestIsValidUploadKey/empty_key787=== RUN TestIsValidUploadKey/unknown_type788=== PAUSE TestIsValidUploadKey/unknown_type789=== CONT TestReadRedirectNar790--- PASS: TestSkippedUploadsHandler (0.14s)791=== CONT TestReadProxyDisabled792=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure793=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure794=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart795=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart796=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts797=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts798=== CONT TestReadProxyRootRedirectsToIndexHTML7992026/10/06 21:12:40 INFO Received cleanup request method=DELETE path=/api/pending_closures8002026/10/06 21:12:40 INFO Aborted multipart uploads count=0 kept=08012026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures8022026/10/06 21:12:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8032026/10/06 21:12:40 INFO Received cleanup request method=DELETE path=/api/pending_closures8042026/10/06 21:12:40 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst805--- PASS: TestCompleteMultipartUnregistered (0.49s)806=== CONT TestReadProxyConditionalGet8072026/10/06 21:12:40 INFO Aborted multipart uploads count=1 kept=08082026/10/06 21:12:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8092026-10-06 21:12:40.574 UTC [645] ERROR: Closure does not exist: id=18102026-10-06 21:12:40.574 UTC [645] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8112026-10-06 21:12:40.574 UTC [645] STATEMENT: -- name: CommitPendingClosure :exec812 SELECT commit_pending_closure($1::bigint)813 814--- PASS: TestService_cleanupPendingClosuresHandler (0.49s)815=== CONT TestReadProxyOutlastsServerWriteTimeout8162026/10/06 21:12:40 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket702261574/001/proxy.sock8172026/10/06 21:12:40 INFO Starting HTTP server address=127.0.0.1:363818182026/10/06 21:12:40 WARN mTLS auth: subject not in bound subjects subject="CN=someone"8192026/10/06 21:12:40 INFO Shutdown signal received, draining in-flight requests timeout=10s820--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.51s)821=== CONT TestReadProxyHead8222026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures823--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)824=== CONT TestReadProxyInvalidPath8252026/10/06 21:12:40 INFO Received push request method=POST path=/api/pushes8262026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures827--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.59s)828=== CONT TestReadProxy4048292026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures8302026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures8312026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures8322026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures8332026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures8342026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures8352026/10/06 21:12:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8362026/10/06 21:12:40 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2JlYmIzNzItNDJmYS00YjlhLTk0ZmItZWU3NWY1YzE3MmNmLmY0NWFkMTUxLTcyMjItNGY4Ni1hOWUwLWQ0YTM1NDIxNjY5YngxNzkxMzIxMTYwNzMyMzkxMjg58372026/10/06 21:12:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2JlYmIzNzItNDJmYS00YjlhLTk0ZmItZWU3NWY1YzE3MmNmLmY0NWFkMTUxLTcyMjItNGY4Ni1hOWUwLWQ0YTM1NDIxNjY5YngxNzkxMzIxMTYwNzMyMzkxMjg5 parts=1838--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.69s)839=== CONT TestReadProxyNarStreaming8402026/10/06 21:12:40 INFO Received push request method=POST path=/api/pushes8412026/10/06 21:12:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8422026/10/06 21:12:40 INFO Signed narinfos id=1 count=18432026/10/06 21:12:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8442026/10/06 21:12:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8452026/10/06 21:12:40 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8462026/10/06 21:12:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8472026/10/06 21:12:40 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8482026/10/06 21:12:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8492026/10/06 21:12:40 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18502026/10/06 21:12:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8512026/10/06 21:12:40 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo852--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.71s)853=== CONT TestReadProxyContentNegotiation8542026/10/06 21:12:40 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"855--- PASS: TestService_AuthMiddleware (0.72s)856=== CONT TestReadProxyNarinfoAlreadyDecompressed857--- PASS: TestService_Rustfstest (0.75s)858=== CONT TestReadProxyNarinfo8592026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures8602026/10/06 21:12:40 INFO Received uploads request method=POST path=/api/pending_closures861=== RUN TestPush_RejectsBadRequests/no_roots862=== PAUSE TestPush_RejectsBadRequests/no_roots863=== RUN TestPush_RejectsBadRequests/no_objects864=== PAUSE TestPush_RejectsBadRequests/no_objects865=== RUN TestPush_RejectsBadRequests/bad_root866=== PAUSE TestPush_RejectsBadRequests/bad_root867=== RUN TestPush_RejectsBadRequests/root_not_in_objects868=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects869=== CONT TestIsValidCachePath870=== RUN TestIsValidCachePath/narinfo871=== PAUSE TestIsValidCachePath/narinfo872=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars873=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars874=== RUN TestIsValidCachePath/nar_zst875=== PAUSE TestIsValidCachePath/nar_zst876=== RUN TestIsValidCachePath/nar_xz877=== PAUSE TestIsValidCachePath/nar_xz878=== RUN TestIsValidCachePath/nar_bz2879=== PAUSE TestIsValidCachePath/nar_bz2880=== RUN TestIsValidCachePath/nar_uncompressed881=== PAUSE TestIsValidCachePath/nar_uncompressed882=== RUN TestIsValidCachePath/ls883=== PAUSE TestIsValidCachePath/ls884=== RUN TestIsValidCachePath/log885=== PAUSE TestIsValidCachePath/log886=== RUN TestIsValidCachePath/realisation887=== PAUSE TestIsValidCachePath/realisation888=== RUN TestIsValidCachePath/nix-cache-info889=== PAUSE TestIsValidCachePath/nix-cache-info890=== RUN TestIsValidCachePath/index.html891=== PAUSE TestIsValidCachePath/index.html892=== RUN TestIsValidCachePath/traversal_parent893=== PAUSE TestIsValidCachePath/traversal_parent894=== RUN TestIsValidCachePath/traversal_in_middle895=== PAUSE TestIsValidCachePath/traversal_in_middle896=== RUN TestIsValidCachePath/invalid_char_e897=== PAUSE TestIsValidCachePath/invalid_char_e898=== RUN TestIsValidCachePath/invalid_char_u899=== PAUSE TestIsValidCachePath/invalid_char_u900=== RUN TestIsValidCachePath/random_path901=== PAUSE TestIsValidCachePath/random_path902=== RUN TestIsValidCachePath/empty903=== PAUSE TestIsValidCachePath/empty904=== RUN TestIsValidCachePath/leading_slash905=== PAUSE TestIsValidCachePath/leading_slash906=== RUN TestIsValidCachePath/wrong_extension907=== PAUSE TestIsValidCachePath/wrong_extension908=== RUN TestIsValidCachePath/short_hash909=== PAUSE TestIsValidCachePath/short_hash910=== CONT TestGenerateLandingPage911--- PASS: TestGenerateLandingPage (0.00s)912=== CONT TestSweepSkipsRowsLockedByPush9132026/10/06 21:12:40 INFO Received push request method=POST path=/api/pushes9142026/10/06 21:12:40 INFO Received complete push request method=POST path=/api/pushes/1/complete915--- PASS: TestPush_CompleteCommitsEveryRoot (0.76s)916=== CONT TestParseSingleRange917=== RUN TestParseSingleRange/none918=== PAUSE TestParseSingleRange/none919=== RUN TestParseSingleRange/unknown_unit920=== PAUSE TestParseSingleRange/unknown_unit921=== RUN TestParseSingleRange/multi-range_ignored922=== PAUSE TestParseSingleRange/multi-range_ignored923=== RUN TestParseSingleRange/malformed_no_dash924=== PAUSE TestParseSingleRange/malformed_no_dash925=== RUN TestParseSingleRange/malformed_both_empty926=== PAUSE TestParseSingleRange/malformed_both_empty927=== RUN TestParseSingleRange/malformed_end_before_start928=== PAUSE TestParseSingleRange/malformed_end_before_start929=== RUN TestParseSingleRange/closed930=== PAUSE TestParseSingleRange/closed931=== RUN TestParseSingleRange/open-ended932=== PAUSE TestParseSingleRange/open-ended933=== RUN TestParseSingleRange/end_clamped_to_size934=== PAUSE TestParseSingleRange/end_clamped_to_size935=== RUN TestParseSingleRange/suffix936=== PAUSE TestParseSingleRange/suffix937=== RUN TestParseSingleRange/suffix_exceeds_size938=== PAUSE TestParseSingleRange/suffix_exceeds_size939=== RUN TestParseSingleRange/single_byte940=== PAUSE TestParseSingleRange/single_byte941=== RUN TestParseSingleRange/start_past_EOF942=== PAUSE TestParseSingleRange/start_past_EOF943=== RUN TestParseSingleRange/start_far_past_EOF944=== PAUSE TestParseSingleRange/start_far_past_EOF945=== CONT TestPresentNotReportedWhileGCDeletesClosure946--- PASS: TestReadRedirectNar (0.77s)947=== CONT TestService_readinessHandler9482026/10/06 21:12:41 INFO Received push request method=POST path=/api/pushes9492026/10/06 21:12:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9502026/10/06 21:12:41 INFO Received complete push request method=POST path=/api/pushes/1/complete9512026/10/06 21:12:41 INFO Received push request method=POST path=/api/pushes952--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.73s)953=== CONT TestService_healthCheckHandler954--- PASS: TestReadProxyDisabled (0.84s)955=== CONT TestPresentReportsOnlyClosureRoots9562026/10/06 21:12:41 INFO Aborted multipart uploads count=0 kept=0957--- PASS: TestReadProxyRangeRequest (0.89s)958=== CONT TestGracefulShutdownDrainsInflight9592026/10/06 21:12:41 INFO Starting HTTP server address=127.0.0.1:464519602026/10/06 21:12:41 INFO Shutdown signal received, draining in-flight requests timeout=10s9612026/10/06 21:12:41 WARN Force mode enabled - objects will be deleted immediately without grace period9622026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures9632026/10/06 21:12:41 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=09642026/10/06 21:12:41 INFO Vacuumed table table=pending_closures9652026/10/06 21:12:41 INFO Vacuumed table table=pending_objects9662026/10/06 21:12:41 INFO Vacuumed table table=multipart_uploads9672026/10/06 21:12:41 INFO Vacuumed table table=closures9682026/10/06 21:12:41 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9692026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures9702026/10/06 21:12:41 INFO Vacuumed table table=objects971--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.93s)9722026/10/06 21:12:41 INFO Received complete push request method=POST path=/api/pushes/2/complete973=== CONT TestGCTaskStore_Fail974--- PASS: TestGCTaskStore_Fail (0.00s)975=== CONT TestGCTaskStore_PhaseUpdates976--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)977=== CONT TestGCTaskStore_CompletedAllowsNewTask978--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)979=== CONT TestGCTaskStore_GetReturnsLatest980--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)981=== CONT TestCreatePin_ReservedPins982--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.94s)983=== CONT TestGCTaskStore_GetEmpty984--- PASS: TestGCTaskStore_GetEmpty (0.00s)985=== CONT TestOrphanedObjectsGCStressTest986--- PASS: TestReadRedirectKeepsNarinfoProxied (0.94s)987=== CONT TestOrphanedObjectsGC9882026/10/06 21:12:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete989--- PASS: TestGracefulShutdownDrainsInflight (0.07s)990=== CONT TestObjectStatsTrigger991--- PASS: TestReadRedirectUsesPublicS3URL (0.97s)992=== CONT TestGCTaskStore_ConflictDifferentParams993--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)994=== CONT TestPendingCleanupUsesOneCutoff9952026/10/06 21:12:41 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=M2JlYmIzNzItNDJmYS00YjlhLTk0ZmItZWU3NWY1YzE3MmNmLmFmYjc0NzljLTkzMDYtNDBkOC04YWEzLTdiYzEyZGI0YzZjYngxNzkxMzIxMTYwNzA1MTM5NDE0 parts=109962026/10/06 21:12:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9972026/10/06 21:12:41 INFO Completed upload id=19982026/10/06 21:12:41 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009992026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures10002026/10/06 21:12:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures10012026/10/06 21:12:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1002--- PASS: TestReadProxyHead (0.62s)1003=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10042026/10/06 21:12:41 INFO Aborted multipart uploads count=0 kept=010052026/10/06 21:12:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45933/oidc10062026/10/06 21:12:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10072026/10/06 21:12:41 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=010082026/10/06 21:12:41 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=M2JlYmIzNzItNDJmYS00YjlhLTk0ZmItZWU3NWY1YzE3MmNmLjIyYzQ4ODE2LWFhN2ItNDBlYS04YjE0LTU5NDVkYTkyMzc0YngxNzkxMzIxMTYwNzU4NjQ3MDM0 parts=1010092026/10/06 21:12:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10102026/10/06 21:12:41 INFO Vacuumed table table=pending_closures10112026/10/06 21:12:41 INFO Completed upload id=110122026/10/06 21:12:41 INFO Vacuumed table table=pending_objects10132026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures10142026/10/06 21:12:41 INFO Vacuumed table table=multipart_uploads10152026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures10162026/10/06 21:12:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=M2JlYmIzNzItNDJmYS00YjlhLTk0ZmItZWU3NWY1YzE3MmNmLmM0MzI2OWRjLWVmZTQtNDQ5NC05ZGY4LWNjMWNmNjhhYTY2ZHgxNzkxMzIxMTYwNjc2NzY3MDcw parts=1210172026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures1018--- PASS: TestReadProxyConditionalGet (0.68s)1019=== CONT TestGCTaskStore_DeduplicateSameParams1020--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1021=== CONT TestMultipartCleanup10222026/10/06 21:12:41 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10232026/10/06 21:12:41 WARN Found objects in DB but missing from S3, will re-upload count=110242026/10/06 21:12:41 INFO Vacuumed table table=closures1025--- PASS: TestService_verifyS3Integrity (1.17s)1026=== CONT TestServerTLSConfig1027=== RUN TestServerTLSConfig/no_client_CA1028=== PAUSE TestServerTLSConfig/no_client_CA1029=== RUN TestServerTLSConfig/missing_CA_file1030=== PAUSE TestServerTLSConfig/missing_CA_file1031=== RUN TestServerTLSConfig/not_a_PEM_file1032=== PAUSE TestServerTLSConfig/not_a_PEM_file1033=== CONT TestGCTaskStore_StartNew1034--- PASS: TestGCTaskStore_StartNew (0.00s)1035=== CONT TestService_NativeMTLS10362026/10/06 21:12:41 INFO Vacuumed table table=objects10372026/10/06 21:12:41 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010382026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures1039--- PASS: TestService_createPendingClosureHandler (1.18s)1040=== CONT TestMetricsInventory1041--- PASS: TestReadProxyInvalidPath (0.63s)1042=== CONT TestGCEndsOnShutdown1043=== RUN TestGCEndsOnShutdown/before_the_run1044=== PAUSE TestGCEndsOnShutdown/before_the_run1045=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1046=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1047=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1048=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1049=== CONT TestNARDeduplicationMetadataUploadBug1050--- PASS: TestReadProxy404 (0.62s)1051=== CONT TestCreatePendingClosureRejectsOversizedNAR10522026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures1053--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1054=== CONT TestGetExistingObjectsLocksRows1055--- PASS: TestReadProxyNarStreaming (0.53s)1056=== CONT TestCacheConfigHandlerMaxNarSize1057--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1058=== CONT TestRegisterCompletedObjectNeedsPendingRow1059--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.55s)1060=== CONT TestCommitRacingPendingCleanupKeepsObjects10612026/10/06 21:12:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1062--- PASS: TestReadProxyContentNegotiation (0.58s)1063=== CONT TestPushWaitsForSweepHoldingRow10642026/10/06 21:12:41 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=M2JlYmIzNzItNDJmYS00YjlhLTk0ZmItZWU3NWY1YzE3MmNmLjFlODIxZDY3LTlhNjYtNGFjMS04ODVkLWZmNGJmYWIwMzE0NXgxNzkxMzIxMTYwODc1NDM1NTk3 parts=1210652026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures1066--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.30s)1067=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10682026/10/06 21:12:41 INFO Aborted multipart uploads count=0 kept=010692026/10/06 21:12:41 WARN Force mode enabled - objects will be deleted immediately without grace period10702026/10/06 21:12:41 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=010712026/10/06 21:12:41 INFO Vacuumed table table=pending_closures10722026/10/06 21:12:41 INFO Vacuumed table table=pending_objects10732026/10/06 21:12:41 INFO Vacuumed table table=multipart_uploads10742026/10/06 21:12:41 INFO Vacuumed table table=closures10752026/10/06 21:12:41 INFO Vacuumed table table=objects10762026/10/06 21:12:41 INFO Aborted multipart uploads count=0 kept=010772026/10/06 21:12:41 WARN Force mode enabled - objects will be deleted immediately without grace period10782026/10/06 21:12:41 WARN readiness check failed error="closed pool"1079--- PASS: TestService_readinessHandler (0.45s)1080=== CONT TestPushDedupSurvivesConcurrentGC10812026/10/06 21:12:41 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=010822026/10/06 21:12:41 INFO Vacuumed table table=pending_closures10832026/10/06 21:12:41 INFO Vacuumed table table=pending_objects10842026/10/06 21:12:41 INFO Vacuumed table table=multipart_uploads10852026/10/06 21:12:41 INFO Vacuumed table table=closures10862026/10/06 21:12:41 INFO Vacuumed table table=objects1087--- PASS: TestSweepSkipsRowsLockedByPush (0.54s)1088=== CONT TestSweepRechecksPendingAfterLocking1089--- PASS: TestService_healthCheckHandler (0.42s)1090=== CONT TestGCMetrics10912026/10/06 21:12:41 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1092--- PASS: TestReadProxyNarinfo (0.64s)1093=== CONT TestFailedS3DeleteKeepsTombstone1094--- PASS: TestPresentReportsOnlyClosureRoots (0.45s)1095=== CONT TestGCBugBareHashReferences10962026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures1097--- PASS: TestObjectStatsTrigger (0.42s)1098=== CONT TestGCSweepDeliversEachKeyOnce10992026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures11002026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures11012026/10/06 21:12:41 INFO Received cleanup request method=DELETE path=/api/pending_closures1102--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.43s)1103=== CONT TestTombstonedObjectOfferedWithoutWaiting11042026/10/06 21:12:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11052026/10/06 21:12:41 WARN Refused reserved pin name=worker-x86_64-linux11062026/10/06 21:12:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11072026/10/06 21:12:41 INFO Received create pin request method=POST path=/api/pins/my-app11082026/10/06 21:12:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1109--- PASS: TestCreatePin_ReservedPins (0.51s)1110=== CONT TestForceGCDuringPushOffersSweptObject1111=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1112=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1113=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1114=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1115=== CONT TestGCSweepSkipsPendingObjects1116--- PASS: TestMetricsInventory (0.45s)1117=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11182026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures11192026/10/06 21:12:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11202026/10/06 21:12:41 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=M2JlYmIzNzItNDJmYS00YjlhLTk0ZmItZWU3NWY1YzE3MmNmLmM5OWZkZmJiLTg4NmUtNGJlZC1iMmYxLTQ5MjkwMzRiOTM1OXgxNzkxMzIxMTYxMjU5NTU0OTM1 error="Get \"http://127.0.0.1:1/bucket8/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11212026/10/06 21:12:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=M2JlYmIzNzItNDJmYS00YjlhLTk0ZmItZWU3NWY1YzE3MmNmLjg0YTk2YWVmLWYyNGQtNDQ4YS1iM2Q3LTg2MDVlMjQ2NTMwZHgxNzkxMzIxMTYxMjUxMzEyNTkz parts=1211222026/10/06 21:12:41 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11232026/10/06 21:12:41 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1124--- PASS: TestService_NativeMTLS (0.51s)1125=== CONT TestDeduplicatedObjectsRecordedAsPending11262026/10/06 21:12:41 INFO Received cleanup request method=DELETE path=/api/pending_closures11272026/10/06 21:12:41 INFO Aborted multipart uploads count=1 kept=01128--- PASS: TestRedundantMultipartUpload (1.70s)1129=== CONT TestLeadElectsOneAndHandsOver11302026/10/06 21:12:41 INFO Received cleanup request method=DELETE path=/api/pending_closures11312026/10/06 21:12:41 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket48/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11322026/10/06 21:12:41 INFO Aborted multipart uploads count=0 kept=111332026/10/06 21:12:41 INFO Received cleanup request method=DELETE path=/api/pending_closures11342026/10/06 21:12:41 INFO Aborted multipart uploads count=1 kept=01135--- PASS: TestMultipartCleanup (0.59s)1136=== CONT TestGCAdvisoryLockBlocksConcurrentRun1137--- PASS: TestGetExistingObjectsLocksRows (0.57s)1138=== CONT TestLeadEndsOnShutdown1139=== NAME TestNARDeduplicationMetadataUploadBug1140 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3309624735/001/store/khcvd96pjyx86zb77ngn5cfdrga2y4vw-file1.txt1141--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.57s)1142=== CONT TestClientCADerivations1143=== NAME TestOrphanedObjectsGC1144 orphaned_objects_gc_test.go:290: GC Test Summary:1145 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1146 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1147 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1148 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1149 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1150--- PASS: TestOrphanedObjectsGC (0.72s)1151=== CONT TestConnectWaitsForAPeerMigration1152--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.95s)1153=== CONT TestLeadIncumbentAnnouncesAtOnce11542026/10/06 21:12:41 INFO Received uploads request method=POST path=/api/pending_closures11552026/10/06 21:12:41 INFO Aborted multipart uploads count=0 kept=011562026/10/06 21:12:41 WARN Force mode enabled - objects will be deleted immediately without grace period11572026/10/06 21:12:41 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=011582026/10/06 21:12:41 INFO Vacuumed table table=pending_closures11592026/10/06 21:12:41 INFO Received push request method=POST path=/api/pushes11602026/10/06 21:12:41 INFO Vacuumed table table=pending_objects11612026/10/06 21:12:41 INFO Vacuumed table table=multipart_uploads11622026/10/06 21:12:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11632026/10/06 21:12:41 INFO Vacuumed table table=closures11642026/10/06 21:12:41 INFO Uploading khcvd96pjyx86zb77ngn5cfdrga2y4vw-file1.txt (160B)11652026/10/06 21:12:41 INFO Vacuumed table table=objects11662026/10/06 21:12:41 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11672026/10/06 21:12:41 WARN Failed to register uploaded object key=khcvd96pjyx86zb77ngn5cfdrga2y4vw.ls error="server returned 404: 404 page not found\n"1168--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.61s)11692026/10/06 21:12:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1170=== CONT TestResolveDBConnectionString11712026/10/06 21:12:41 INFO Signed narinfos id=1 count=111722026/10/06 21:12:41 INFO Uploading 1 narinfos1173=== RUN TestResolveDBConnectionString/flag_wins1174=== PAUSE TestResolveDBConnectionString/flag_wins1175=== RUN TestResolveDBConnectionString/file_when_flag_empty1176=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1177=== RUN TestResolveDBConnectionString/missing_file_is_an_error1178=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1179=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1180=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1181=== RUN TestResolveDBConnectionString/nothing_configured1182=== PAUSE TestResolveDBConnectionString/nothing_configured1183=== CONT TestClientFallsBackToClosures11842026/10/06 21:12:41 INFO Received complete push request method=POST path=/api/pushes/1/complete11852026/10/06 21:12:41 WARN Failed to register uploaded object key=khcvd96pjyx86zb77ngn5cfdrga2y4vw.narinfo error="server returned 404: 404 page not found\n"11862026/10/06 21:12:41 INFO Upload complete. (73ms)1187=== NAME TestNARDeduplicationMetadataUploadBug1188 metadata_upload_test.go:54: Retrieved narinfo from S3:1189 StorePath: /build/TestNARDeduplicationMetadataUploadBug3309624735/001/store/khcvd96pjyx86zb77ngn5cfdrga2y4vw-file1.txt1190 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1191 Compression: zstd1192 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1193 NarSize: 1601194 References: 1195 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1196 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1197 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1198 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11992026/10/06 21:12:42 INFO Received uploads request method=POST path=/api/pending_closures1200 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3309624735/001/store/ci9ygff5r6h0g7mjgswg66ncn3hzb6lw-file2.txt12012026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=012022026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period12032026/10/06 21:12:42 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=012042026/10/06 21:12:42 INFO Vacuumed table table=pending_closures12052026/10/06 21:12:42 INFO Vacuumed table table=pending_objects12062026/10/06 21:12:42 INFO Vacuumed table table=multipart_uploads12072026/10/06 21:12:42 INFO Vacuumed table table=closures12082026/10/06 21:12:42 INFO Vacuumed table table=objects1209--- PASS: TestGCMetrics (0.59s)1210=== CONT TestService_RequireScope_OIDC12112026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=012122026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period12132026/10/06 21:12:42 INFO Received uploads request method=POST path=/api/pending_closures12142026/10/06 21:12:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35303/oidc12152026/10/06 21:12:42 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=012162026/10/06 21:12:42 INFO Vacuumed table table=pending_closures12172026/10/06 21:12:42 INFO Vacuumed table table=pending_objects12182026/10/06 21:12:42 INFO Vacuumed table table=multipart_uploads12192026/10/06 21:12:42 INFO Vacuumed table table=closures12202026/10/06 21:12:42 INFO Vacuumed table table=objects12212026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=01222--- PASS: TestSweepRechecksPendingAfterLocking (0.63s)1223=== CONT TestClientWithDependencies12242026/10/06 21:12:42 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=012252026/10/06 21:12:42 INFO Vacuumed table table=pending_closures12262026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes12272026/10/06 21:12:42 INFO Vacuumed table table=pending_objects12282026/10/06 21:12:42 INFO Vacuumed table table=multipart_uploads12292026/10/06 21:12:42 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12302026/10/06 21:12:42 INFO Vacuumed table table=closures12312026/10/06 21:12:42 INFO Vacuumed table table=objects12322026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12332026/10/06 21:12:42 INFO Signed narinfos id=2 count=112342026/10/06 21:12:42 WARN Failed to register uploaded object key=ci9ygff5r6h0g7mjgswg66ncn3hzb6lw.ls error="server returned 404: 404 page not found\n"12352026/10/06 21:12:42 INFO Uploading 1 narinfos12362026/10/06 21:12:42 INFO Received complete push request method=POST path=/api/pushes/2/complete12372026/10/06 21:12:42 WARN Failed to register uploaded object key=ci9ygff5r6h0g7mjgswg66ncn3hzb6lw.narinfo error="server returned 404: 404 page not found\n"12382026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=012392026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period12402026/10/06 21:12:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012412026/10/06 21:12:42 INFO Upload complete. (56ms)1242=== NAME TestNARDeduplicationMetadataUploadBug1243 metadata_upload_test.go:76: Retrieved narinfo from S3:1244 StorePath: /build/TestNARDeduplicationMetadataUploadBug3309624735/001/store/ci9ygff5r6h0g7mjgswg66ncn3hzb6lw-file2.txt1245 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1246 Compression: zstd1247 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1248 NarSize: 1601249 References: 1250 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12512026/10/06 21:12:42 INFO Vacuumed table table=pending_closures1252 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)12532026/10/06 21:12:42 INFO Vacuumed table table=pending_objects1254 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1255 {"version":1,"root":{"type":"regular","size":44}}12562026/10/06 21:12:42 INFO Vacuumed table table=multipart_uploads12572026/10/06 21:12:42 INFO Vacuumed table table=closures12582026/10/06 21:12:42 INFO Vacuumed table table=objects1259--- PASS: TestPushDedupSurvivesConcurrentGC (0.69s)1260=== CONT TestCacheStatsHandler1261--- PASS: TestNARDeduplicationMetadataUploadBug (0.87s)1262=== CONT TestClientPushesUseOnePush12632026/10/06 21:12:42 INFO Received uploads request method=POST path=/api/pending_closures12642026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=012652026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period1266--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.51s)1267=== CONT TestCacheConfigHandler1268=== RUN TestCacheConfigHandler/full_config,_no_issuer1269=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1270=== RUN TestCacheConfigHandler/no_cache_url_configured1271=== PAUSE TestCacheConfigHandler/no_cache_url_configured1272=== RUN TestCacheConfigHandler/no_signing_keys1273=== PAUSE TestCacheConfigHandler/no_signing_keys1274=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1275=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1276=== CONT TestPinProtectsFromGC12772026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=012782026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period12792026/10/06 21:12:42 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=012802026/10/06 21:12:42 INFO Vacuumed table table=pending_closures12812026/10/06 21:12:42 INFO Vacuumed table table=pending_objects12822026/10/06 21:12:42 INFO Vacuumed table table=multipart_uploads12832026/10/06 21:12:42 INFO Vacuumed table table=closures12842026/10/06 21:12:42 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12852026/10/06 21:12:42 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12862026/10/06 21:12:42 INFO Vacuumed table table=objects1287--- PASS: TestGCSweepDeliversEachKeyOnce (0.58s)1288=== CONT TestClientSharedPathCommittedMidPush1289--- PASS: TestFailedS3DeleteKeepsTombstone (0.70s)1290=== CONT TestService_ReadScope_PublicByDefault12912026/10/06 21:12:42 INFO Received uploads request method=POST path=/api/pending_closures12922026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=012932026/10/06 21:12:42 INFO Received uploads request method=POST path=/api/pending_closures12942026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period12952026/10/06 21:12:42 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=012962026/10/06 21:12:42 INFO Vacuumed table table=pending_closures12972026/10/06 21:12:42 INFO Vacuumed table table=pending_objects12982026/10/06 21:12:42 INFO Vacuumed table table=multipart_uploads12992026/10/06 21:12:42 INFO Vacuumed table table=closures13002026/10/06 21:12:42 INFO Vacuumed table table=objects13012026/10/06 21:12:42 INFO Received uploads request method=POST path=/api/pending_closures1302--- PASS: TestGCSweepSkipsPendingObjects (0.57s)1303=== CONT TestClientMultipleUploads1304--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.47s)1305=== CONT TestClientErrorHandling1306=== RUN TestClientErrorHandling/InvalidStorePath1307=== PAUSE TestClientErrorHandling/InvalidStorePath1308=== RUN TestClientErrorHandling/InvalidAuthToken1309=== PAUSE TestClientErrorHandling/InvalidAuthToken1310=== RUN TestClientErrorHandling/ServerNotAvailable1311=== PAUSE TestClientErrorHandling/ServerNotAvailable1312=== CONT TestService_ReadAuthMiddleware13132026/10/06 21:12:42 INFO lead: acquired remote=192.0.2.1:12341314--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.87s)1315=== CONT TestClientIntegration13162026/10/06 21:12:42 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1317--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.44s)1318=== CONT TestService_AuthMiddleware_OIDC13192026/10/06 21:12:42 INFO lead: acquired remote=192.0.2.1:12341320--- PASS: TestGCBugBareHashReferences (0.83s)1321=== CONT TestService_AuthMiddleware_MTLSProxyHeader13222026/10/06 21:12:42 INFO lead: acquired remote=192.0.2.1:123413232026/10/06 21:12:42 INFO lead: released remote=192.0.2.1:12341324--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.42s)1325=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13262026/10/06 21:12:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32819/oidc1327=== RUN TestService_RequireScope_OIDC/builder_may_write1328=== PAUSE TestService_RequireScope_OIDC/builder_may_write1329=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1330=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1331=== RUN TestService_RequireScope_OIDC/ops_may_admin1332=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1333=== RUN TestService_RequireScope_OIDC/ops_may_not_write1334=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1335=== RUN TestService_RequireScope_OIDC/reader_may_not_write1336=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1337=== RUN TestService_RequireScope_OIDC/static_token_may_admin1338=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1339=== RUN TestService_RequireScope_OIDC/static_token_may_write1340=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1341=== RUN TestService_RequireScope_OIDC/reader_may_read1342=== PAUSE TestService_RequireScope_OIDC/reader_may_read1343=== RUN TestService_RequireScope_OIDC/writer_implies_read1344=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1345=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1346=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1347=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1348=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1349=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1350=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1351=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1352=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1353=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1354=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1355=== CONT TestProxyWriteTimeout/narinfo1356=== CONT TestProxyWriteTimeout/unknown_size1357=== CONT TestProxyWriteTimeout/10_GiB_nar1358=== CONT TestProxyWriteTimeout/1_GiB_nar1359--- PASS: TestProxyWriteTimeout (0.13s)1360 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1361 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1362 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1363 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1364=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13652026/10/06 21:12:42 INFO Received uploads request method=POST path=/1366=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13672026/10/06 21:12:42 INFO Received complete multipart upload request method=POST path=/1368=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13692026/10/06 21:12:42 INFO Received request for more parts method=POST path=/1370=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal13712026/10/06 21:12:42 INFO Received uploads request method=POST path=/1372--- PASS: TestUploadHandlersRejectInvalidKeys (0.13s)1373 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1374 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1375 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1376 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1377=== CONT TestPendingClosureWriteTimeout/empty1378=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1379=== NAME TestClientCADerivations1380 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4241900900/001/store/sc4k834yan3z5f2i3793vcwxlfy98klg-ca-test1381--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.72s)1382=== CONT TestPendingClosureWriteTimeout/400_objects1383=== CONT TestPendingClosureWriteTimeout/670k_objects1384=== CONT TestIsValidUploadKey/narinfo1385=== CONT TestIsValidUploadKey/empty_key1386=== CONT TestIsValidUploadKey/absolute1387=== CONT TestIsValidUploadKey/traversal_nar1388=== CONT TestIsValidUploadKey/traversal1389=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1390=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1391=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1392=== CONT TestIsValidUploadKey/index.html1393=== CONT TestIsValidUploadKey/nix-cache-info1394=== CONT TestIsValidUploadKey/realisation_plus_in_output1395=== CONT TestIsValidUploadKey/realisation1396=== CONT TestIsValidUploadKey/build_log_equals1397=== CONT TestIsValidUploadKey/build_log_question_mark1398=== CONT TestIsValidUploadKey/build_log_plus_in_name1399=== CONT TestIsValidUploadKey/unknown_type1400=== CONT TestIsValidUploadKey/build_log_home-manager_file1401=== CONT TestIsValidUploadKey/build_log1402=== CONT TestIsValidUploadKey/listing1403=== CONT TestIsValidUploadKey/nar_plain1404=== CONT TestIsValidUploadKey/nar_xz1405=== CONT TestIsValidUploadKey/nar_zst1406--- PASS: TestIsValidUploadKey (0.14s)1407 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1408 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1409 --- PASS: TestIsValidUploadKey/absolute (0.00s)1410 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1411 --- PASS: TestIsValidUploadKey/traversal (0.00s)1412 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1413 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1414 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1415 --- PASS: TestIsValidUploadKey/index.html (0.00s)1416 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1417 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1418 --- PASS: TestIsValidUploadKey/realisation (0.00s)1419 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1420 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1421 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1422 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1423 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1424 --- PASS: TestIsValidUploadKey/build_log (0.00s)1425 --- PASS: TestIsValidUploadKey/listing (0.00s)1426 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1427 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1428 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1429=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14302026/10/06 21:12:42 INFO Received uploads request method=POST path=/1431--- PASS: TestPushWaitsForSweepHoldingRow (1.07s)1432=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14332026/10/06 21:12:42 INFO Received request for more parts method=POST path=/1434=== NAME TestClientCADerivations1435 client_ca_test.go:139: Found 1 dependencies (including self)1436--- PASS: TestCacheStatsHandler (0.34s)1437=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14382026/10/06 21:12:42 INFO Received complete multipart upload request method=POST path=/1439=== CONT TestPush_RejectsBadRequests/no_roots14402026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes1441=== CONT TestPush_RejectsBadRequests/bad_root14422026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes1443=== CONT TestPush_RejectsBadRequests/no_objects14442026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes1445=== CONT TestPush_RejectsBadRequests/root_not_in_objects14462026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes1447=== CONT TestIsValidCachePath/narinfo1448--- PASS: TestPush_RejectsBadRequests (0.70s)1449 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1450 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1451 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1452 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1453=== CONT TestIsValidCachePath/index.html1454=== CONT TestIsValidCachePath/short_hash1455=== CONT TestIsValidCachePath/wrong_extension1456=== CONT TestIsValidCachePath/leading_slash1457=== CONT TestIsValidCachePath/empty1458=== CONT TestIsValidCachePath/random_path1459=== CONT TestIsValidCachePath/traversal_in_middle1460=== CONT TestIsValidCachePath/traversal_parent1461=== CONT TestIsValidCachePath/nar_uncompressed1462=== CONT TestIsValidCachePath/invalid_char_e1463=== CONT TestIsValidCachePath/nix-cache-info1464=== CONT TestIsValidCachePath/invalid_char_u1465=== CONT TestIsValidCachePath/realisation1466=== CONT TestIsValidCachePath/ls1467=== CONT TestIsValidCachePath/log1468=== CONT TestIsValidCachePath/nar_zst1469=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1470=== CONT TestIsValidCachePath/nar_bz21471=== CONT TestIsValidCachePath/nar_xz1472--- PASS: TestIsValidCachePath (0.00s)1473 --- PASS: TestIsValidCachePath/narinfo (0.00s)1474 --- PASS: TestIsValidCachePath/index.html (0.00s)1475 --- PASS: TestIsValidCachePath/short_hash (0.00s)1476 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1477 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1478 --- PASS: TestIsValidCachePath/empty (0.00s)1479 --- PASS: TestIsValidCachePath/random_path (0.00s)1480 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1481 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1482 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1483 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1484 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1485 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1486 --- PASS: TestIsValidCachePath/realisation (0.00s)1487 --- PASS: TestIsValidCachePath/ls (0.00s)1488 --- PASS: TestIsValidCachePath/log (0.00s)1489 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1490 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1491 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1492 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1493=== CONT TestParseSingleRange/none1494=== CONT TestParseSingleRange/open-ended1495=== CONT TestParseSingleRange/start_far_past_EOF1496=== CONT TestParseSingleRange/start_past_EOF1497=== CONT TestParseSingleRange/single_byte1498=== CONT TestParseSingleRange/suffix_exceeds_size1499=== CONT TestParseSingleRange/suffix1500=== CONT TestParseSingleRange/end_clamped_to_size1501=== CONT TestParseSingleRange/malformed_both_empty1502=== CONT TestParseSingleRange/closed1503=== CONT TestParseSingleRange/malformed_end_before_start1504=== CONT TestParseSingleRange/unknown_unit1505=== CONT TestParseSingleRange/malformed_no_dash1506=== CONT TestParseSingleRange/multi-range_ignored1507--- PASS: TestParseSingleRange (0.00s)1508 --- PASS: TestParseSingleRange/none (0.00s)1509 --- PASS: TestParseSingleRange/open-ended (0.00s)1510 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1511 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1512 --- PASS: TestParseSingleRange/single_byte (0.00s)1513 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1514 --- PASS: TestParseSingleRange/suffix (0.00s)1515 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1516 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1517 --- PASS: TestParseSingleRange/closed (0.00s)1518 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1519 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1520 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1521 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1522=== CONT TestServerTLSConfig/no_client_CA1523=== CONT TestServerTLSConfig/not_a_PEM_file1524=== CONT TestServerTLSConfig/missing_CA_file1525--- PASS: TestServerTLSConfig (0.00s)1526 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1527 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1528 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1529=== CONT TestGCEndsOnShutdown/before_the_run1530--- PASS: TestService_ReadScope_PublicByDefault (0.32s)1531=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1532=== NAME TestClientWithDependencies1533 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies491060308/001/store/skxz0j4va4hr57vj0f1xa71bqf27bx5p-test-script1534 client_integration_test.go:615: Found 1 dependencies (including self)1535--- PASS: TestService_ReadAuthMiddleware (0.31s)1536=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1537=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows15382026/10/06 21:12:42 INFO Received uploads request method=POST path=/api/pending_closures1539=== NAME TestPinProtectsFromGC1540 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC425655533/001/store/h3qpn8w9h6cjb9ybngsf88gfi79zxhhk-pinned-file.txt1541 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC425655533/001/store/wjjin0n8x50k9l41f7aw0qz49yqghnpm-unpinned-file.txt15422026/10/06 21:12:42 INFO Received uploads request method=POST path=/api/pending_closures15432026/10/06 21:12:42 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15442026/10/06 21:12:42 INFO Uploading 1b87rd3aggyb0ziw1r1mwl6zin31mwql-shared-dep (136B)15452026/10/06 21:12:42 INFO Uploading xwnkja9yayggfjkmgccy874yi3mcc9dg-a (216B)15462026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes15472026/10/06 21:12:42 WARN Failed to register uploaded object key=gmhv1vvqs8sy8v3rj9nv54wnfxwk6rpy.ls error="server returned 404: 404 page not found\n"15482026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15492026/10/06 21:12:42 WARN Failed to register uploaded object key=1b87rd3aggyb0ziw1r1mwl6zin31mwql.ls error="server returned 404: 404 page not found\n"15502026/10/06 21:12:42 WARN Failed to register uploaded object key=xwnkja9yayggfjkmgccy874yi3mcc9dg.ls error="server returned 404: 404 page not found\n"15512026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15522026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/09xgsqpxkn17nzajgpwzpwvywdpn10if42kgz66vmgr9dx8ji9bg.nar.zst error="server returned 404: 404 page not found\n"15532026/10/06 21:12:42 INFO Signed narinfos id=1 count=215542026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15552026/10/06 21:12:42 INFO Signed narinfos id=2 count=215562026/10/06 21:12:42 INFO Uploading 4 narinfos15572026/10/06 21:12:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15582026/10/06 21:12:42 WARN Failed to register uploaded object key=1b87rd3aggyb0ziw1r1mwl6zin31mwql.narinfo error="server returned 404: 404 page not found\n"15592026/10/06 21:12:42 INFO Uploading sc4k834yan3z5f2i3793vcwxlfy98klg-ca-test (144B)15602026/10/06 21:12:42 WARN Failed to register uploaded object key=xwnkja9yayggfjkmgccy874yi3mcc9dg.narinfo error="server returned 404: 404 page not found\n"15612026/10/06 21:12:42 WARN Failed to register uploaded object key=gmhv1vvqs8sy8v3rj9nv54wnfxwk6rpy.narinfo error="server returned 404: 404 page not found\n"15622026/10/06 21:12:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15632026/10/06 21:12:42 WARN Failed to register uploaded object key=1b87rd3aggyb0ziw1r1mwl6zin31mwql.narinfo error="server returned 404: 404 page not found\n"15642026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15652026/10/06 21:12:42 WARN Failed to register uploaded object key=log/mc6m0bg3q0rsxa72z4gh38c2yx74m5n2-ca-test.drv error="server returned 404: 404 page not found\n"15662026/10/06 21:12:42 WARN Failed to register uploaded object key=sc4k834yan3z5f2i3793vcwxlfy98klg.ls error="server returned 404: 404 page not found\n"15672026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15682026/10/06 21:12:42 INFO Signed narinfos id=1 count=115692026/10/06 21:12:42 INFO Uploading 1 narinfos15702026/10/06 21:12:42 INFO Received complete push request method=POST path=/api/pushes/1/complete15712026/10/06 21:12:42 WARN Failed to register uploaded object key=sc4k834yan3z5f2i3793vcwxlfy98klg.narinfo error="server returned 404: 404 page not found\n"15722026/10/06 21:12:42 INFO Completed upload id=115732026/10/06 21:12:42 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15742026/10/06 21:12:42 INFO Completed upload id=215752026/10/06 21:12:42 INFO Upload complete. (74ms)1576=== NAME TestClientFallsBackToClosures1577 client_pushes_test.go:112: Retrieved narinfo from S3:1578 StorePath: /build/TestClientFallsBackToClosures3733562700/001/store/1b87rd3aggyb0ziw1r1mwl6zin31mwql-shared-dep1579 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1580 Compression: zstd1581 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821582 NarSize: 1361583 References: 1584 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1585 client_pushes_test.go:112: Retrieved narinfo from S3:1586 StorePath: /build/TestClientFallsBackToClosures3733562700/001/store/xwnkja9yayggfjkmgccy874yi3mcc9dg-a1587 URL: nar/09xgsqpxkn17nzajgpwzpwvywdpn10if42kgz66vmgr9dx8ji9bg.nar.zst1588 Compression: zstd1589 NarHash: sha256:09xgsqpxkn17nzajgpwzpwvywdpn10if42kgz66vmgr9dx8ji9bg1590 NarSize: 2161591 References: /build/TestClientFallsBackToClosures3733562700/001/store/1b87rd3aggyb0ziw1r1mwl6zin31mwql-shared-dep1592 CA: text:sha256:0ysm2mqkcwfnsd05v7ll3nc2ch95xrjgliwxgx98jv4yl2sg47dx15932026/10/06 21:12:42 INFO Upload complete. (111ms)1594 client_pushes_test.go:112: Retrieved narinfo from S3:1595 StorePath: /build/TestClientFallsBackToClosures3733562700/001/store/gmhv1vvqs8sy8v3rj9nv54wnfxwk6rpy-b1596 URL: nar/09xgsqpxkn17nzajgpwzpwvywdpn10if42kgz66vmgr9dx8ji9bg.nar.zst1597 Compression: zstd1598 NarHash: sha256:09xgsqpxkn17nzajgpwzpwvywdpn10if42kgz66vmgr9dx8ji9bg1599 NarSize: 2161600 References: /build/TestClientFallsBackToClosures3733562700/001/store/1b87rd3aggyb0ziw1r1mwl6zin31mwql-shared-dep1601 CA: text:sha256:0ysm2mqkcwfnsd05v7ll3nc2ch95xrjgliwxgx98jv4yl2sg47dx1602=== NAME TestClientCADerivations1603 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4241900900/001/store/sc4k834yan3z5f2i3793vcwxlfy98klg-ca-test1604 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1605 Compression: zstd1606 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1607 NarSize: 1441608 References: 1609 Deriver: /build/TestClientCADerivations4241900900/001/store/mc6m0bg3q0rsxa72z4gh38c2yx74m5n2-ca-test.drv1610 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1611 client_ca_test.go:185: Checking for realisation files in S3...1612 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1613 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1614--- PASS: TestClientFallsBackToClosures (0.64s)1615=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1616=== NAME TestClientMultipleUploads1617 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3449093081/001/store/y0j77gyprkkvq8amz3zv3q0digdnx84v-test-file-0.txt1618--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.28s)1619=== CONT TestResolveDBConnectionString/flag_wins1620=== CONT TestResolveDBConnectionString/nothing_configured1621=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1622=== CONT TestResolveDBConnectionString/missing_file_is_an_error1623=== CONT TestResolveDBConnectionString/file_when_flag_empty1624=== CONT TestCacheConfigHandler/full_config,_no_issuer1625=== CONT TestCacheConfigHandler/no_signing_keys1626=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1627=== CONT TestCacheConfigHandler/no_cache_url_configured1628=== CONT TestClientErrorHandling/InvalidStorePath1629--- PASS: TestResolveDBConnectionString (0.00s)1630 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1631 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1632 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1633 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1634 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1635--- PASS: TestCacheConfigHandler (0.00s)1636 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1637 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1638 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1639 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)16402026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes16412026/10/06 21:12:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16422026/10/06 21:12:42 INFO Uploading skxz0j4va4hr57vj0f1xa71bqf27bx5p-test-script (136B)16432026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes16442026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes16452026/10/06 21:12:42 WARN Failed to register uploaded object key=log/b6df5d04xbi581bckxb61lmdqrphdpzq-test-script.drv error="server returned 404: 404 page not found\n"16462026/10/06 21:12:42 WARN Failed to register uploaded object key=skxz0j4va4hr57vj0f1xa71bqf27bx5p.ls error="server returned 404: 404 page not found\n"16472026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16482026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16492026/10/06 21:12:42 INFO Signed narinfos id=1 count=116502026/10/06 21:12:42 INFO Uploading 1 narinfos16512026/10/06 21:12:42 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16522026/10/06 21:12:42 WARN mTLS auth: bound subjects configured but subject DN unavailable16532026/10/06 21:12:42 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1654--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.30s)1655=== CONT TestClientErrorHandling/InvalidAuthToken1656=== NAME TestClientIntegration1657 client_integration_test.go:286: Created store path: /build/TestClientIntegration3418259266/002/store/xl9n4xg1zrzx4p42jving74jlyc98k9v-test-file.txt16582026/10/06 21:12:42 INFO Received complete push request method=POST path=/api/pushes/1/complete16592026/10/06 21:12:42 WARN Failed to register uploaded object key=skxz0j4va4hr57vj0f1xa71bqf27bx5p.narinfo error="server returned 404: 404 page not found\n"1660=== NAME TestClientMultipleUploads1661 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3449093081/001/store/rfg1h206qcgznwrwpqbdmb59ghlmbkg0-test-file-1.txt16622026/10/06 21:12:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16632026/10/06 21:12:42 INFO Uploading h3qpn8w9h6cjb9ybngsf88gfi79zxhhk-pinned-file.txt (128B)16642026/10/06 21:12:42 INFO Upload complete. (76ms)16652026/10/06 21:12:42 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16662026/10/06 21:12:42 INFO Uploading rhcd9gr7l2g2m4zz0s6nvf641whhc9gz-shared-dep (136B)16672026/10/06 21:12:42 INFO Uploading g589hw86s6ym5q8dylc9ghsihdwzdiv7-b (216B)1668=== NAME TestClientWithDependencies1669 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies491060308/001/store) requires matching store prefix16702026/10/06 21:12:42 WARN Failed to register uploaded object key=h3qpn8w9h6cjb9ybngsf88gfi79zxhhk.ls error="server returned 404: 404 page not found\n"16712026/10/06 21:12:42 WARN Failed to register uploaded object key=h5jhbapp0374z8h6bf4mb1dbndfppi8m.ls error="server returned 404: 404 page not found\n"16722026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16732026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16742026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16752026/10/06 21:12:42 INFO Signed narinfos id=1 count=116762026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/0iajwx0c3nyfqb9pqmiaa25jwk3307xb44jw9g3m4b9la5xsvss5.nar.zst error="server returned 404: 404 page not found\n"16772026/10/06 21:12:42 INFO Uploading 1 narinfos16782026/10/06 21:12:42 WARN Failed to register uploaded object key=g589hw86s6ym5q8dylc9ghsihdwzdiv7.ls error="server returned 404: 404 page not found\n"16792026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16802026/10/06 21:12:42 WARN Failed to register uploaded object key=rhcd9gr7l2g2m4zz0s6nvf641whhc9gz.ls error="server returned 404: 404 page not found\n"16812026/10/06 21:12:42 INFO Signed narinfos id=1 count=316822026/10/06 21:12:42 INFO Uploading 3 narinfos16832026/10/06 21:12:42 INFO Received complete push request method=POST path=/api/pushes/1/complete16842026/10/06 21:12:42 WARN Failed to register uploaded object key=h3qpn8w9h6cjb9ybngsf88gfi79zxhhk.narinfo error="server returned 404: 404 page not found\n"1685--- PASS: TestClientWithDependencies (0.58s)1686=== CONT TestClientErrorHandling/ServerNotAvailable16872026/10/06 21:12:42 WARN Failed to register uploaded object key=h5jhbapp0374z8h6bf4mb1dbndfppi8m.narinfo error="server returned 404: 404 page not found\n"16882026/10/06 21:12:42 WARN Failed to register uploaded object key=rhcd9gr7l2g2m4zz0s6nvf641whhc9gz.narinfo error="server returned 404: 404 page not found\n"16892026/10/06 21:12:42 INFO Received complete push request method=POST path=/api/pushes/1/complete16902026/10/06 21:12:42 WARN Failed to register uploaded object key=g589hw86s6ym5q8dylc9ghsihdwzdiv7.narinfo error="server returned 404: 404 page not found\n"1691=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1692=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1693=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1694=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1695=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1696=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1697=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1698=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1699=== CONT TestService_RequireScope_OIDC/builder_may_write1700=== CONT TestService_RequireScope_OIDC/reader_may_read1701=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1702=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read17032026/10/06 21:12:42 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]1704=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1705=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1706=== CONT TestService_RequireScope_OIDC/writer_implies_read1707=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1708=== CONT TestService_RequireScope_OIDC/reader_may_not_write1709=== CONT TestService_RequireScope_OIDC/static_token_may_write1710=== CONT TestService_RequireScope_OIDC/static_token_may_admin1711=== CONT TestService_RequireScope_OIDC/ops_may_admin1712=== CONT TestService_RequireScope_OIDC/ops_may_not_write1713=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1714=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1715--- PASS: TestService_RequireScope_OIDC (0.36s)1716 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1717 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1718 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1719 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1720 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1721 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1722 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1723 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1724 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1725 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1726 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1727 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1728 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1729 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1730=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17312026/10/06 21:12:42 INFO Upload complete. (74ms)17322026/10/06 21:12:42 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]1733=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured17342026/10/06 21:12:42 INFO Upload complete. (73ms)1735=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1736=== NAME TestClientPushesUseOnePush1737 client_pushes_test.go:97: Retrieved narinfo from S3:1738 StorePath: /build/TestClientPushesUseOnePush1108467578/001/store/rhcd9gr7l2g2m4zz0s6nvf641whhc9gz-shared-dep1739 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1740 Compression: zstd1741 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821742 NarSize: 1361743 References: 1744 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1745 client_pushes_test.go:97: Retrieved narinfo from S3:17462026/10/06 21:12:42 WARN Authentication failed token_preview=eyJhbGciOi...KVa_ZpfJKg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1747 StorePath: /build/TestClientPushesUseOnePush1108467578/001/store/h5jhbapp0374z8h6bf4mb1dbndfppi8m-a1748 URL: nar/0iajwx0c3nyfqb9pqmiaa25jwk3307xb44jw9g3m4b9la5xsvss5.nar.zst1749 Compression: zstd1750 NarHash: sha256:0iajwx0c3nyfqb9pqmiaa25jwk3307xb44jw9g3m4b9la5xsvss51751 NarSize: 2161752 References: /build/TestClientPushesUseOnePush1108467578/001/store/rhcd9gr7l2g2m4zz0s6nvf641whhc9gz-shared-dep1753 CA: text:sha256:10jfz7sq407c6vaxchlwxizdlq31k7hddb478hxmrprxp80dvcw31754=== NAME TestClientMultipleUploads1755 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3449093081/001/store/fclyd92b5l061ga288vns481f6wfxsci-test-file-2.txt1756--- PASS: TestService_AuthMiddleware_OIDC (0.39s)1757 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1758 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1759 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1760 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)17612026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes1762=== NAME TestClientCADerivations1763 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1764 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable17652026/10/06 21:12:42 INFO Received uploads request method=POST path=/api/pending_closures1766 error: binary cache 's3://bucket69?endpoint=http://localhost:34041®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4241900900/001/store'1767 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11768=== NAME TestClientPushesUseOnePush1769 client_pushes_test.go:97: Retrieved narinfo from S3:1770 StorePath: /build/TestClientPushesUseOnePush1108467578/001/store/g589hw86s6ym5q8dylc9ghsihdwzdiv7-b1771 URL: nar/0iajwx0c3nyfqb9pqmiaa25jwk3307xb44jw9g3m4b9la5xsvss5.nar.zst1772 Compression: zstd1773 NarHash: sha256:0iajwx0c3nyfqb9pqmiaa25jwk3307xb44jw9g3m4b9la5xsvss51774 NarSize: 2161775 References: /build/TestClientPushesUseOnePush1108467578/001/store/rhcd9gr7l2g2m4zz0s6nvf641whhc9gz-shared-dep1776 CA: text:sha256:10jfz7sq407c6vaxchlwxizdlq31k7hddb478hxmrprxp80dvcw31777--- PASS: TestClientCADerivations (0.94s)17782026/10/06 21:12:42 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17792026/10/06 21:12:42 INFO Uploading 1pfhcr9cbxkqxdbp8xjzp9j17hi3zqif-shared-dep (136B)17802026/10/06 21:12:42 INFO Uploading 9ffihdnvjsri29862hf25mpf4d0vc0gw-top (224B)1781--- PASS: TestClientPushesUseOnePush (0.69s)17822026/10/06 21:12:42 WARN Failed to register uploaded object key=1pfhcr9cbxkqxdbp8xjzp9j17hi3zqif.ls error="server returned 404: 404 page not found\n"17832026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/1icynqwvsgg80mm2l9va4h2kw7sykczg0yhqk9ya10vak2f56c68.nar.zst error="server returned 404: 404 page not found\n"17842026/10/06 21:12:42 WARN Failed to register uploaded object key=9ffihdnvjsri29862hf25mpf4d0vc0gw.ls error="server returned 404: 404 page not found\n"17852026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17862026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17872026/10/06 21:12:42 INFO Signed narinfos id=1 count=217882026/10/06 21:12:42 INFO Uploading 2 narinfos17892026/10/06 21:12:42 WARN Failed to register uploaded object key=1pfhcr9cbxkqxdbp8xjzp9j17hi3zqif.narinfo error="server returned 404: 404 page not found\n"17902026/10/06 21:12:42 INFO Received complete push request method=POST path=/api/pushes/1/complete17912026/10/06 21:12:42 WARN Failed to register uploaded object key=9ffihdnvjsri29862hf25mpf4d0vc0gw.narinfo error="server returned 404: 404 page not found\n"17922026/10/06 21:12:42 INFO Upload complete. (211ms)1793=== NAME TestClientSharedPathCommittedMidPush1794 client_integration_test.go:680: Retrieved narinfo from S3:1795 StorePath: /build/TestClientSharedPathCommittedMidPush1918424109/001/store/1pfhcr9cbxkqxdbp8xjzp9j17hi3zqif-shared-dep1796 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1797 Compression: zstd1798 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821799 NarSize: 1361800 References: 1801 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1802 client_integration_test.go:680: Retrieved narinfo from S3:1803 StorePath: /build/TestClientSharedPathCommittedMidPush1918424109/001/store/9ffihdnvjsri29862hf25mpf4d0vc0gw-top1804 URL: nar/1icynqwvsgg80mm2l9va4h2kw7sykczg0yhqk9ya10vak2f56c68.nar.zst1805 Compression: zstd1806 NarHash: sha256:1icynqwvsgg80mm2l9va4h2kw7sykczg0yhqk9ya10vak2f56c681807 NarSize: 2241808 References: /build/TestClientSharedPathCommittedMidPush1918424109/001/store/1pfhcr9cbxkqxdbp8xjzp9j17hi3zqif-shared-dep1809 CA: text:sha256:0656iljjwfrljac3vha6s9bknfaikqhhyw13v9bc74fhhlgzrq9v1810--- PASS: TestClientSharedPathCommittedMidPush (0.69s)18112026/10/06 21:12:42 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18122026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes18132026/10/06 21:12:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18142026/10/06 21:12:42 INFO Uploading wjjin0n8x50k9l41f7aw0qz49yqghnpm-unpinned-file.txt (128B)18152026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes18162026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18172026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18182026/10/06 21:12:42 WARN Failed to register uploaded object key=wjjin0n8x50k9l41f7aw0qz49yqghnpm.ls error="server returned 404: 404 page not found\n"18192026/10/06 21:12:42 INFO Signed narinfos id=2 count=118202026/10/06 21:12:42 INFO Uploading 1 narinfos18212026/10/06 21:12:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18222026/10/06 21:12:42 INFO Uploading xl9n4xg1zrzx4p42jving74jlyc98k9v-test-file.txt (152B)18232026/10/06 21:12:42 INFO Received complete push request method=POST path=/api/pushes/2/complete18242026/10/06 21:12:42 WARN Failed to register uploaded object key=wjjin0n8x50k9l41f7aw0qz49yqghnpm.narinfo error="server returned 404: 404 page not found\n"18252026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18262026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18272026/10/06 21:12:42 WARN Failed to register uploaded object key=xl9n4xg1zrzx4p42jving74jlyc98k9v.ls error="server returned 404: 404 page not found\n"18282026/10/06 21:12:42 INFO Signed narinfos id=1 count=118292026/10/06 21:12:42 INFO Uploading 1 narinfos18302026/10/06 21:12:42 INFO Upload complete. (63ms)18312026/10/06 21:12:42 INFO Received complete push request method=POST path=/api/pushes/1/complete18322026/10/06 21:12:42 WARN Failed to register uploaded object key=xl9n4xg1zrzx4p42jving74jlyc98k9v.narinfo error="server returned 404: 404 page not found\n"18332026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=018342026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period18352026/10/06 21:12:42 INFO Upload complete. (211ms)18362026/10/06 21:12:42 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:34041/bucket87/?delete=\": context canceled"18372026/10/06 21:12:42 INFO Received uploads request method=POST path=/api/pending_closures18382026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=018392026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period18402026/10/06 21:12:42 INFO Received push request method=POST path=/api/pushes18412026/10/06 21:12:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures18422026/10/06 21:12:42 INFO Garbage collection started18432026/10/06 21:12:42 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18442026/10/06 21:12:42 INFO Uploading y0j77gyprkkvq8amz3zv3q0digdnx84v-test-file-0.txt (160B)18452026/10/06 21:12:42 INFO Uploading fclyd92b5l061ga288vns481f6wfxsci-test-file-2.txt (160B)18462026/10/06 21:12:42 INFO Uploading rfg1h206qcgznwrwpqbdmb59ghlmbkg0-test-file-1.txt (160B)18472026/10/06 21:12:42 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=018482026/10/06 21:12:42 INFO Vacuumed table table=pending_closures18492026/10/06 21:12:42 INFO Vacuumed table table=pending_objects18502026/10/06 21:12:42 INFO Vacuumed table table=multipart_uploads18512026/10/06 21:12:42 INFO Vacuumed table table=closures18522026/10/06 21:12:42 INFO All 1 paths already cached18532026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18542026/10/06 21:12:42 WARN Failed to register uploaded object key=fclyd92b5l061ga288vns481f6wfxsci.ls error="server returned 404: 404 page not found\n"18552026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18562026/10/06 21:12:42 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1857=== NAME TestClientIntegration1858 client_integration_test.go:312: Retrieved narinfo from S3:1859 StorePath: /build/TestClientIntegration3418259266/002/store/xl9n4xg1zrzx4p42jving74jlyc98k9v-test-file.txt18602026/10/06 21:12:42 INFO Vacuumed table table=objects1861 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1862 Compression: zstd18632026/10/06 21:12:42 WARN Failed to register uploaded object key=y0j77gyprkkvq8amz3zv3q0digdnx84v.ls error="server returned 404: 404 page not found\n"1864 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11865 NarSize: 1521866 References: 1867 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk118682026/10/06 21:12:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18692026/10/06 21:12:42 WARN Failed to register uploaded object key=rfg1h206qcgznwrwpqbdmb59ghlmbkg0.ls error="server returned 404: 404 page not found\n"18702026/10/06 21:12:42 INFO Signed narinfos id=1 count=318712026/10/06 21:12:42 INFO Uploading 3 narinfos1872 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1873 client_integration_test.go:313: Decompressed .ls content (64 bytes):1874 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1875 client_integration_test.go:316: Testing garbage collection...18762026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=018772026/10/06 21:12:42 WARN Failed to register uploaded object key=fclyd92b5l061ga288vns481f6wfxsci.narinfo error="server returned 404: 404 page not found\n"18782026/10/06 21:12:42 WARN Failed to register uploaded object key=y0j77gyprkkvq8amz3zv3q0digdnx84v.narinfo error="server returned 404: 404 page not found\n"18792026/10/06 21:12:42 INFO Received complete push request method=POST path=/api/pushes/1/complete18802026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period18812026/10/06 21:12:42 WARN Failed to register uploaded object key=rfg1h206qcgznwrwpqbdmb59ghlmbkg0.narinfo error="server returned 404: 404 page not found\n"18822026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=018832026/10/06 21:12:42 INFO Upload complete. (83ms)1884=== NAME TestClientMultipleUploads1885 client_integration_test.go:369: Uploaded 3 paths in 128.780962ms18862026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period18872026/10/06 21:12:42 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=01888--- PASS: TestClientMultipleUploads (0.72s)18892026/10/06 21:12:42 INFO Vacuumed table table=pending_closures18902026/10/06 21:12:42 INFO Vacuumed table table=pending_objects18912026/10/06 21:12:42 INFO Vacuumed table table=multipart_uploads18922026/10/06 21:12:42 INFO Vacuumed table table=closures1893--- PASS: TestGCEndsOnShutdown (0.00s)1894 --- PASS: TestGCEndsOnShutdown/before_the_run (0.36s)1895 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.39s)1896 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.41s)18972026/10/06 21:12:42 INFO Vacuumed table table=objects18982026/10/06 21:12:42 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.930554ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18992026/10/06 21:12:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures19002026/10/06 21:12:42 INFO Garbage collection started19012026/10/06 21:12:42 INFO Aborted multipart uploads count=0 kept=019022026/10/06 21:12:42 WARN Force mode enabled - objects will be deleted immediately without grace period19032026/10/06 21:12:42 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=019042026/10/06 21:12:42 INFO Vacuumed table table=pending_closures19052026/10/06 21:12:42 INFO Vacuumed table table=pending_objects19062026/10/06 21:12:42 INFO Vacuumed table table=multipart_uploads19072026/10/06 21:12:42 INFO Vacuumed table table=closures19082026/10/06 21:12:42 INFO Vacuumed table table=objects19092026/10/06 21:12:43 INFO Received uploads request method=POST path=/api/pending_closures19102026/10/06 21:12:43 INFO Aborted multipart uploads count=0 kept=019112026/10/06 21:12:43 WARN Force mode enabled - objects will be deleted immediately without grace period19122026/10/06 21:12:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019132026/10/06 21:12:43 INFO Vacuumed table table=pending_closures19142026/10/06 21:12:43 INFO Vacuumed table table=pending_objects19152026/10/06 21:12:43 INFO Vacuumed table table=multipart_uploads19162026/10/06 21:12:43 INFO Vacuumed table table=closures19172026/10/06 21:12:43 INFO Vacuumed table table=objects1918--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1919 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.40s)1920 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.42s)19212026/10/06 21:12:43 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19222026/10/06 21:12:43 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1923=== NAME TestOrphanedObjectsGCStressTest1924 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1925 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19262026/10/06 21:12:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.720241ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1927--- PASS: TestUploadHandlersRejectOversizedBody (0.23s)1928 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1929 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.08s)1930 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.76s)19312026/10/06 21:12:43 INFO lead: released remote=192.0.2.1:12341932--- PASS: TestLeadEndsOnShutdown (1.49s)19332026/10/06 21:12:43 INFO lead: released remote=192.0.2.1:12341934=== NAME TestOrphanedObjectsGCStressTest1935 orphaned_objects_gc_test.go:509: Stress test completed successfully:1936 orphaned_objects_gc_test.go:510: - Active objects preserved: 201937 orphaned_objects_gc_test.go:511: - Objects deleted: 2101938 orphaned_objects_gc_test.go:512: - Total GC'd: 2101939--- PASS: TestOrphanedObjectsGCStressTest (2.32s)19402026/10/06 21:12:43 INFO lead: acquired remote=192.0.2.1:123419412026/10/06 21:12:43 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=786.100401ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1942--- PASS: TestPendingClosureWriteTimeout (0.13s)1943 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1944 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1945 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1946 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.22s)19472026/10/06 21:12:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.549318301s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19482026/10/06 21:12:44 INFO lead: released remote=192.0.2.1:12341949--- PASS: TestLeadElectsOneAndHandsOver (2.77s)19502026/10/06 21:12:44 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019512026/10/06 21:12:44 INFO Received create pin request method=POST path=/api/pins/myapp19522026/10/06 21:12:44 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC425655533/001/store/h3qpn8w9h6cjb9ybngsf88gfi79zxhhk-pinned-file.txt narinfo_key=h3qpn8w9h6cjb9ybngsf88gfi79zxhhk.narinfo19532026/10/06 21:12:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures19542026/10/06 21:12:44 INFO Garbage collection started19552026/10/06 21:12:44 INFO Aborted multipart uploads count=0 kept=019562026/10/06 21:12:44 WARN Force mode enabled - objects will be deleted immediately without grace period19572026/10/06 21:12:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019582026/10/06 21:12:44 INFO Vacuumed table table=pending_closures19592026/10/06 21:12:44 INFO Vacuumed table table=pending_objects19602026/10/06 21:12:44 INFO Vacuumed table table=multipart_uploads19612026/10/06 21:12:44 INFO Vacuumed table table=closures19622026/10/06 21:12:44 INFO Vacuumed table table=objects19632026/10/06 21:12:44 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01964=== NAME TestClientIntegration1965 client_integration_test.go:323: Objects in database after GC:1966 client_integration_test.go:323: Successfully deleted all objects with GC --force1967--- PASS: TestClientIntegration (2.73s)19682026/10/06 21:12:45 WARN Rate limiter enabled after throttle name=s3-test rate=519692026/10/06 21:12:45 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1970=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1971 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101972 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001973--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.31s)1974--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.86s)19752026/10/06 21:12:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19762026/10/06 21:12:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.900389ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19772026/10/06 21:12:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=432.841195ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19782026/10/06 21:12:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=743.195248ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1979=== NAME TestPinProtectsFromGC1980 client_integration_test.go:840: Pin successfully protected closure from garbage collection1981--- PASS: TestPinProtectsFromGC (4.79s)1982--- PASS: TestConnectWaitsForAPeerMigration (5.18s)19832026/10/06 21:12:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.678380217s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19842026/10/06 21:12:47 INFO Aborted multipart uploads count=1 kept=019852026/10/06 21:12:47 INFO Received cleanup request method=DELETE path=/api/pending_closures19862026/10/06 21:12:47 INFO Aborted multipart uploads count=1 kept=01987--- PASS: TestPendingCleanupUsesOneCutoff (6.45s)19882026/10/06 21:12:49 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"19892026/10/06 21:12:49 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19902026/10/06 21:12:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.65978ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19912026/10/06 21:12:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=392.455862ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19922026/10/06 21:12:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=762.822521ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19932026/10/06 21:12:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.584138831s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19942026/10/06 21:12:52 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19952026/10/06 21:12:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.706288ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19962026/10/06 21:12:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=432.310556ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19972026/10/06 21:12:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=824.501285ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19982026/10/06 21:12:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.695762684s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1999--- PASS: TestClientErrorHandling (0.00s)2000 --- PASS: TestClientErrorHandling/InvalidStorePath (0.40s)2001 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.43s)2002 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.69s)2003PASS20042026-10-06 21:12:55.894 UTC [128] LOG: received smart shutdown request20052026-10-06 21:12:55.900 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 120062026-10-06 21:12:55.916 UTC [133] LOG: shutting down20072026-10-06 21:12:55.917 UTC [133] LOG: checkpoint starting: shutdown immediate20082026-10-06 21:12:57.683 UTC [133] LOG: checkpoint complete: wrote 10736 buffers (65.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.429 s, sync=1.281 s, total=1.767 s; sync files=31336, longest=0.014 s, average=0.001 s; distance=433081 kB, estimate=433081 kB; lsn=0/1BE541C0, redo lsn=0/1BE541C020092026-10-06 21:12:57.757 UTC [128] LOG: database system is shut down2010Running OIDC tests...2011=== RUN TestAudienceForIssuer2012=== PAUSE TestAudienceForIssuer2013=== RUN TestGlobMatch2014=== PAUSE TestGlobMatch2015=== RUN TestValidateToken_ValidToken2016=== PAUSE TestValidateToken_ValidToken2017=== RUN TestValidateToken_WrongAudience2018=== PAUSE TestValidateToken_WrongAudience2019=== RUN TestValidateToken_Expired2020=== PAUSE TestValidateToken_Expired2021=== RUN TestValidateToken_BoundClaimsMismatch2022=== PAUSE TestValidateToken_BoundClaimsMismatch2023=== RUN TestValidateToken_BoundSubjectMismatch2024=== PAUSE TestValidateToken_BoundSubjectMismatch2025=== RUN TestValidateToken_MultipleProviders2026=== PAUSE TestValidateToken_MultipleProviders2027=== RUN TestValidateToken_NoMatchingProvider2028=== PAUSE TestValidateToken_NoMatchingProvider2029=== RUN TestValidateToken_KubernetesServiceAccount2030=== PAUSE TestValidateToken_KubernetesServiceAccount2031=== RUN TestNewValidator_KubernetesRequiresCA2032=== PAUSE TestNewValidator_KubernetesRequiresCA2033=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2034=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2035=== RUN TestPins_ReservedForMatchingRule2036=== PAUSE TestPins_ReservedForMatchingRule2037=== RUN TestPins_TopLevelShorthand2038=== PAUSE TestPins_TopLevelShorthand2039=== RUN TestPins_ConfigValidation2040=== PAUSE TestPins_ConfigValidation2041=== RUN TestScopes_LegacyProviderDefaultsToWrite2042=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2043=== RUN TestScopes_Rules2044=== PAUSE TestScopes_Rules2045=== RUN TestScopes_ConfigValidation2046=== PAUSE TestScopes_ConfigValidation2047=== CONT TestAudienceForIssuer2048=== CONT TestPins_TopLevelShorthand2049=== CONT TestScopes_Rules2050=== CONT TestPins_ConfigValidation2051=== CONT TestScopes_LegacyProviderDefaultsToWrite2052=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2053=== CONT TestPins_ReservedForMatchingRule2054=== CONT TestValidateToken_BoundClaimsMismatch2055=== CONT TestValidateToken_NoMatchingProvider2056=== CONT TestValidateToken_MultipleProviders2057--- PASS: TestAudienceForIssuer (0.00s)2058=== CONT TestValidateToken_BoundSubjectMismatch2059=== CONT TestValidateToken_KubernetesServiceAccount2060=== CONT TestValidateToken_Expired2061=== CONT TestValidateToken_WrongAudience2062=== CONT TestValidateToken_ValidToken2063=== CONT TestNewValidator_KubernetesRequiresCA2064=== CONT TestGlobMatch2065=== CONT TestScopes_ConfigValidation2066--- PASS: TestPins_ConfigValidation (0.00s)2067--- PASS: TestScopes_ConfigValidation (0.00s)2068=== RUN TestGlobMatch/foo_foo2069=== PAUSE TestGlobMatch/foo_foo2070=== RUN TestGlobMatch/foo_bar2071=== PAUSE TestGlobMatch/foo_bar2072=== RUN TestGlobMatch/*_2073=== PAUSE TestGlobMatch/*_2074=== RUN TestGlobMatch/*_anything2075=== PAUSE TestGlobMatch/*_anything2076=== RUN TestGlobMatch/foo*_foo2077=== PAUSE TestGlobMatch/foo*_foo2078=== RUN TestGlobMatch/foo*_foobar2079=== PAUSE TestGlobMatch/foo*_foobar2080=== RUN TestGlobMatch/foo*_bar2081=== PAUSE TestGlobMatch/foo*_bar2082=== RUN TestGlobMatch/*bar_bar2083=== PAUSE TestGlobMatch/*bar_bar2084=== RUN TestGlobMatch/*bar_foobar2085=== PAUSE TestGlobMatch/*bar_foobar2086=== RUN TestGlobMatch/*bar_foo2087=== PAUSE TestGlobMatch/*bar_foo2088=== RUN TestGlobMatch/foo*bar_foobar2089=== PAUSE TestGlobMatch/foo*bar_foobar2090=== RUN TestGlobMatch/foo*bar_foo123bar2091=== PAUSE TestGlobMatch/foo*bar_foo123bar2092=== RUN TestGlobMatch/foo*bar_foobarbaz2093=== PAUSE TestGlobMatch/foo*bar_foobarbaz2094=== RUN TestGlobMatch/*/*_foo/bar2095=== PAUSE TestGlobMatch/*/*_foo/bar2096=== RUN TestGlobMatch/*/*_foo2097=== PAUSE TestGlobMatch/*/*_foo2098=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2099=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2100=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02101=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02102=== RUN TestGlobMatch/refs/*/main_refs/heads/main2103=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2104=== RUN TestGlobMatch/fo?_foo2105=== PAUSE TestGlobMatch/fo?_foo2106=== RUN TestGlobMatch/fo?_fo2107=== PAUSE TestGlobMatch/fo?_fo2108=== RUN TestGlobMatch/fo?_fooo2109=== PAUSE TestGlobMatch/fo?_fooo2110=== RUN TestGlobMatch/?oo_foo2111=== PAUSE TestGlobMatch/?oo_foo2112=== RUN TestGlobMatch/?oo_boo2113=== PAUSE TestGlobMatch/?oo_boo2114=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2115=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2116=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2117=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2118=== CONT TestGlobMatch/foo_foo2119=== CONT TestGlobMatch/*/*_foo2120=== CONT TestGlobMatch/*/*_foo/bar2121=== CONT TestGlobMatch/foo*bar_foobarbaz2122=== CONT TestGlobMatch/foo*bar_foo123bar2123=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2124=== CONT TestGlobMatch/foo*_bar2125=== CONT TestGlobMatch/foo*bar_foobar2126=== CONT TestGlobMatch/*bar_foo2127=== CONT TestGlobMatch/*bar_foobar2128=== CONT TestGlobMatch/*bar_bar2129=== CONT TestGlobMatch/*_anything2130=== CONT TestGlobMatch/foo*_foobar2131=== CONT TestGlobMatch/foo*_foo2132=== CONT TestGlobMatch/*_2133=== CONT TestGlobMatch/foo_bar2134=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2135=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2136=== CONT TestGlobMatch/?oo_boo2137=== CONT TestGlobMatch/?oo_foo2138=== CONT TestGlobMatch/fo?_fooo2139=== CONT TestGlobMatch/fo?_fo2140=== CONT TestGlobMatch/fo?_foo2141=== CONT TestGlobMatch/refs/*/main_refs/heads/main2142=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02143--- PASS: TestGlobMatch (0.00s)2144 --- PASS: TestGlobMatch/foo_foo (0.00s)2145 --- PASS: TestGlobMatch/*/*_foo (0.00s)2146 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2147 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2148 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2149 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2150 --- PASS: TestGlobMatch/foo*_bar (0.00s)2151 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2152 --- PASS: TestGlobMatch/*bar_foo (0.00s)2153 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2154 --- PASS: TestGlobMatch/*bar_bar (0.00s)2155 --- PASS: TestGlobMatch/*_anything (0.00s)2156 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2157 --- PASS: TestGlobMatch/foo*_foo (0.00s)2158 --- PASS: TestGlobMatch/*_ (0.00s)2159 --- PASS: TestGlobMatch/foo_bar (0.00s)2160 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2161 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2162 --- PASS: TestGlobMatch/?oo_boo (0.00s)2163 --- PASS: TestGlobMatch/?oo_foo (0.00s)2164 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2165 --- PASS: TestGlobMatch/fo?_fo (0.00s)2166 --- PASS: TestGlobMatch/fo?_foo (0.00s)2167 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2168 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)21692026/10/06 21:13:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39605/oidc21702026/10/06 21:13:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38769/oidc2171--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)2172--- PASS: TestValidateToken_Expired (0.05s)21732026/10/06 21:13:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42875/oidc2174--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)21752026/10/06 21:13:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41531/oidc21762026/10/06 21:13:00 http: TLS handshake error from 127.0.0.1:50208: remote error: tls: bad certificate2177--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)2178--- PASS: TestScopes_Rules (0.08s)21792026/10/06 21:13:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40075/oidc21802026/10/06 21:13:00 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:41665/oidc21812026/10/06 21:13:00 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12321822026/10/06 21:13:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46163/oidc2183--- PASS: TestValidateToken_MultipleProviders (0.08s)21842026/10/06 21:13:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35861/oidc2185--- PASS: TestPins_ReservedForMatchingRule (0.10s)2186--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)2187--- PASS: TestValidateToken_ValidToken (0.09s)21882026/10/06 21:13:00 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:427412189--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)21902026/10/06 21:13:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44943/oidc21912026/10/06 21:13:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32867/oidc2192--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)2193--- PASS: TestValidateToken_WrongAudience (0.11s)21942026/10/06 21:13:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37999/oidc2195--- PASS: TestPins_TopLevelShorthand (0.12s)21962026/10/06 21:13:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37217/oidc2197--- PASS: TestValidateToken_NoMatchingProvider (0.14s)2198PASS2199Running hook tests...2200=== RUN TestSendPathsEmpty2201=== PAUSE TestSendPathsEmpty2202=== RUN TestQueueEnqueueAndFetch2203=== PAUSE TestQueueEnqueueAndFetch2204=== RUN TestQueueDeduplication2205=== PAUSE TestQueueDeduplication2206=== RUN TestQueueRemove2207=== PAUSE TestQueueRemove2208=== RUN TestQueueFetchBatchLimit2209=== PAUSE TestQueueFetchBatchLimit2210=== RUN TestQueueRetryMovesToBack2211=== PAUSE TestQueueRetryMovesToBack2212=== RUN TestQueueFetchRemoveLifecycle2213=== PAUSE TestQueueFetchRemoveLifecycle2214=== RUN TestQueueConcurrentWriters2215=== PAUSE TestQueueConcurrentWriters2216=== RUN TestQueueRemoveLargeClosure2217=== PAUSE TestQueueRemoveLargeClosure2218=== RUN TestServerClientIntegration2219=== PAUSE TestServerClientIntegration2220=== RUN TestServerQueueError2221=== PAUSE TestServerQueueError2222=== RUN TestGetListenerSocketActivation2223 server_test.go:210: === RUN TestGetListenerSocketActivation2224 --- PASS: TestGetListenerSocketActivation (0.00s)2225 PASS2226 2227--- PASS: TestGetListenerSocketActivation (0.01s)2228=== RUN TestDrainIsolatesPoisonPath2229=== PAUSE TestDrainIsolatesPoisonPath2230=== RUN TestRunNotBlockedByPoisonHead2231=== PAUSE TestRunNotBlockedByPoisonHead2232=== RUN TestDrainGivesUpWhenServerDown2233=== PAUSE TestDrainGivesUpWhenServerDown2234=== RUN TestFailedPathPrunedByLaterClosure2235=== PAUSE TestFailedPathPrunedByLaterClosure2236=== RUN TestWorkerUploadsAndRemoves2237=== PAUSE TestWorkerUploadsAndRemoves2238=== RUN TestWorkerSkipsGCdPaths2239=== PAUSE TestWorkerSkipsGCdPaths2240=== RUN TestWorkerPrunesClosureDeps2241=== PAUSE TestWorkerPrunesClosureDeps2242=== RUN TestDrainTimeout2243=== PAUSE TestDrainTimeout2244=== CONT TestSendPathsEmpty2245=== CONT TestServerQueueError2246=== CONT TestWorkerUploadsAndRemoves2247=== CONT TestDrainTimeout2248=== CONT TestWorkerPrunesClosureDeps2249--- PASS: TestSendPathsEmpty (0.00s)2250=== CONT TestServerClientIntegration2251=== CONT TestQueueRemoveLargeClosure2252=== CONT TestQueueConcurrentWriters22532026/10/06 21:13:00 ERROR Failed to queue paths error="permission denied" count=12254=== CONT TestQueueFetchRemoveLifecycle2255=== CONT TestWorkerSkipsGCdPaths2256=== CONT TestQueueRetryMovesToBack2257--- PASS: TestServerClientIntegration (0.00s)2258--- PASS: TestServerQueueError (0.00s)2259=== CONT TestQueueDeduplication2260=== CONT TestQueueRemove2261=== CONT TestQueueEnqueueAndFetch2262=== CONT TestQueueFetchBatchLimit2263=== CONT TestDrainGivesUpWhenServerDown2264=== CONT TestFailedPathPrunedByLaterClosure2265=== CONT TestRunNotBlockedByPoisonHead2266=== CONT TestDrainIsolatesPoisonPath22672026/10/06 21:13:00 INFO Upload queue status pending=222682026/10/06 21:13:00 INFO Uploading batch count=222692026/10/06 21:13:00 INFO Uploading batch count=422702026/10/06 21:13:00 INFO Upload queue status pending=222712026/10/06 21:13:00 ERROR Upload failed error="upload failed" count=422722026/10/06 21:13:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2706668039/002/nonexistent22732026/10/06 21:13:00 INFO Uploading batch count=222742026/10/06 21:13:00 INFO Uploading batch count=222752026/10/06 21:13:00 ERROR Upload failed error="upload failed" count=222762026/10/06 21:13:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1548672107/002/a22772026/10/06 21:13:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1096256031/002/bbb2278--- PASS: TestQueueFetchBatchLimit (0.02s)22792026/10/06 21:13:00 INFO Upload queue status pending=322802026/10/06 21:13:00 INFO Uploading batch count=12281--- PASS: TestQueueRetryMovesToBack (0.02s)22822026/10/06 21:13:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1548672107/002/b22832026/10/06 21:13:00 INFO Uploading batch count=12284--- PASS: TestQueueDeduplication (0.02s)22852026/10/06 21:13:00 ERROR Upload failed error="upload failed" count=122862026/10/06 21:13:00 INFO Uploading batch count=122872026/10/06 21:13:00 ERROR Upload failed error="upload failed" count=12288--- PASS: TestQueueEnqueueAndFetch (0.02s)2289--- PASS: TestQueueFetchRemoveLifecycle (0.02s)22902026/10/06 21:13:00 INFO Upload queue status pending=222912026/10/06 21:13:00 INFO Uploading batch count=12292--- PASS: TestQueueRemove (0.02s)22932026/10/06 21:13:00 INFO Uploading batch count=222942026/10/06 21:13:00 ERROR Upload failed error="upload failed" count=222952026/10/06 21:13:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1548672107/002/c22962026/10/06 21:13:00 INFO Uploading batch count=122972026/10/06 21:13:00 ERROR Upload failed error="upload failed" count=122982026/10/06 21:13:00 INFO Uploading batch count=122992026/10/06 21:13:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1548672107/002/d23002026/10/06 21:13:00 INFO Uploading batch count=123012026/10/06 21:13:00 ERROR Upload failed error="upload failed" count=123022026/10/06 21:13:00 INFO Uploading batch count=123032026/10/06 21:13:00 INFO Uploading batch count=223042026/10/06 21:13:00 ERROR Upload failed error="upload failed" count=223052026/10/06 21:13:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1548672107/002/e23062026/10/06 21:13:00 INFO Uploading batch count=123072026/10/06 21:13:00 ERROR Upload failed error="upload failed" count=123082026/10/06 21:13:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1548672107/002/f23092026/10/06 21:13:00 ERROR Drain finished with paths left in queue remaining=123102026/10/06 21:13:00 ERROR Drain finished with paths left in queue remaining=102311--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2312--- PASS: TestDrainIsolatesPoisonPath (0.02s)2313--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2314--- PASS: TestWorkerUploadsAndRemoves (0.04s)2315--- PASS: TestWorkerPrunesClosureDeps (0.04s)2316--- PASS: TestWorkerSkipsGCdPaths (0.04s)2317--- PASS: TestQueueRemoveLargeClosure (0.06s)23182026/10/06 21:13:00 ERROR Upload failed error="context deadline exceeded" count=223192026/10/06 21:13:00 ERROR Drain finished with paths left in queue remaining=42320--- PASS: TestDrainTimeout (0.22s)2321--- PASS: TestQueueConcurrentWriters (0.48s)23222026/10/06 21:13:01 INFO Uploading batch count=123232026/10/06 21:13:01 INFO Uploading batch count=123242026/10/06 21:13:01 INFO Uploading batch count=123252026/10/06 21:13:01 ERROR Upload failed error="upload failed" count=123262026/10/06 21:13:01 INFO Uploading batch count=123272026/10/06 21:13:01 ERROR Upload failed error="upload failed" count=123282026/10/06 21:13:01 INFO Uploading batch count=123292026/10/06 21:13:01 ERROR Upload failed error="upload failed" count=123302026/10/06 21:13:01 INFO Uploading batch count=123312026/10/06 21:13:01 ERROR Upload failed error="upload failed" count=123322026/10/06 21:13:01 ERROR Drain finished with paths left in queue remaining=12333--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2334PASS2335Running signing tests...2336=== RUN TestExternalSigner2337=== PAUSE TestExternalSigner2338=== RUN TestExternalSignerWrongPublicKey2339=== PAUSE TestExternalSignerWrongPublicKey2340=== RUN TestExternalSignerErrors2341=== PAUSE TestExternalSignerErrors2342=== RUN TestExternalSignerRestartsAfterCrash2343=== PAUSE TestExternalSignerRestartsAfterCrash2344=== RUN TestExternalSignerProgramErrorKeepsProcess2345=== PAUSE TestExternalSignerProgramErrorKeepsProcess2346=== RUN TestExternalSignerClose2347=== PAUSE TestExternalSignerClose2348=== RUN TestExternalSignerRejectsInvalidPublicKey2349=== PAUSE TestExternalSignerRejectsInvalidPublicKey2350=== RUN TestExternalSignerCancellation2351=== PAUSE TestExternalSignerCancellation2352=== RUN TestGenerateFingerprint2353=== PAUSE TestGenerateFingerprint2354=== RUN TestParseSigningKey2355=== PAUSE TestParseSigningKey2356=== RUN TestSign2357=== PAUSE TestSign2358=== RUN TestSignBatch2359=== PAUSE TestSignBatch2360=== RUN TestNilKeyPublicKey2361=== PAUSE TestNilKeyPublicKey2362=== RUN TestSignErrors2363=== PAUSE TestSignErrors2364=== CONT TestExternalSigner2365=== CONT TestNilKeyPublicKey2366=== CONT TestExternalSignerCancellation2367=== CONT TestSign2368=== CONT TestParseSigningKey2369=== CONT TestGenerateFingerprint2370=== RUN TestGenerateFingerprint/basic_with_references2371=== PAUSE TestGenerateFingerprint/basic_with_references2372=== RUN TestParseSigningKey/valid_32-byte_key2373=== PAUSE TestParseSigningKey/valid_32-byte_key2374=== CONT TestExternalSignerProgramErrorKeepsProcess2375=== CONT TestExternalSignerRejectsInvalidPublicKey2376=== CONT TestExternalSignerClose2377=== RUN TestExternalSignerRejectsInvalidPublicKey/#002378=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002379=== CONT TestExternalSignerErrors2380=== CONT TestExternalSignerRestartsAfterCrash2381=== CONT TestExternalSignerWrongPublicKey2382=== CONT TestSignBatch2383=== CONT TestSignErrors2384--- PASS: TestNilKeyPublicKey (0.00s)2385=== RUN TestGenerateFingerprint/no_references2386=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2387=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2388--- PASS: TestSign (0.00s)2389=== RUN TestParseSigningKey/no_colon2390=== PAUSE TestParseSigningKey/no_colon2391=== RUN TestExternalSignerErrors/wrong_id2392=== RUN TestSignErrors/nil_key2393=== PAUSE TestSignErrors/nil_key2394=== RUN TestSignErrors/nil_narinfo2395=== PAUSE TestSignErrors/nil_narinfo2396=== RUN TestSignErrors/invalid_narinfo2397=== PAUSE TestSignErrors/invalid_narinfo2398=== RUN TestSignErrors/canceled2399=== PAUSE TestSignErrors/canceled2400=== CONT TestSignErrors/nil_key2401=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2402=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2403=== CONT TestSignErrors/canceled2404=== PAUSE TestGenerateFingerprint/no_references2405=== RUN TestParseSigningKey/empty_name2406=== PAUSE TestParseSigningKey/empty_name2407=== RUN TestParseSigningKey/invalid_base642408=== PAUSE TestExternalSignerErrors/wrong_id2409=== RUN TestExternalSignerErrors/too_few_signatures2410=== PAUSE TestExternalSignerErrors/too_few_signatures2411=== RUN TestExternalSignerErrors/unrequested_key2412=== PAUSE TestExternalSignerErrors/unrequested_key2413=== RUN TestExternalSignerErrors/wrong_signature_name2414=== PAUSE TestExternalSignerErrors/wrong_signature_name2415=== RUN TestExternalSignerErrors/wrong_signature_length2416=== PAUSE TestExternalSignerErrors/wrong_signature_length2417=== RUN TestExternalSignerErrors/null_signatures2418=== PAUSE TestExternalSignerErrors/null_signatures2419=== CONT TestSignErrors/invalid_narinfo2420=== CONT TestSignErrors/nil_narinfo2421=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2422=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2423=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2424=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2425=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2426=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2427=== CONT TestExternalSignerRejectsInvalidPublicKey/#002428=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2429=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2430=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2431=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2432=== RUN TestGenerateFingerprint/invalid_nar_hash_length2433=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2434=== RUN TestGenerateFingerprint/invalid_store_path_prefix2435=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2436=== RUN TestGenerateFingerprint/invalid_reference_prefix2437=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2438=== CONT TestGenerateFingerprint/basic_with_references2439=== CONT TestGenerateFingerprint/invalid_nar_hash_length2440=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2441=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2442=== PAUSE TestParseSigningKey/invalid_base642443--- PASS: TestSignBatch (0.00s)2444=== RUN TestExternalSignerErrors/missing_signature_name2445=== PAUSE TestExternalSignerErrors/missing_signature_name2446--- PASS: TestSignErrors (0.00s)2447 --- PASS: TestSignErrors/nil_key (0.00s)2448 --- PASS: TestSignErrors/canceled (0.00s)2449 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2450 --- PASS: TestSignErrors/nil_narinfo (0.00s)2451--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2452=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2453=== RUN TestExternalSignerErrors/exit_on_request2454=== PAUSE TestExternalSignerErrors/exit_on_request2455=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2456=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2457--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2458 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2459 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2460 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2461 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2462 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2463=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2464=== CONT TestGenerateFingerprint/no_references2465=== CONT TestGenerateFingerprint/invalid_store_path_prefix2466=== CONT TestGenerateFingerprint/invalid_reference_prefix2467--- PASS: TestGenerateFingerprint (0.00s)2468 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2469 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2470 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2471 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2472 --- PASS: TestGenerateFingerprint/no_references (0.00s)2473 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2474 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2475=== RUN TestParseSigningKey/wrong_length2476=== RUN TestExternalSignerErrors/missing_signatures2477=== PAUSE TestExternalSignerErrors/missing_signatures2478=== RUN TestExternalSignerErrors/wrong_signatures_shape2479=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2480=== PAUSE TestParseSigningKey/wrong_length2481=== CONT TestParseSigningKey/valid_32-byte_key2482=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2483=== CONT TestParseSigningKey/invalid_base642484=== RUN TestExternalSignerErrors/program_error2485=== PAUSE TestExternalSignerErrors/program_error2486=== CONT TestParseSigningKey/wrong_length2487=== CONT TestParseSigningKey/empty_name2488=== CONT TestParseSigningKey/no_colon2489--- PASS: TestExternalSignerClose (0.00s)2490=== RUN TestExternalSignerErrors/exit_at_startup2491=== PAUSE TestExternalSignerErrors/exit_at_startup2492=== RUN TestExternalSignerErrors/invalid_signature_base642493=== PAUSE TestExternalSignerErrors/invalid_signature_base642494=== RUN TestExternalSignerErrors/invalid_JSON2495=== PAUSE TestExternalSignerErrors/invalid_JSON2496=== RUN TestExternalSignerErrors/wrong_shape2497=== PAUSE TestExternalSignerErrors/wrong_shape2498=== RUN TestExternalSignerErrors/null2499=== PAUSE TestExternalSignerErrors/null2500--- PASS: TestExternalSignerWrongPublicKey (0.00s)2501--- PASS: TestParseSigningKey (0.01s)2502 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2503 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2504 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2505 --- PASS: TestParseSigningKey/wrong_length (0.00s)2506 --- PASS: TestParseSigningKey/empty_name (0.00s)2507 --- PASS: TestParseSigningKey/no_colon (0.00s)2508--- PASS: TestExternalSigner (0.01s)2509=== CONT TestExternalSignerErrors/wrong_id2510=== CONT TestExternalSignerErrors/null2511=== CONT TestExternalSignerErrors/wrong_shape2512=== CONT TestExternalSignerErrors/invalid_JSON2513=== CONT TestExternalSignerErrors/invalid_signature_base642514=== CONT TestExternalSignerErrors/exit_at_startup2515=== CONT TestExternalSignerErrors/program_error2516=== CONT TestExternalSignerErrors/null_signatures2517=== CONT TestExternalSignerErrors/wrong_signature_length2518=== CONT TestExternalSignerErrors/wrong_signatures_shape2519=== CONT TestExternalSignerErrors/missing_signatures2520=== CONT TestExternalSignerErrors/too_few_signatures2521=== CONT TestExternalSignerErrors/unrequested_key2522=== CONT TestExternalSignerErrors/exit_on_request2523=== CONT TestExternalSignerErrors/missing_signature_name2524=== CONT TestExternalSignerErrors/wrong_signature_name2525--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2526--- PASS: TestExternalSignerErrors (0.00s)2527 --- PASS: TestExternalSignerErrors/null (0.00s)2528 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2529 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2530 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2531 --- PASS: TestExternalSignerErrors/program_error (0.01s)2532 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2533 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2534 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2535 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2536 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2537 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2538 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2539 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2540 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2541 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2542 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2543--- PASS: TestExternalSignerCancellation (0.02s)2544PASS2545Running OpenBao signer tests...2546=== RUN TestSign2547=== PAUSE TestSign2548=== RUN TestSignErrors2549=== PAUSE TestSignErrors2550=== RUN TestServe2551=== PAUSE TestServe2552=== RUN TestServeRejectsGarbage2553=== PAUSE TestServeRejectsGarbage2554=== CONT TestSign2555=== CONT TestServe2556=== CONT TestSignErrors2557=== RUN TestSignErrors/no_prefix2558=== PAUSE TestSignErrors/no_prefix2559=== RUN TestSignErrors/invalid_base642560=== PAUSE TestSignErrors/invalid_base642561=== RUN TestSignErrors/http_error2562=== PAUSE TestSignErrors/http_error2563=== CONT TestServeRejectsGarbage2564=== RUN TestSignErrors/invalid_json2565=== PAUSE TestSignErrors/invalid_json2566--- PASS: TestServeRejectsGarbage (0.00s)2567--- PASS: TestServe (0.00s)2568=== CONT TestSignErrors/no_prefix2569=== CONT TestSignErrors/invalid_json2570=== CONT TestSignErrors/http_error2571=== CONT TestSignErrors/invalid_base642572--- PASS: TestSign (0.00s)2573--- PASS: TestSignErrors (0.00s)2574 --- PASS: TestSignErrors/invalid_json (0.00s)2575 --- PASS: TestSignErrors/no_prefix (0.00s)2576 --- PASS: TestSignErrors/http_error (0.00s)2577 --- PASS: TestSignErrors/invalid_base64 (0.00s)2578PASS