nixbot

builds

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #366 · raw

1tribuchet: building on eliza2Running 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.09s)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 TestScriptTokenScriptFails101=== CONT TestScriptTokenEmptyCommand102=== CONT TestResolveStorePath103=== CONT TestScriptTokenBadJSON104=== CONT TestStreamPushReportsSignatures105=== CONT TestStreamPushRequestLine106=== CONT TestStreamPushGivesUpOnDeadServer107=== CONT TestStreamPushIsolatesFailures108=== CONT TestStreamPushBatchesUnderLoad109=== CONT TestStreamPushReportsEveryPath110=== CONT TestShellSplitErrors111=== CONT TestClientSignaturesByStorePath112=== CONT TestShellSplit113=== CONT TestFileTokenMissing114=== CONT TestPathInfoHashCompatibility115=== CONT TestScriptTokenEmptyToken116=== CONT TestScriptTokenCachesUntilRefresh117=== CONT TestScriptTokenNoExpiryRerunsEveryCall118=== CONT TestFileTokenEmpty119=== CONT TestStaticToken120=== CONT TestFileTokenReadsAndCaches121=== CONT TestSetClientTLSErrors122=== CONT TestDumpPathWriterError123--- PASS: TestScriptTokenEmptyCommand (0.00s)124=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess125=== CONT TestRateLimiterFeedback126=== CONT TestDoWithRetry_BodyReplayedViaGetBody127=== CONT TestPathInfoCACompatibility128=== CONT TestParsePathInfoJSONMultiplePaths129=== CONT TestGetStorePathHash1302026/10/06 09:19:20 ERROR Upload failed error=boom count=11312026/10/06 09:19:20 ERROR Upload failed error=boom count=1132=== RUN TestGetStorePathHash/valid_store_path133=== PAUSE TestGetStorePathHash/valid_store_path134=== RUN TestGetStorePathHash/basename_without_hyphen_should_error135=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error136=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error137=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error138=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error139=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error140=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths141=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths142=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths143=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths144=== CONT TestConvertHashToNix32145=== RUN TestConvertHashToNix32/SRI_format_to_Nix32146=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32147=== RUN TestConvertHashToNix32/already_Nix32_format148=== PAUSE TestConvertHashToNix32/already_Nix32_format149=== RUN TestConvertHashToNix32/invalid_format1502026/10/06 09:19:20 ERROR Upload failed error="bad path" count=3151=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1522026/10/06 09:19:20 WARN Rate limiter enabled after throttle name=server-test rate=5153--- PASS: TestShellSplitErrors (0.00s)1542026/10/06 09:19:20 ERROR Upload failed error="connection refused" count=201552026/10/06 09:19:20 ERROR Server seems unavailable, giving up on batch untried=17156=== CONT TestParsePathInfoJSON157=== RUN TestParsePathInfoJSON/Nix_format158=== RUN TestRateLimiterFeedback/429_enables_limiter159=== PAUSE TestParsePathInfoJSON/Nix_format160=== RUN TestParsePathInfoJSON/Lix_format161=== PAUSE TestParsePathInfoJSON/Lix_format162=== RUN TestParsePathInfoJSON/empty_input163=== CONT TestEncodeNixBase32WithRealHash164=== CONT TestFilterOversizedClosures165=== RUN TestPathInfoCACompatibility/null_ca_field166=== CONT TestSetClientTLSDoesNotMutateDefaultTransport167=== PAUSE TestPathInfoCACompatibility/null_ca_field168=== RUN TestPathInfoCACompatibility/old_string_format_-_text169=== CONT TestEncodeNixBase32170--- PASS: TestClientSignaturesByStorePath (0.00s)171=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)172=== CONT TestPartSizeForNAR173=== CONT TestUploadMultipart_PartsInParallel174=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun175=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon176=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon1772026/10/06 09:19:20 WARN Rate limiter enabled after throttle name=server-test rate=5178=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1792026/10/06 09:19:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43537180=== PAUSE TestConvertHashToNix32/invalid_format181=== PAUSE TestRateLimiterFeedback/429_enables_limiter182=== CONT TestDumpPathSingleFile183=== CONT TestDumpPathMatchesNix184=== PAUSE TestParsePathInfoJSON/empty_input185=== RUN TestFilterOversizedClosures/no_limit_keeps_everything186=== CONT TestUploadMultipart_SupersededByPeer187=== RUN TestUploadMultipart_SupersededByPeer/exists188=== PAUSE TestUploadMultipart_SupersededByPeer/exists189=== RUN TestUploadMultipart_SupersededByPeer/missing190=== PAUSE TestUploadMultipart_SupersededByPeer/missing191=== RUN TestEncodeNixBase32/test_string_hash192=== PAUSE TestEncodeNixBase32/test_string_hash193=== RUN TestEncodeNixBase32/empty_input194=== PAUSE TestEncodeNixBase32/empty_input195=== RUN TestRateLimiterFeedback/503_enables_limiter196=== CONT TestRegisterUploadedObjectReusesConnections197=== PAUSE TestRateLimiterFeedback/503_enables_limiter198=== RUN TestPartSizeForNAR/zero_stays_at_minimum199=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI200=== CONT TestCaseHackSuffix201=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything202=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica203--- PASS: TestScriptTokenScriptFails (0.00s)204--- PASS: TestResolveStorePath (0.00s)205=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text206=== RUN TestParsePathInfoJSON/whitespace_only207=== RUN TestSetClientTLSErrors/missing_cert_file208=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum209=== RUN TestPartSizeForNAR/small_stays_at_minimum2102026/10/06 09:19:20 WARN Rate limiter backed off name=server-test rate=52112026/10/06 09:19:20 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43537212=== CONT TestSetClientTLS213=== PAUSE TestPartSizeForNAR/small_stays_at_minimum214=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive215=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths216=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive217=== RUN TestPathInfoCACompatibility/new_structured_format_-_text218=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text219=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method220=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method221=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error222=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error223=== CONT TestGetStorePathHash/basename_without_hyphen_should_error224=== CONT TestConvertHashToNix32/SRI_format_to_Nix32225=== CONT TestConvertHashToNix32/invalid_format226=== CONT TestConvertHashToNix32/already_Nix32_format227=== CONT TestUploadMultipart_SupersededByPeer/exists2282026/10/06 09:19:20 INFO Garbage collection started229=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped230=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231=== RUN TestFilterOversizedClosures/all_closures_skipped232=== PAUSE TestFilterOversizedClosures/all_closures_skipped233=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum2342026/10/06 09:19:20 INFO Garbage collection started235=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum236=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts237=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts238=== RUN TestPartSizeForNAR/1_TiB239=== PAUSE TestPartSizeForNAR/1_TiB240=== RUN TestPartSizeForNAR/5_TiB_S3_max_object241=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object242=== RUN TestPartSizeForNAR/capped_at_5_GiB243=== PAUSE TestPartSizeForNAR/capped_at_5_GiB244=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths245=== CONT TestEncodeNixBase32/empty_input246=== CONT TestPathInfoCACompatibility/null_ca_field247=== CONT TestPathInfoCACompatibility/new_structured_format_-_text248=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method249=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive250=== CONT TestFilterOversizedClosures/no_limit_keeps_everything251=== CONT TestPartSizeForNAR/zero_stays_at_minimum252=== CONT TestPathInfoCACompatibility/old_string_format_-_text253=== PAUSE TestParsePathInfoJSON/whitespace_only254=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512255=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512256=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)257=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts258=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512259=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI260=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon261=== CONT TestEncodeNixBase32/test_string_hash262=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped263=== CONT TestUploadMultipart_SupersededByPeer/missing2642026/10/06 09:19:20 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=2000265=== CONT TestPartSizeForNAR/capped_at_5_GiB266=== CONT TestPartSizeForNAR/5_TiB_S3_max_object267=== CONT TestPartSizeForNAR/1_TiB268=== RUN TestParsePathInfoJSON/invalid_JSON269=== PAUSE TestParsePathInfoJSON/invalid_JSON270=== RUN TestSetClientTLS/rejects_connection_without_client_cert271=== CONT TestParsePathInfoJSON/empty_input272=== CONT TestParsePathInfoJSON/Nix_format273=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert274=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA275=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum276=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter277=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter278=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter279=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter280=== CONT TestRateLimiterFeedback/429_enables_limiter2812026/10/06 09:19:20 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=0282=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter283=== CONT TestFilterOversizedClosures/all_closures_skipped2842026/10/06 09:19:20 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=50285=== CONT TestRateLimiterFeedback/503_enables_limiter286=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter287=== CONT TestPartSizeForNAR/small_stays_at_minimum2882026/10/06 09:19:20 WARN Rate limiter enabled after throttle name=server-test rate=5289=== CONT TestParsePathInfoJSON/invalid_JSON2902026/10/06 09:19:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:40857291=== CONT TestParsePathInfoJSON/whitespace_only292--- PASS: TestShellSplit (0.00s)293--- PASS: TestStaticToken (0.00s)294--- PASS: TestStreamPushReportsEveryPath (0.00s)295--- PASS: TestStreamPushReportsSignatures (0.00s)296--- PASS: TestStreamPushIsolatesFailures (0.00s)297--- PASS: TestFileTokenMissing (0.00s)298--- PASS: TestScriptTokenBadJSON (0.00s)299--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)300--- PASS: TestFileTokenReadsAndCaches (0.00s)301--- PASS: TestFileTokenEmpty (0.00s)302--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)303--- PASS: TestEncodeNixBase32WithRealHash (0.00s)304--- PASS: TestDoServerRequestAttachesToken (0.01s)305--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)306=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA307=== CONT TestParsePathInfoJSON/Lix_format308=== CONT TestGetStorePathHash/valid_store_path309=== PAUSE TestSetClientTLSErrors/missing_cert_file310=== RUN TestSetClientTLSErrors/missing_key_file311=== PAUSE TestSetClientTLSErrors/missing_key_file312=== RUN TestSetClientTLSErrors/missing_ca_file313=== RUN TestSetClientTLS/preserves_debug_logging_transport3142026/10/06 09:19:20 WARN Rate limiter backed off name=server-test rate=5315=== PAUSE TestSetClientTLS/preserves_debug_logging_transport316=== CONT TestSetClientTLS/rejects_connection_without_client_cert317--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)3182026/10/06 09:19:20 WARN Rate limiter enabled after throttle name=server-test rate=5319--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)3202026/10/06 09:19:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:32787321=== PAUSE TestSetClientTLSErrors/missing_ca_file322=== RUN TestSetClientTLSErrors/invalid_ca_file323=== PAUSE TestSetClientTLSErrors/invalid_ca_file324=== CONT TestSetClientTLSErrors/missing_cert_file325=== CONT TestSetClientTLS/preserves_debug_logging_transport3262026/10/06 09:19:20 WARN Rate limiter backed off name=server-test rate=5327--- PASS: TestConvertHashToNix32 (0.00s)328 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)329 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)330 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)331--- PASS: TestScriptTokenEmptyToken (0.04s)3322026/10/06 09:19:20 WARN Garbage collection finished on another replica. Its statistics are not available here333=== CONT TestSetClientTLSErrors/invalid_ca_file334--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)335=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA336--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)337 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)338 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)339--- PASS: TestEncodeNixBase32 (0.00s)340 --- PASS: TestEncodeNixBase32/empty_input (0.00s)341 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)342--- PASS: TestGetStorePathHash (0.00s)343 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)344 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)345 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)346 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)347--- PASS: TestParsePathInfoJSON (0.03s)348 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)349 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)350 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)351 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)352 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)353--- PASS: TestPartSizeForNAR (0.03s)354 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)355 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)356 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)357 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)358 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)359 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)360 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)361--- PASS: TestFilterOversizedClosures (0.03s)362 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)363 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)364 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)365--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)366--- PASS: TestRateLimiterFeedback (0.04s)367 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)368 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)369 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)370 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)371--- PASS: TestPathInfoCACompatibility (0.03s)372 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)373 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)374 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)375 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)376 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)377--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)378 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)379 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)380--- PASS: TestPathInfoHashCompatibility (0.04s)381 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)382 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)383 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)384 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)385=== CONT TestSetClientTLSErrors/missing_key_file386=== CONT TestSetClientTLSErrors/missing_ca_file387--- PASS: TestSetClientTLSErrors (0.04s)388 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)389 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3922026/10/06 09:19:20 http: TLS handshake error from 127.0.0.1:36960: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.01s)394 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)395 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)397--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)398--- PASS: TestDumpPathSingleFile (0.06s)399--- PASS: TestCaseHackSuffix (0.03s)400--- PASS: TestStreamPushRequestLine (0.07s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)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/postgres3493143312/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/postgres3493143312/data -l logfile start434435/build/postgres3493143312:5432 - no response4362026-10-06 09:19:22.806 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 09:19:22.807 UTC [129] LOG: listening on Unix socket "/build/postgres3493143312/.s.PGSQL.5432"4382026-10-06 09:19:22.811 UTC [136] LOG: database system was shut down at 2026-10-06 09:19:22 UTC4392026-10-06 09:19:22.814 UTC [129] LOG: database system is ready to accept connections440/build/postgres3493143312: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 09:19:23 INFO lead: acquired remote=192.0.2.1:12344872026/10/06 09:19:23 INFO lead: released remote=192.0.2.1:12344882026/10/06 09:19:23 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 09:19:25 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/06 09:19:25 INFO lead: acquired remote=192.0.2.1:12344972026-10-06 09:19:26.515 UTC [382] FATAL: terminating connection due to administrator command4982026/10/06 09:19:26 INFO lead: acquired remote=192.0.2.1:12344992026/10/06 09:19:27 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/06 09:19:27 INFO lead: released remote=192.0.2.1:12345012026/10/06 09:19:27 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 09:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/06 09:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 09:19:28 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 TestSkippedUploadsHandler692=== CONT TestCompletedNarNotReofferedAcrossClosures693=== CONT TestService_cleanupPendingClosuresHandler694=== CONT TestUploadHandlersRejectOversizedBody695=== CONT TestGCTaskStore_CompletedAllowsNewTask696=== CONT TestParseSize697=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded6982026/10/06 09:19:28 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000699=== CONT TestService_Rustfstest700=== CONT TestPresignedUploadRegisteredBeforeCommit701=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT702=== CONT TestCompleteMultipartUnregistered703=== CONT TestService_verifyS3Integrity704=== CONT TestService_createPendingClosureHandler705=== CONT TestCompleteMultipartUpload_ErrorButObjectExists706=== CONT TestRedundantMultipartUpload707=== CONT TestPush_SignsNarinfosOfItsPendingObjects708=== CONT TestPush_RejectsBadRequests709=== CONT TestPresentNotReportedWhileGCDeletesClosure710=== CONT TestPresentReportsOnlyClosureRoots711=== CONT TestCreatePin_ReservedPins712=== CONT TestOrphanedObjectsGCStressTest713=== CONT TestOrphanedObjectsGC714=== CONT TestObjectStatsTrigger715=== CONT TestPendingCleanupUsesOneCutoff716=== CONT TestService_AuthMiddleware717--- PASS: TestParseSize (0.00s)718=== CONT TestParseSingleRange719=== RUN TestParseSingleRange/none720=== PAUSE TestParseSingleRange/none721=== CONT TestMultipartCleanup722--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)723--- PASS: TestSkippedUploadsHandler (0.01s)724=== RUN TestParseSingleRange/unknown_unit725=== PAUSE TestParseSingleRange/unknown_unit726=== RUN TestParseSingleRange/multi-range_ignored727=== PAUSE TestParseSingleRange/multi-range_ignored728=== RUN TestParseSingleRange/malformed_no_dash729=== PAUSE TestParseSingleRange/malformed_no_dash730=== RUN TestParseSingleRange/malformed_both_empty731=== PAUSE TestParseSingleRange/malformed_both_empty732=== RUN TestParseSingleRange/malformed_end_before_start733=== PAUSE TestParseSingleRange/malformed_end_before_start734=== RUN TestParseSingleRange/closed735=== PAUSE TestParseSingleRange/closed736=== RUN TestParseSingleRange/open-ended737=== PAUSE TestParseSingleRange/open-ended738=== RUN TestParseSingleRange/end_clamped_to_size739=== PAUSE TestParseSingleRange/end_clamped_to_size740=== RUN TestParseSingleRange/suffix741=== PAUSE TestParseSingleRange/suffix742=== RUN TestParseSingleRange/suffix_exceeds_size743=== PAUSE TestParseSingleRange/suffix_exceeds_size744=== RUN TestParseSingleRange/single_byte745=== PAUSE TestParseSingleRange/single_byte746=== RUN TestParseSingleRange/start_past_EOF747=== PAUSE TestParseSingleRange/start_past_EOF748=== RUN TestParseSingleRange/start_far_past_EOF749=== PAUSE TestParseSingleRange/start_far_past_EOF750=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit7512026/10/06 09:19:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35623/oidc752=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts753=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts754=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure755=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure756=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart757=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart758=== CONT TestServerTLSConfig759=== RUN TestServerTLSConfig/no_client_CA760=== PAUSE TestServerTLSConfig/no_client_CA761=== RUN TestServerTLSConfig/missing_CA_file762=== PAUSE TestServerTLSConfig/missing_CA_file763=== RUN TestServerTLSConfig/not_a_PEM_file764=== PAUSE TestServerTLSConfig/not_a_PEM_file765=== CONT TestPush_CompleteCommitsEveryRoot7662026/10/06 09:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7672026/10/06 09:19:28 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst768--- PASS: TestCompleteMultipartUnregistered (0.26s)769=== CONT TestService_NativeMTLS7702026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures7712026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures7722026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures7732026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures7742026/10/06 09:19:28 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7752026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures776--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.33s)777=== CONT TestPush_OverlappingRootsStoreOneRowPerKey7782026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures7792026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures7802026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures781--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.38s)782=== CONT TestMetricsInventory783--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.38s)784=== CONT TestReadRedirectUsesPublicS3URL7852026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures7862026/10/06 09:19:28 INFO Received cleanup request method=DELETE path=/api/pending_closures7872026/10/06 09:19:28 INFO Aborted multipart uploads count=0 kept=07882026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures7892026/10/06 09:19:28 INFO Received cleanup request method=DELETE path=/api/pending_closures7902026/10/06 09:19:28 INFO Aborted multipart uploads count=1 kept=07912026/10/06 09:19:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7922026-10-06 09:19:28.600 UTC [451] ERROR: Closure does not exist: id=17932026-10-06 09:19:28.600 UTC [451] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE7942026-10-06 09:19:28.600 UTC [451] STATEMENT: -- name: CommitPendingClosure :exec795 SELECT commit_pending_closure($1::bigint)796 797--- PASS: TestService_cleanupPendingClosuresHandler (0.46s)798=== CONT TestNARDeduplicationMetadataUploadBug799--- PASS: TestService_Rustfstest (0.46s)800=== CONT TestReadProxyRangeRequest8012026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures8022026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures803--- PASS: TestPresentReportsOnlyClosureRoots (0.44s)804=== CONT TestCreatePendingClosureRejectsOversizedNAR8052026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures806--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)807=== CONT TestReadRedirectKeepsNarinfoProxied8082026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures809=== RUN TestPush_RejectsBadRequests/no_roots810=== PAUSE TestPush_RejectsBadRequests/no_roots811=== RUN TestPush_RejectsBadRequests/no_objects812=== PAUSE TestPush_RejectsBadRequests/no_objects813=== RUN TestPush_RejectsBadRequests/bad_root814=== PAUSE TestPush_RejectsBadRequests/bad_root815=== RUN TestPush_RejectsBadRequests/root_not_in_objects816=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects817=== CONT TestCacheConfigHandlerMaxNarSize818--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)819=== CONT TestReadRedirectNar8202026/10/06 09:19:28 INFO Received push request method=POST path=/api/pushes8212026/10/06 09:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8222026/10/06 09:19:28 INFO Received complete push request method=POST path=/api/pushes/1/complete8232026/10/06 09:19:28 INFO Received push request method=POST path=/api/pushes8242026/10/06 09:19:28 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjIxMzRmMzgtNjM0Ny00N2E5LWE3M2EtZWQyYThjNDI0YmU3LmYwNWJmZWNiLTRjODMtNDE0NS05MGU5LTQ5OTdjODM3OWNjNXgxNzkxMjc4MzY4NDM0MTcxODU3 parts=108252026/10/06 09:19:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8262026/10/06 09:19:28 INFO Completed upload id=18272026/10/06 09:19:28 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008282026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures8292026/10/06 09:19:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures8302026/10/06 09:19:28 INFO Aborted multipart uploads count=0 kept=08312026/10/06 09:19:28 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=08322026/10/06 09:19:28 INFO Vacuumed table table=pending_closures8332026/10/06 09:19:28 INFO Vacuumed table table=pending_objects8342026/10/06 09:19:28 INFO Vacuumed table table=multipart_uploads8352026/10/06 09:19:28 INFO Vacuumed table table=closures8362026/10/06 09:19:28 INFO Received cleanup request method=DELETE path=/api/pending_closures8372026/10/06 09:19:28 INFO Vacuumed table table=objects8382026/10/06 09:19:28 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket14/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8392026/10/06 09:19:28 INFO Aborted multipart uploads count=0 kept=18402026/10/06 09:19:28 INFO Received cleanup request method=DELETE path=/api/pending_closures8412026/10/06 09:19:28 INFO Aborted multipart uploads count=1 kept=0842--- PASS: TestMultipartCleanup (0.58s)843=== CONT TestGenerateLandingPage8442026/10/06 09:19:28 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"845--- PASS: TestService_AuthMiddleware (0.58s)846=== CONT TestReadProxyDisabled847--- PASS: TestGenerateLandingPage (0.00s)848=== CONT TestService_readinessHandler8492026/10/06 09:19:28 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000850--- PASS: TestService_createPendingClosureHandler (0.67s)851=== CONT TestReadProxyRootRedirectsToIndexHTML8522026/10/06 09:19:28 INFO Aborted multipart uploads count=0 kept=08532026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures8542026/10/06 09:19:28 WARN Force mode enabled - objects will be deleted immediately without grace period8552026/10/06 09:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8562026/10/06 09:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8572026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures8582026/10/06 09:19:28 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=08592026/10/06 09:19:28 INFO Vacuumed table table=pending_closures8602026/10/06 09:19:28 INFO Received cleanup request method=DELETE path=/api/pending_closures8612026/10/06 09:19:28 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjIxMzRmMzgtNjM0Ny00N2E5LWE3M2EtZWQyYThjNDI0YmU3LjA4NDI4MTk2LTg4ZjktNGJiMy04YmZkLTlhYWRmZWFkNmYzMngxNzkxMjc4MzY4NDgzNDY1MDQ4 parts=128622026/10/06 09:19:28 INFO Vacuumed table table=pending_objects8632026/10/06 09:19:28 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjIxMzRmMzgtNjM0Ny00N2E5LWE3M2EtZWQyYThjNDI0YmU3LjVkMzI4MWViLWQ2NGItNDM5Yi05YzQ4LTdhNDcxNGVjM2NiOHgxNzkxMjc4MzY4NTQ4OTkxMDAw parts=108642026/10/06 09:19:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8652026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures8662026/10/06 09:19:28 INFO Vacuumed table table=multipart_uploads8672026/10/06 09:19:28 INFO Received push request method=POST path=/api/pushes8682026/10/06 09:19:28 INFO Completed upload id=1869--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.72s)870=== CONT TestService_healthCheckHandler8712026/10/06 09:19:28 INFO Vacuumed table table=closures8722026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures8732026/10/06 09:19:28 INFO Vacuumed table table=objects8742026/10/06 09:19:28 INFO Received complete push request method=POST path=/api/pushes/2/complete8752026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures876--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.64s)877=== CONT TestReadProxyConditionalGet8782026/10/06 09:19:28 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8792026/10/06 09:19:28 WARN Found objects in DB but missing from S3, will re-upload count=1880--- PASS: TestService_verifyS3Integrity (0.73s)8812026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign882=== CONT TestGracefulShutdownDrainsInflight8832026/10/06 09:19:28 INFO Starting HTTP server address=127.0.0.1:335998842026/10/06 09:19:28 INFO Shutdown signal received, draining in-flight requests timeout=10s8852026/10/06 09:19:28 INFO Signed narinfos id=1 count=18862026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8872026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8882026/10/06 09:19:28 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8892026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8902026/10/06 09:19:28 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8912026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8922026/10/06 09:19:28 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18932026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8942026/10/06 09:19:28 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo895--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.65s)896=== CONT TestReadProxyOutlastsServerWriteTimeout8972026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures8982026/10/06 09:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8992026/10/06 09:19:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjIxMzRmMzgtNjM0Ny00N2E5LWE3M2EtZWQyYThjNDI0YmU3LmUxMzIwYzI3LTcxZDEtNGQyYi1iY2Y0LWJmOTQ5MDc0Yzk1Y3gxNzkxMjc4MzY4ODk0NDE4Mjc49002026/10/06 09:19:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjIxMzRmMzgtNjM0Ny00N2E5LWE3M2EtZWQyYThjNDI0YmU3LmUxMzIwYzI3LTcxZDEtNGQyYi1iY2Y0LWJmOTQ5MDc0Yzk1Y3gxNzkxMjc4MzY4ODk0NDE4Mjc4 parts=1901--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.71s)902=== CONT TestGCTaskStore_Fail903--- PASS: TestGCTaskStore_Fail (0.00s)904=== CONT TestReadProxyHead905--- PASS: TestGracefulShutdownDrainsInflight (0.07s)906=== CONT TestGCTaskStore_PhaseUpdates907--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)908=== CONT TestReadProxyInvalidPath909--- PASS: TestObjectStatsTrigger (0.72s)910=== CONT TestReadProxy4049112026/10/06 09:19:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9122026/10/06 09:19:28 WARN Refused reserved pin name=worker-x86_64-linux9132026/10/06 09:19:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9142026/10/06 09:19:28 INFO Received create pin request method=POST path=/api/pins/my-app9152026/10/06 09:19:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux916--- PASS: TestCreatePin_ReservedPins (0.75s)917=== CONT TestReadProxyNarinfoAlreadyDecompressed9182026/10/06 09:19:28 INFO Received push request method=POST path=/api/pushes9192026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete9202026/10/06 09:19:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9212026/10/06 09:19:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9222026/10/06 09:19:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"923--- PASS: TestService_NativeMTLS (0.61s)924=== CONT TestReadProxyNarinfo925--- PASS: TestPush_CompleteCommitsEveryRoot (0.71s)926=== CONT TestReadProxyNarStreaming9272026/10/06 09:19:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjIxMzRmMzgtNjM0Ny00N2E5LWE3M2EtZWQyYThjNDI0YmU3LmIxYjI3NjJlLWNjZjktNDEyZi1iMmVkLWM1YzA4MTVmMDIxN3gxNzkxMjc4MzY4NjQyNTAyMTk3 parts=129282026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures9292026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes9302026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures931--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.60s)932=== CONT TestIsValidCachePath933=== RUN TestIsValidCachePath/narinfo934=== PAUSE TestIsValidCachePath/narinfo935=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars936=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars937=== RUN TestIsValidCachePath/nar_zst938=== PAUSE TestIsValidCachePath/nar_zst939=== RUN TestIsValidCachePath/nar_xz940=== PAUSE TestIsValidCachePath/nar_xz941=== RUN TestIsValidCachePath/nar_bz2942=== PAUSE TestIsValidCachePath/nar_bz2943=== RUN TestIsValidCachePath/nar_uncompressed944=== PAUSE TestIsValidCachePath/nar_uncompressed945=== RUN TestIsValidCachePath/ls946=== PAUSE TestIsValidCachePath/ls947=== RUN TestIsValidCachePath/log948=== PAUSE TestIsValidCachePath/log949=== RUN TestIsValidCachePath/realisation950=== PAUSE TestIsValidCachePath/realisation951=== RUN TestIsValidCachePath/nix-cache-info952=== PAUSE TestIsValidCachePath/nix-cache-info953=== RUN TestIsValidCachePath/index.html954=== PAUSE TestIsValidCachePath/index.html955=== RUN TestIsValidCachePath/traversal_parent956=== PAUSE TestIsValidCachePath/traversal_parent957=== RUN TestIsValidCachePath/traversal_in_middle958=== PAUSE TestIsValidCachePath/traversal_in_middle959=== RUN TestIsValidCachePath/invalid_char_e960=== PAUSE TestIsValidCachePath/invalid_char_e961=== RUN TestIsValidCachePath/invalid_char_u962=== PAUSE TestIsValidCachePath/invalid_char_u963=== RUN TestIsValidCachePath/random_path964=== PAUSE TestIsValidCachePath/random_path965=== RUN TestIsValidCachePath/empty966=== PAUSE TestIsValidCachePath/empty967=== RUN TestIsValidCachePath/leading_slash968=== PAUSE TestIsValidCachePath/leading_slash969=== RUN TestIsValidCachePath/wrong_extension970=== PAUSE TestIsValidCachePath/wrong_extension971=== RUN TestIsValidCachePath/short_hash972=== PAUSE TestIsValidCachePath/short_hash973=== CONT TestReadProxyContentNegotiation974--- PASS: TestMetricsInventory (0.58s)975=== CONT TestProxyHeadersOnlyTrustedOnSocket976--- PASS: TestReadRedirectUsesPublicS3URL (0.59s)977=== CONT TestPendingClosureWriteTimeout978=== RUN TestPendingClosureWriteTimeout/empty979=== PAUSE TestPendingClosureWriteTimeout/empty980=== RUN TestPendingClosureWriteTimeout/400_objects981=== PAUSE TestPendingClosureWriteTimeout/400_objects982=== RUN TestPendingClosureWriteTimeout/670k_objects983=== PAUSE TestPendingClosureWriteTimeout/670k_objects984=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline985=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline986=== CONT TestRegisterCompletedObjectNeedsPendingRow987=== NAME TestOrphanedObjectsGC988 orphaned_objects_gc_test.go:290: GC Test Summary:989 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A990 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B991 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)992 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)993 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects994--- PASS: TestOrphanedObjectsGC (0.89s)995=== CONT TestGCAdvisoryLockBlocksConcurrentRun996--- PASS: TestReadProxyRangeRequest (0.56s)997=== CONT TestSweepSkipsRowsLockedByPush998=== NAME TestNARDeduplicationMetadataUploadBug999 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3820299015/001/store/2g3bka4w3cwiqxcydra9rdka4k9sby2j-file1.txt1000--- PASS: TestReadRedirectKeepsNarinfoProxied (0.51s)1001=== CONT TestUploadHandlersRejectInvalidKeys1002=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1003=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1004=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1005=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1006=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1007=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1008=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1009=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1010=== CONT TestFailedS3DeleteKeepsTombstone1011--- PASS: TestReadRedirectNar (0.49s)1012=== CONT TestIsValidUploadKey1013=== RUN TestIsValidUploadKey/narinfo1014=== PAUSE TestIsValidUploadKey/narinfo1015=== RUN TestIsValidUploadKey/nar_zst1016=== PAUSE TestIsValidUploadKey/nar_zst1017=== RUN TestIsValidUploadKey/nar_xz1018=== PAUSE TestIsValidUploadKey/nar_xz1019=== RUN TestIsValidUploadKey/nar_plain1020=== PAUSE TestIsValidUploadKey/nar_plain1021=== RUN TestIsValidUploadKey/listing1022=== PAUSE TestIsValidUploadKey/listing1023=== RUN TestIsValidUploadKey/build_log1024=== PAUSE TestIsValidUploadKey/build_log1025=== RUN TestIsValidUploadKey/build_log_home-manager_file1026=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1027=== RUN TestIsValidUploadKey/build_log_plus_in_name1028=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1029=== RUN TestIsValidUploadKey/build_log_question_mark1030=== PAUSE TestIsValidUploadKey/build_log_question_mark1031=== RUN TestIsValidUploadKey/build_log_equals1032=== PAUSE TestIsValidUploadKey/build_log_equals1033=== RUN TestIsValidUploadKey/realisation1034=== PAUSE TestIsValidUploadKey/realisation1035=== RUN TestIsValidUploadKey/realisation_plus_in_output1036=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1037=== RUN TestIsValidUploadKey/nix-cache-info1038=== PAUSE TestIsValidUploadKey/nix-cache-info1039=== RUN TestIsValidUploadKey/index.html1040=== PAUSE TestIsValidUploadKey/index.html1041=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1042=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1043=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1044=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1045=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1046=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1047=== RUN TestIsValidUploadKey/traversal1048=== PAUSE TestIsValidUploadKey/traversal1049=== RUN TestIsValidUploadKey/traversal_nar1050=== PAUSE TestIsValidUploadKey/traversal_nar1051=== RUN TestIsValidUploadKey/absolute1052=== PAUSE TestIsValidUploadKey/absolute1053=== RUN TestIsValidUploadKey/empty_key1054=== PAUSE TestIsValidUploadKey/empty_key1055=== RUN TestIsValidUploadKey/unknown_type1056=== PAUSE TestIsValidUploadKey/unknown_type1057=== CONT TestProxyWriteTimeout1058=== RUN TestProxyWriteTimeout/narinfo1059=== PAUSE TestProxyWriteTimeout/narinfo1060=== RUN TestProxyWriteTimeout/1_GiB_nar1061=== PAUSE TestProxyWriteTimeout/1_GiB_nar1062=== RUN TestProxyWriteTimeout/10_GiB_nar1063=== PAUSE TestProxyWriteTimeout/10_GiB_nar1064=== RUN TestProxyWriteTimeout/unknown_size1065=== PAUSE TestProxyWriteTimeout/unknown_size1066=== CONT TestGCSweepSkipsPendingObjects1067--- PASS: TestReadProxyDisabled (0.41s)1068=== CONT TestForceGCDuringPushOffersSweptObject1069=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1070=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1071=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1072=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1073=== CONT TestGCTaskStore_GetReturnsLatest1074--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1075=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10762026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes10772026/10/06 09:19:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10782026/10/06 09:19:29 INFO Uploading 2g3bka4w3cwiqxcydra9rdka4k9sby2j-file1.txt (160B)10792026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10802026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10812026/10/06 09:19:29 WARN Failed to register uploaded object key=2g3bka4w3cwiqxcydra9rdka4k9sby2j.ls error="server returned 404: 404 page not found\n"10822026/10/06 09:19:29 INFO Signed narinfos id=1 count=110832026/10/06 09:19:29 INFO Uploading 1 narinfos10842026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete10852026/10/06 09:19:29 WARN Failed to register uploaded object key=2g3bka4w3cwiqxcydra9rdka4k9sby2j.narinfo error="server returned 404: 404 page not found\n"10862026/10/06 09:19:29 WARN readiness check failed error="closed pool"1087--- PASS: TestService_readinessHandler (0.44s)1088=== CONT TestGCMetrics10892026/10/06 09:19:29 INFO Upload complete. (62ms)1090=== NAME TestNARDeduplicationMetadataUploadBug1091 metadata_upload_test.go:54: Retrieved narinfo from S3:1092 StorePath: /build/TestNARDeduplicationMetadataUploadBug3820299015/001/store/2g3bka4w3cwiqxcydra9rdka4k9sby2j-file1.txt1093 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1094 Compression: zstd1095 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1096 NarSize: 1601097 References: 1098 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1099 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1100 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1101 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1102--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.46s)1103=== CONT TestGCTaskStore_GetEmpty1104--- PASS: TestGCTaskStore_GetEmpty (0.00s)1105=== CONT TestGCSweepDeliversEachKeyOnce1106=== NAME TestNARDeduplicationMetadataUploadBug1107 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3820299015/001/store/1lkryrbzqranss5x15d3bchs930zafnq-file2.txt1108--- PASS: TestService_healthCheckHandler (0.45s)1109=== CONT TestGCTaskStore_ConflictDifferentParams1110--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1111=== CONT TestGCBugBareHashReferences1112--- PASS: TestReadProxyConditionalGet (0.48s)1113=== CONT TestTombstonedObjectOfferedWithoutWaiting11142026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes11152026/10/06 09:19:29 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11162026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11172026/10/06 09:19:29 INFO Signed narinfos id=2 count=111182026/10/06 09:19:29 WARN Failed to register uploaded object key=1lkryrbzqranss5x15d3bchs930zafnq.ls error="server returned 404: 404 page not found\n"11192026/10/06 09:19:29 INFO Uploading 1 narinfos11202026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/2/complete11212026/10/06 09:19:29 WARN Failed to register uploaded object key=1lkryrbzqranss5x15d3bchs930zafnq.narinfo error="server returned 404: 404 page not found\n"11222026/10/06 09:19:29 INFO Upload complete. (50ms)1123--- PASS: TestReadProxyInvalidPath (0.44s)1124=== CONT TestGCTaskStore_DeduplicateSameParams1125--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1126=== CONT TestGCTaskStore_StartNew1127--- PASS: TestGCTaskStore_StartNew (0.00s)1128=== CONT TestClientMultipleUploads1129=== NAME TestNARDeduplicationMetadataUploadBug1130 metadata_upload_test.go:76: Retrieved narinfo from S3:1131 StorePath: /build/TestNARDeduplicationMetadataUploadBug3820299015/001/store/1lkryrbzqranss5x15d3bchs930zafnq-file2.txt1132 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1133 Compression: zstd1134 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1135 NarSize: 1601136 References: 1137 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1138 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1139 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1140 {"version":1,"root":{"type":"regular","size":44}}1141--- PASS: TestNARDeduplicationMetadataUploadBug (0.79s)1142=== CONT TestGCEndsOnShutdown1143=== RUN TestGCEndsOnShutdown/before_the_run1144=== PAUSE TestGCEndsOnShutdown/before_the_run1145=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1146=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1147=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1148=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1149=== CONT TestDeduplicatedObjectsRecordedAsPending11502026/10/06 09:19:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1151--- PASS: TestReadProxyHead (0.48s)1152=== CONT TestPushDedupSurvivesConcurrentGC1153--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.19s)1154=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle11552026/10/06 09:19:29 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjIxMzRmMzgtNjM0Ny00N2E5LWE3M2EtZWQyYThjNDI0YmU3LmNiYzJhODNjLTZkOGEtNDI1YS1iYzE4LTg4NmJjYTJjMjg0NngxNzkxMjc4MzY5MDUxMzE3MDY5 error="Get \"http://127.0.0.1:1/bucket12/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11562026/10/06 09:19:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjIxMzRmMzgtNjM0Ny00N2E5LWE3M2EtZWQyYThjNDI0YmU3LjViMDMwMDM5LWQ1ODMtNDE4MC1iOWUwLWM0Yzc2NmI5OTM3ZHgxNzkxMjc4MzY5MDQzMDQ4Mjk2 parts=1211572026/10/06 09:19:29 INFO Received cleanup request method=DELETE path=/api/pending_closures11582026/10/06 09:19:29 INFO Aborted multipart uploads count=1 kept=01159--- PASS: TestRedundantMultipartUpload (1.22s)1160=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1161--- PASS: TestReadProxy404 (0.50s)1162=== CONT TestLeadIncumbentAnnouncesAtOnce1163--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.49s)1164=== CONT TestSweepRechecksPendingAfterLocking1165--- PASS: TestReadProxyNarStreaming (0.49s)1166=== CONT TestCommitRacingPendingCleanupKeepsObjects11672026/10/06 09:19:29 INFO Starting HTTP server address=127.0.0.1:4364511682026/10/06 09:19:29 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3839159390/001/proxy.sock11692026/10/06 09:19:29 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11702026/10/06 09:19:29 INFO Shutdown signal received, draining in-flight requests timeout=10s1171--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.47s)1172=== CONT TestLeadElectsOneAndHandsOver11732026/10/06 09:19:29 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1174--- PASS: TestReadProxyNarinfo (0.55s)1175=== CONT TestGetExistingObjectsLocksRows11762026/10/06 09:19:29 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"1177--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.48s)1178--- PASS: TestReadProxyContentNegotiation (0.52s)1179=== CONT TestPushWaitsForSweepHoldingRow1180=== CONT TestConnectWaitsForAPeerMigration1181--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.50s)1182=== CONT TestResolveDBConnectionString1183=== RUN TestResolveDBConnectionString/flag_wins1184=== PAUSE TestResolveDBConnectionString/flag_wins1185=== RUN TestResolveDBConnectionString/file_when_flag_empty1186=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1187=== RUN TestResolveDBConnectionString/missing_file_is_an_error1188=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1189=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1190=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1191=== RUN TestResolveDBConnectionString/nothing_configured1192=== PAUSE TestResolveDBConnectionString/nothing_configured1193=== CONT TestPinProtectsFromGC11942026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=011952026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period11962026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures11972026/10/06 09:19:29 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=011982026/10/06 09:19:29 INFO Vacuumed table table=pending_closures11992026/10/06 09:19:29 INFO Vacuumed table table=pending_objects12002026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads12012026/10/06 09:19:29 INFO Vacuumed table table=closures12022026/10/06 09:19:29 INFO Vacuumed table table=objects12032026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=012042026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period12052026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures12062026/10/06 09:19:29 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=012072026/10/06 09:19:29 INFO Vacuumed table table=pending_closures12082026/10/06 09:19:29 INFO Vacuumed table table=pending_objects12092026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads12102026/10/06 09:19:29 INFO Vacuumed table table=closures12112026/10/06 09:19:29 INFO Vacuumed table table=objects1212--- PASS: TestSweepSkipsRowsLockedByPush (0.54s)1213=== CONT TestService_ReadScope_PublicByDefault12142026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=012152026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period12162026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures12172026/10/06 09:19:29 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=012182026/10/06 09:19:29 INFO Vacuumed table table=pending_closures12192026/10/06 09:19:29 INFO Vacuumed table table=pending_objects12202026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads12212026/10/06 09:19:29 INFO Vacuumed table table=closures12222026/10/06 09:19:29 INFO Vacuumed table table=objects1223--- PASS: TestGCSweepSkipsPendingObjects (0.53s)1224=== CONT TestClientFallsBackToClosures12252026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=012262026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=012272026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period12282026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period12292026/10/06 09:19:29 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=012302026/10/06 09:19:29 INFO Vacuumed table table=pending_closures12312026/10/06 09:19:29 INFO Vacuumed table table=pending_objects12322026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads12332026/10/06 09:19:29 INFO Vacuumed table table=closures12342026/10/06 09:19:29 INFO Vacuumed table table=objects12352026/10/06 09:19:29 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12362026/10/06 09:19:29 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1237--- PASS: TestGCMetrics (0.51s)1238=== CONT TestCacheStatsHandler1239--- PASS: TestFailedS3DeleteKeepsTombstone (0.58s)1240=== CONT TestClientCADerivations12412026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=012422026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period12432026/10/06 09:19:29 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=012442026/10/06 09:19:29 INFO Vacuumed table table=pending_closures12452026/10/06 09:19:29 INFO Vacuumed table table=pending_objects12462026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads12472026/10/06 09:19:29 INFO Vacuumed table table=closures12482026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures12492026/10/06 09:19:29 INFO Vacuumed table table=objects1250--- PASS: TestGCSweepDeliversEachKeyOnce (0.54s)1251=== CONT TestClientPushesUseOnePush1252--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.48s)1253=== CONT TestCacheConfigHandler1254=== RUN TestCacheConfigHandler/full_config,_no_issuer1255=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1256=== RUN TestCacheConfigHandler/no_cache_url_configured1257=== PAUSE TestCacheConfigHandler/no_cache_url_configured1258=== RUN TestCacheConfigHandler/no_signing_keys1259=== PAUSE TestCacheConfigHandler/no_signing_keys1260=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1261=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1262=== CONT TestClientIntegration12632026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures1264--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.49s)1265=== CONT TestClientErrorHandling1266=== RUN TestClientErrorHandling/InvalidStorePath1267=== PAUSE TestClientErrorHandling/InvalidStorePath1268=== RUN TestClientErrorHandling/InvalidAuthToken1269=== PAUSE TestClientErrorHandling/InvalidAuthToken1270=== RUN TestClientErrorHandling/ServerNotAvailable1271=== PAUSE TestClientErrorHandling/ServerNotAvailable1272=== CONT TestClientSharedPathCommittedMidPush1273=== NAME TestClientMultipleUploads1274 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads877476506/001/store/z73m1lnlyfh560mv44sqjbhpanhaa492-test-file-0.txt12752026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures12762026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures1277 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads877476506/001/store/v89q0dx3xrp702czd0a4algy3pmfcmp1-test-file-1.txt1278--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.71s)1279=== CONT TestLeadEndsOnShutdown1280=== NAME TestClientMultipleUploads1281 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads877476506/001/store/k7283nl9558pylyhndfskkd2kq7w767j-test-file-2.txt12822026/10/06 09:19:29 INFO lead: acquired remote=192.0.2.1:123412832026/10/06 09:19:29 INFO lead: released remote=192.0.2.1:12341284--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.52s)1285=== CONT TestService_ReadAuthMiddleware12862026/10/06 09:19:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12872026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=012882026/10/06 09:19:30 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=012892026/10/06 09:19:30 INFO Vacuumed table table=pending_closures12902026/10/06 09:19:30 INFO Vacuumed table table=pending_objects12912026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=012922026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads12932026/10/06 09:19:30 INFO Vacuumed table table=closures12942026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period12952026/10/06 09:19:30 INFO Vacuumed table table=objects12962026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=012972026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period12982026/10/06 09:19:30 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=012992026/10/06 09:19:30 INFO Vacuumed table table=pending_closures13002026/10/06 09:19:30 INFO Vacuumed table table=pending_objects13012026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads13022026/10/06 09:19:30 INFO Vacuumed table table=closures13032026/10/06 09:19:30 INFO Vacuumed table table=objects13042026/10/06 09:19:30 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=01305--- PASS: TestGCBugBareHashReferences (0.73s)1306=== CONT TestClientWithDependencies1307--- PASS: TestPushDedupSurvivesConcurrentGC (0.62s)1308=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13092026/10/06 09:19:30 INFO Vacuumed table table=pending_closures13102026/10/06 09:19:30 INFO Vacuumed table table=pending_objects13112026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads13122026/10/06 09:19:30 INFO Vacuumed table table=closures13132026/10/06 09:19:30 INFO Vacuumed table table=objects13142026/10/06 09:19:30 INFO lead: acquired remote=192.0.2.1:12341315--- PASS: TestSweepRechecksPendingAfterLocking (0.58s)1316=== CONT TestService_AuthMiddleware_OIDC13172026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes13182026/10/06 09:19:30 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13192026/10/06 09:19:30 INFO Uploading k7283nl9558pylyhndfskkd2kq7w767j-test-file-2.txt (160B)13202026/10/06 09:19:30 INFO Uploading v89q0dx3xrp702czd0a4algy3pmfcmp1-test-file-1.txt (160B)13212026/10/06 09:19:30 INFO Uploading z73m1lnlyfh560mv44sqjbhpanhaa492-test-file-0.txt (160B)13222026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13232026/10/06 09:19:30 WARN Failed to register uploaded object key=z73m1lnlyfh560mv44sqjbhpanhaa492.ls error="server returned 404: 404 page not found\n"13242026/10/06 09:19:30 WARN Failed to register uploaded object key=k7283nl9558pylyhndfskkd2kq7w767j.ls error="server returned 404: 404 page not found\n"13252026/10/06 09:19:30 WARN Failed to register uploaded object key=v89q0dx3xrp702czd0a4algy3pmfcmp1.ls error="server returned 404: 404 page not found\n"13262026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13272026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13282026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13292026/10/06 09:19:30 INFO Signed narinfos id=1 count=313302026/10/06 09:19:30 INFO Uploading 3 narinfos13312026/10/06 09:19:30 WARN Failed to register uploaded object key=k7283nl9558pylyhndfskkd2kq7w767j.narinfo error="server returned 404: 404 page not found\n"13322026/10/06 09:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete13332026/10/06 09:19:30 WARN Failed to register uploaded object key=z73m1lnlyfh560mv44sqjbhpanhaa492.narinfo error="server returned 404: 404 page not found\n"13342026/10/06 09:19:30 WARN Failed to register uploaded object key=v89q0dx3xrp702czd0a4algy3pmfcmp1.narinfo error="server returned 404: 404 page not found\n"13352026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=013362026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period13372026/10/06 09:19:30 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=013382026/10/06 09:19:30 INFO Upload complete. (67ms)1339=== NAME TestClientMultipleUploads1340 client_integration_test.go:369: Uploaded 3 paths in 104.968617ms13412026/10/06 09:19:30 INFO Vacuumed table table=pending_closures13422026/10/06 09:19:30 INFO Vacuumed table table=pending_objects13432026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads13442026/10/06 09:19:30 INFO Vacuumed table table=closures13452026/10/06 09:19:30 INFO Vacuumed table table=objects1346--- PASS: TestClientMultipleUploads (0.69s)1347=== CONT TestService_RequireScope_OIDC1348--- PASS: TestGetExistingObjectsLocksRows (0.51s)1349=== CONT TestService_AuthMiddleware_MTLSProxyHeader1350--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.57s)1351=== CONT TestParseSingleRange/none1352=== CONT TestParseSingleRange/open-ended1353=== CONT TestParseSingleRange/start_far_past_EOF1354=== CONT TestParseSingleRange/start_past_EOF1355=== CONT TestParseSingleRange/single_byte1356=== CONT TestParseSingleRange/suffix_exceeds_size1357=== CONT TestParseSingleRange/suffix1358=== CONT TestParseSingleRange/end_clamped_to_size1359=== CONT TestParseSingleRange/malformed_both_empty1360=== CONT TestParseSingleRange/closed1361=== CONT TestParseSingleRange/malformed_end_before_start1362=== CONT TestParseSingleRange/multi-range_ignored1363=== CONT TestParseSingleRange/malformed_no_dash1364=== CONT TestParseSingleRange/unknown_unit1365--- PASS: TestParseSingleRange (0.08s)1366 --- PASS: TestParseSingleRange/none (0.00s)1367 --- PASS: TestParseSingleRange/open-ended (0.00s)1368 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1369 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1370 --- PASS: TestParseSingleRange/single_byte (0.00s)1371 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1372 --- PASS: TestParseSingleRange/suffix (0.00s)1373 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1374 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1375 --- PASS: TestParseSingleRange/closed (0.00s)1376 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1377 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1378 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1379 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1380=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts13812026/10/06 09:19:30 INFO Received request for more parts method=POST path=/13822026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures1383--- PASS: TestService_ReadScope_PublicByDefault (0.44s)1384=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart13852026/10/06 09:19:30 INFO Received complete multipart upload request method=POST path=/1386=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure13872026/10/06 09:19:30 INFO Received uploads request method=POST path=/1388=== NAME TestPinProtectsFromGC1389 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC968176079/001/store/nx91ama5iglvbkj6z939kzsmij11anc0-pinned-file.txt1390 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC968176079/001/store/4hsqqqhny45lk3nlq775yflzng9qwxal-unpinned-file.txt13912026/10/06 09:19:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38477/oidc1392=== CONT TestServerTLSConfig/no_client_CA1393=== CONT TestServerTLSConfig/not_a_PEM_file1394=== CONT TestServerTLSConfig/missing_CA_file1395--- PASS: TestServerTLSConfig (0.00s)1396 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1397 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1398 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1399=== CONT TestPush_RejectsBadRequests/no_roots14002026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes1401=== CONT TestPush_RejectsBadRequests/bad_root14022026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes1403=== CONT TestPush_RejectsBadRequests/root_not_in_objects14042026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes1405=== CONT TestPush_RejectsBadRequests/no_objects14062026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes1407=== CONT TestIsValidCachePath/narinfo1408=== CONT TestIsValidCachePath/index.html1409--- PASS: TestPush_RejectsBadRequests (0.49s)1410 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1411 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1412 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1413 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1414=== CONT TestIsValidCachePath/short_hash1415=== CONT TestIsValidCachePath/wrong_extension1416=== CONT TestIsValidCachePath/leading_slash1417=== CONT TestIsValidCachePath/empty1418=== CONT TestIsValidCachePath/random_path1419=== CONT TestIsValidCachePath/invalid_char_u1420=== CONT TestIsValidCachePath/invalid_char_e1421=== CONT TestIsValidCachePath/traversal_in_middle1422=== CONT TestIsValidCachePath/traversal_parent1423=== CONT TestIsValidCachePath/nar_uncompressed1424=== CONT TestIsValidCachePath/nix-cache-info1425=== CONT TestIsValidCachePath/realisation1426=== CONT TestIsValidCachePath/log1427=== CONT TestIsValidCachePath/ls1428=== CONT TestIsValidCachePath/nar_xz1429=== CONT TestIsValidCachePath/nar_bz21430=== CONT TestIsValidCachePath/nar_zst1431=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1432--- PASS: TestIsValidCachePath (0.00s)1433 --- PASS: TestIsValidCachePath/narinfo (0.00s)1434 --- PASS: TestIsValidCachePath/index.html (0.00s)1435 --- PASS: TestIsValidCachePath/short_hash (0.00s)1436 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1437 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1438 --- PASS: TestIsValidCachePath/empty (0.00s)1439 --- PASS: TestIsValidCachePath/random_path (0.00s)1440 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1441 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1442 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1443 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1444 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1445 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1446 --- PASS: TestIsValidCachePath/realisation (0.00s)1447 --- PASS: TestIsValidCachePath/log (0.00s)1448 --- PASS: TestIsValidCachePath/ls (0.00s)1449 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1450 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1451 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1452 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1453=== CONT TestPendingClosureWriteTimeout/empty1454=== CONT TestPendingClosureWriteTimeout/670k_objects1455=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1456--- PASS: TestCacheStatsHandler (0.46s)1457=== CONT TestPendingClosureWriteTimeout/400_objects1458=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14592026/10/06 09:19:30 INFO Received uploads request method=POST path=/1460=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14612026/10/06 09:19:30 INFO Received complete multipart upload request method=POST path=/1462=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14632026/10/06 09:19:30 INFO Received request for more parts method=POST path=/1464=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14652026/10/06 09:19:30 INFO Received uploads request method=POST path=/1466--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1467 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1468 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1469 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1470 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1471=== CONT TestIsValidUploadKey/narinfo1472=== CONT TestIsValidUploadKey/realisation_plus_in_output1473=== CONT TestIsValidUploadKey/unknown_type1474=== CONT TestIsValidUploadKey/empty_key1475=== CONT TestIsValidUploadKey/absolute1476=== CONT TestIsValidUploadKey/traversal_nar1477=== CONT TestIsValidUploadKey/traversal1478=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1479=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1480=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1481=== CONT TestIsValidUploadKey/index.html1482=== CONT TestIsValidUploadKey/nix-cache-info1483=== CONT TestIsValidUploadKey/build_log_home-manager_file1484=== CONT TestIsValidUploadKey/realisation1485=== CONT TestIsValidUploadKey/build_log_equals1486=== CONT TestIsValidUploadKey/build_log_question_mark1487=== CONT TestIsValidUploadKey/build_log_plus_in_name1488=== CONT TestIsValidUploadKey/nar_plain1489=== CONT TestIsValidUploadKey/build_log1490=== CONT TestIsValidUploadKey/listing1491=== CONT TestIsValidUploadKey/nar_xz1492=== CONT TestIsValidUploadKey/nar_zst1493=== CONT TestProxyWriteTimeout/narinfo1494--- PASS: TestIsValidUploadKey (0.00s)1495 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1496 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1497 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1498 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1499 --- PASS: TestIsValidUploadKey/absolute (0.00s)1500 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1501 --- PASS: TestIsValidUploadKey/traversal (0.00s)1502 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1503 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1504 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1505 --- PASS: TestIsValidUploadKey/index.html (0.00s)1506 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1507 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1508 --- PASS: TestIsValidUploadKey/realisation (0.00s)1509 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1510 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1511 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1512 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1513 --- PASS: TestIsValidUploadKey/build_log (0.00s)1514 --- PASS: TestIsValidUploadKey/listing (0.00s)1515 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1516 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1517=== CONT TestProxyWriteTimeout/10_GiB_nar1518=== CONT TestProxyWriteTimeout/unknown_size1519=== CONT TestProxyWriteTimeout/1_GiB_nar1520--- PASS: TestProxyWriteTimeout (0.00s)1521 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1522 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1523 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1524 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1525=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows15262026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes15272026/10/06 09:19:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15282026/10/06 09:19:30 INFO Uploading nx91ama5iglvbkj6z939kzsmij11anc0-pinned-file.txt (128B)15292026/10/06 09:19:30 WARN Failed to register uploaded object key=nx91ama5iglvbkj6z939kzsmij11anc0.ls error="server returned 404: 404 page not found\n"15302026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15312026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1532=== NAME TestClientCADerivations1533 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1363099113/001/store/4g7z5fyn9pb31m0al6sjn1mf26jv89jy-ca-test15342026/10/06 09:19:30 INFO Signed narinfos id=1 count=115352026/10/06 09:19:30 INFO Uploading 1 narinfos15362026/10/06 09:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete15372026/10/06 09:19:30 WARN Failed to register uploaded object key=nx91ama5iglvbkj6z939kzsmij11anc0.narinfo error="server returned 404: 404 page not found\n"15382026/10/06 09:19:30 INFO Upload complete. (66ms)1539=== NAME TestClientIntegration1540 client_integration_test.go:286: Created store path: /build/TestClientIntegration3092878879/002/store/ldkccgy9i4kbd4rg3s7fnj03kqhvhd10-test-file.txt15412026/10/06 09:19:30 INFO lead: acquired remote=192.0.2.1:12341542=== NAME TestClientCADerivations1543 client_ca_test.go:139: Found 1 dependencies (including self)1544--- PASS: TestService_ReadAuthMiddleware (0.36s)1545=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15462026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures15472026/10/06 09:19:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40001/oidc1548--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.90s)1549=== CONT TestGCEndsOnShutdown/before_the_run15502026/10/06 09:19:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15512026/10/06 09:19:30 WARN mTLS auth: bound subjects configured but subject DN unavailable15522026/10/06 09:19:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1553--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)1554=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15552026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures15562026/10/06 09:19:30 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15572026/10/06 09:19:30 INFO Uploading prky0d2cihvxii5vh81d3czan2nzvp1m-b (216B)15582026/10/06 09:19:30 INFO Uploading 416cqr9kqd3l2rpj20kp88zz3c77k06l-shared-dep (136B)15592026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes15602026/10/06 09:19:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15612026/10/06 09:19:30 INFO Uploading 4hsqqqhny45lk3nlq775yflzng9qwxal-unpinned-file.txt (128B)15622026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/0ssky60byxwksh1zjk7rfnx9hjy1ksjjhh1m5q3jh0af3d0781px.nar.zst error="server returned 404: 404 page not found\n"15632026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes15642026/10/06 09:19:30 WARN Failed to register uploaded object key=prky0d2cihvxii5vh81d3czan2nzvp1m.ls error="server returned 404: 404 page not found\n"15652026/10/06 09:19:30 WARN Failed to register uploaded object key=416cqr9kqd3l2rpj20kp88zz3c77k06l.ls error="server returned 404: 404 page not found\n"15662026/10/06 09:19:30 WARN Failed to register uploaded object key=ipppd5mwcp4qijlsvsz3s844ssmpy63m.ls error="server returned 404: 404 page not found\n"15672026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15682026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15692026/10/06 09:19:30 INFO Signed narinfos id=1 count=215702026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15712026/10/06 09:19:30 INFO Signed narinfos id=2 count=215722026/10/06 09:19:30 WARN Failed to register uploaded object key=4hsqqqhny45lk3nlq775yflzng9qwxal.ls error="server returned 404: 404 page not found\n"15732026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15742026/10/06 09:19:30 INFO Uploading 4 narinfos15752026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15762026/10/06 09:19:30 INFO Signed narinfos id=2 count=115772026/10/06 09:19:30 INFO Uploading 1 narinfos15782026/10/06 09:19:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15792026/10/06 09:19:30 INFO Uploading ldkccgy9i4kbd4rg3s7fnj03kqhvhd10-test-file.txt (152B)15802026/10/06 09:19:30 INFO Received complete push request method=POST path=/api/pushes/2/complete15812026/10/06 09:19:30 WARN Failed to register uploaded object key=416cqr9kqd3l2rpj20kp88zz3c77k06l.narinfo error="server returned 404: 404 page not found\n"15822026/10/06 09:19:30 WARN Failed to register uploaded object key=prky0d2cihvxii5vh81d3czan2nzvp1m.narinfo error="server returned 404: 404 page not found\n"15832026/10/06 09:19:30 WARN Failed to register uploaded object key=4hsqqqhny45lk3nlq775yflzng9qwxal.narinfo error="server returned 404: 404 page not found\n"15842026/10/06 09:19:30 WARN Failed to register uploaded object key=ipppd5mwcp4qijlsvsz3s844ssmpy63m.narinfo error="server returned 404: 404 page not found\n"15852026/10/06 09:19:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15862026/10/06 09:19:30 WARN Failed to register uploaded object key=416cqr9kqd3l2rpj20kp88zz3c77k06l.narinfo error="server returned 404: 404 page not found\n"15872026/10/06 09:19:30 INFO Upload complete. (61ms)15882026/10/06 09:19:30 WARN Failed to register uploaded object key=ldkccgy9i4kbd4rg3s7fnj03kqhvhd10.ls error="server returned 404: 404 page not found\n"15892026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15902026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15912026/10/06 09:19:30 INFO Signed narinfos id=1 count=115922026/10/06 09:19:30 INFO Uploading 1 narinfos15932026/10/06 09:19:30 INFO Completed upload id=115942026/10/06 09:19:30 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15952026/10/06 09:19:30 INFO Completed upload id=215962026/10/06 09:19:30 INFO Upload complete. (83ms)1597=== NAME TestClientFallsBackToClosures1598 client_pushes_test.go:112: Retrieved narinfo from S3:1599 StorePath: /build/TestClientFallsBackToClosures2174120945/001/store/416cqr9kqd3l2rpj20kp88zz3c77k06l-shared-dep1600 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1601 Compression: zstd1602 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821603 NarSize: 1361604 References: 1605 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16062026/10/06 09:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete16072026/10/06 09:19:30 WARN Failed to register uploaded object key=ldkccgy9i4kbd4rg3s7fnj03kqhvhd10.narinfo error="server returned 404: 404 page not found\n"1608=== NAME TestOrphanedObjectsGCStressTest1609 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1610=== NAME TestClientFallsBackToClosures1611 client_pushes_test.go:112: Retrieved narinfo from S3:1612 StorePath: /build/TestClientFallsBackToClosures2174120945/001/store/ipppd5mwcp4qijlsvsz3s844ssmpy63m-a1613 URL: nar/0ssky60byxwksh1zjk7rfnx9hjy1ksjjhh1m5q3jh0af3d0781px.nar.zst1614 Compression: zstd1615 NarHash: sha256:0ssky60byxwksh1zjk7rfnx9hjy1ksjjhh1m5q3jh0af3d0781px1616 NarSize: 2161617 References: /build/TestClientFallsBackToClosures2174120945/001/store/416cqr9kqd3l2rpj20kp88zz3c77k06l-shared-dep1618 CA: text:sha256:0c53cv6z0zh2z0z6qf575lzyq24if47vs9szl24s1pzhzkhr0zr416192026/10/06 09:19:30 INFO Upload complete. (62ms)1620 client_pushes_test.go:112: Retrieved narinfo from S3:1621 StorePath: /build/TestClientFallsBackToClosures2174120945/001/store/prky0d2cihvxii5vh81d3czan2nzvp1m-b1622 URL: nar/0ssky60byxwksh1zjk7rfnx9hjy1ksjjhh1m5q3jh0af3d0781px.nar.zst1623 Compression: zstd1624 NarHash: sha256:0ssky60byxwksh1zjk7rfnx9hjy1ksjjhh1m5q3jh0af3d0781px1625 NarSize: 2161626 References: /build/TestClientFallsBackToClosures2174120945/001/store/416cqr9kqd3l2rpj20kp88zz3c77k06l-shared-dep1627 CA: text:sha256:0c53cv6z0zh2z0z6qf575lzyq24if47vs9szl24s1pzhzkhr0zr41628--- PASS: TestClientFallsBackToClosures (0.67s)1629=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1630--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.34s)1631=== CONT TestResolveDBConnectionString/flag_wins1632=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1633=== CONT TestResolveDBConnectionString/nothing_configured1634=== CONT TestResolveDBConnectionString/file_when_flag_empty1635=== CONT TestResolveDBConnectionString/missing_file_is_an_error1636=== CONT TestCacheConfigHandler/full_config,_no_issuer1637=== CONT TestCacheConfigHandler/no_signing_keys1638=== CONT TestCacheConfigHandler/no_cache_url_configured1639=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1640--- PASS: TestCacheConfigHandler (0.00s)1641 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1642 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1643 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1644 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1645--- PASS: TestResolveDBConnectionString (0.00s)1646 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1647 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1648 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1649 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1650 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1651=== CONT TestClientErrorHandling/InvalidStorePath16522026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes1653=== NAME TestOrphanedObjectsGCStressTest1654 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16552026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes16562026/10/06 09:19:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16572026/10/06 09:19:30 INFO Uploading 4g7z5fyn9pb31m0al6sjn1mf26jv89jy-ca-test (144B)16582026/10/06 09:19:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures16592026/10/06 09:19:30 INFO Garbage collection started16602026/10/06 09:19:30 WARN Failed to register uploaded object key=4g7z5fyn9pb31m0al6sjn1mf26jv89jy.ls error="server returned 404: 404 page not found\n"16612026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16622026/10/06 09:19:30 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16632026/10/06 09:19:30 INFO Uploading 6d4w5mp60rgv439raqdi926acyhm0zl7-shared-dep (136B)16642026/10/06 09:19:30 INFO Uploading g8fgk52w6p05pzhh2lsabcg440pn9jji-b (216B)16652026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16662026/10/06 09:19:30 WARN Failed to register uploaded object key=log/n7gq5fwa0sfnd9ql295spcdawyiqv0y1-ca-test.drv error="server returned 404: 404 page not found\n"16672026/10/06 09:19:30 INFO Signed narinfos id=1 count=116682026/10/06 09:19:30 INFO Uploading 1 narinfos16692026/10/06 09:19:30 INFO All 1 paths already cached16702026/10/06 09:19:30 WARN Failed to register uploaded object key=dqfp0fr9v26kc42gavipnxyjh3h9is4x.ls error="server returned 404: 404 page not found\n"16712026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16722026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/00npydxca591w53qqbk6n9d1hj6sm1bdnjrcfigrqphpyica186a.nar.zst error="server returned 404: 404 page not found\n"16732026/10/06 09:19:30 WARN Failed to register uploaded object key=6d4w5mp60rgv439raqdi926acyhm0zl7.ls error="server returned 404: 404 page not found\n"1674=== NAME TestClientIntegration1675 client_integration_test.go:312: Retrieved narinfo from S3:1676 StorePath: /build/TestClientIntegration3092878879/002/store/ldkccgy9i4kbd4rg3s7fnj03kqhvhd10-test-file.txt1677 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1678 Compression: zstd1679 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11680 NarSize: 1521681 References: 1682 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk116832026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16842026/10/06 09:19:30 WARN Failed to register uploaded object key=g8fgk52w6p05pzhh2lsabcg440pn9jji.ls error="server returned 404: 404 page not found\n"16852026/10/06 09:19:30 INFO Signed narinfos id=1 count=316862026/10/06 09:19:30 INFO Uploading 3 narinfos16872026/10/06 09:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete16882026/10/06 09:19:30 WARN Failed to register uploaded object key=4g7z5fyn9pb31m0al6sjn1mf26jv89jy.narinfo error="server returned 404: 404 page not found\n"1689 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1690 client_integration_test.go:313: Decompressed .ls content (64 bytes):1691 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1692 client_integration_test.go:316: Testing garbage collection...16932026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=016942026/10/06 09:19:30 WARN Failed to register uploaded object key=g8fgk52w6p05pzhh2lsabcg440pn9jji.narinfo error="server returned 404: 404 page not found\n"16952026/10/06 09:19:30 WARN Failed to register uploaded object key=6d4w5mp60rgv439raqdi926acyhm0zl7.narinfo error="server returned 404: 404 page not found\n"16962026/10/06 09:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete16972026/10/06 09:19:30 WARN Failed to register uploaded object key=dqfp0fr9v26kc42gavipnxyjh3h9is4x.narinfo error="server returned 404: 404 page not found\n"16982026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes16992026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures17002026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period17012026/10/06 09:19:30 INFO Upload complete. (100ms)17022026/10/06 09:19:30 INFO Upload complete. (65ms)17032026/10/06 09:19:30 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17042026/10/06 09:19:30 INFO Uploading whd76zbh97ragxcalpix75az0i7zychs-shared-dep (136B)17052026/10/06 09:19:30 INFO Uploading 25bzvlfgglmij41d4p1br00vk6922z6w-top (224B)1706=== NAME TestClientPushesUseOnePush1707 client_pushes_test.go:97: Retrieved narinfo from S3:1708 StorePath: /build/TestClientPushesUseOnePush3240250477/001/store/6d4w5mp60rgv439raqdi926acyhm0zl7-shared-dep1709 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1710 Compression: zstd1711 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821712 NarSize: 1361713 References: 1714 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1715=== NAME TestClientCADerivations1716 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1363099113/001/store/4g7z5fyn9pb31m0al6sjn1mf26jv89jy-ca-test1717 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1718 Compression: zstd1719 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1720 NarSize: 1441721 References: 1722 Deriver: /build/TestClientCADerivations1363099113/001/store/n7gq5fwa0sfnd9ql295spcdawyiqv0y1-ca-test.drv1723 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1724 client_ca_test.go:185: Checking for realisation files in S3...1725=== NAME TestClientPushesUseOnePush1726 client_pushes_test.go:97: Retrieved narinfo from S3:1727 StorePath: /build/TestClientPushesUseOnePush3240250477/001/store/dqfp0fr9v26kc42gavipnxyjh3h9is4x-a1728 URL: nar/00npydxca591w53qqbk6n9d1hj6sm1bdnjrcfigrqphpyica186a.nar.zst1729 Compression: zstd1730 NarHash: sha256:00npydxca591w53qqbk6n9d1hj6sm1bdnjrcfigrqphpyica186a1731 NarSize: 2161732 References: /build/TestClientPushesUseOnePush3240250477/001/store/6d4w5mp60rgv439raqdi926acyhm0zl7-shared-dep1733 CA: text:sha256:0j06yj0x3sszrhby411ssa9ndhf7ynfsnxdblzaw2i7yv7kn0nss1734=== NAME TestClientCADerivations1735 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1736 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17372026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/1z8rpmg2bm19r0c1b7jwi1lfgl7x7ils7wz2ylk8dn22lnhqsdhy.nar.zst error="server returned 404: 404 page not found\n"17382026/10/06 09:19:30 WARN Failed to register uploaded object key=whd76zbh97ragxcalpix75az0i7zychs.ls error="server returned 404: 404 page not found\n"17392026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17402026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17412026/10/06 09:19:30 WARN Failed to register uploaded object key=25bzvlfgglmij41d4p1br00vk6922z6w.ls error="server returned 404: 404 page not found\n"17422026/10/06 09:19:30 INFO Signed narinfos id=1 count=217432026/10/06 09:19:30 INFO Uploading 2 narinfos1744=== NAME TestClientPushesUseOnePush1745 client_pushes_test.go:97: Retrieved narinfo from S3:1746 StorePath: /build/TestClientPushesUseOnePush3240250477/001/store/g8fgk52w6p05pzhh2lsabcg440pn9jji-b1747 URL: nar/00npydxca591w53qqbk6n9d1hj6sm1bdnjrcfigrqphpyica186a.nar.zst1748 Compression: zstd1749 NarHash: sha256:00npydxca591w53qqbk6n9d1hj6sm1bdnjrcfigrqphpyica186a1750 NarSize: 2161751 References: /build/TestClientPushesUseOnePush3240250477/001/store/6d4w5mp60rgv439raqdi926acyhm0zl7-shared-dep1752 CA: text:sha256:0j06yj0x3sszrhby411ssa9ndhf7ynfsnxdblzaw2i7yv7kn0nss17532026/10/06 09:19:30 WARN Failed to register uploaded object key=whd76zbh97ragxcalpix75az0i7zychs.narinfo error="server returned 404: 404 page not found\n"17542026/10/06 09:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete17552026/10/06 09:19:30 WARN Failed to register uploaded object key=25bzvlfgglmij41d4p1br00vk6922z6w.narinfo error="server returned 404: 404 page not found\n"1756--- PASS: TestClientPushesUseOnePush (0.64s)1757=== CONT TestClientErrorHandling/InvalidAuthToken17582026/10/06 09:19:30 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=017592026/10/06 09:19:30 INFO Upload complete. (65ms)1760=== NAME TestClientSharedPathCommittedMidPush1761 client_integration_test.go:680: Retrieved narinfo from S3:1762 StorePath: /build/TestClientSharedPathCommittedMidPush244359666/001/store/whd76zbh97ragxcalpix75az0i7zychs-shared-dep1763 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1764 Compression: zstd1765 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821766 NarSize: 1361767 References: 1768 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17692026/10/06 09:19:30 INFO Vacuumed table table=pending_closures1770=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1771=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1772=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1773=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1774=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1775=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1776=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1777=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1778=== CONT TestClientErrorHandling/ServerNotAvailable1779=== NAME TestClientSharedPathCommittedMidPush1780 client_integration_test.go:680: Retrieved narinfo from S3:1781 StorePath: /build/TestClientSharedPathCommittedMidPush244359666/001/store/25bzvlfgglmij41d4p1br00vk6922z6w-top17822026/10/06 09:19:30 INFO Vacuumed table table=pending_objects1783 URL: nar/1z8rpmg2bm19r0c1b7jwi1lfgl7x7ils7wz2ylk8dn22lnhqsdhy.nar.zst1784 Compression: zstd1785 NarHash: sha256:1z8rpmg2bm19r0c1b7jwi1lfgl7x7ils7wz2ylk8dn22lnhqsdhy1786 NarSize: 2241787 References: /build/TestClientSharedPathCommittedMidPush244359666/001/store/whd76zbh97ragxcalpix75az0i7zychs-shared-dep1788 CA: text:sha256:1lwnvy0i2kbhmc7z6s9q4p1rfzc5by12j57yj019rcgjmfcppa8d17892026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads17902026/10/06 09:19:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures17912026/10/06 09:19:30 INFO Garbage collection started17922026/10/06 09:19:30 INFO Vacuumed table table=closures1793--- PASS: TestClientSharedPathCommittedMidPush (0.60s)1794=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token17952026/10/06 09:19:30 INFO Vacuumed table table=objects1796=== NAME TestClientWithDependencies1797 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1755887840/001/store/yf8bdlm1pz8snknn0wwrha40pq31kdb9-test-script1798=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17992026/10/06 09:19:30 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]1800=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1801=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18022026/10/06 09:19:30 WARN Authentication failed token_preview=eyJhbGciOi...3ue5_pmyHA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1803--- PASS: TestService_AuthMiddleware_OIDC (0.43s)1804 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1805 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1806 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1807 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18082026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=018092026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period18102026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures18112026/10/06 09:19:30 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=018122026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=018132026/10/06 09:19:30 INFO Vacuumed table table=pending_closures18142026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period18152026/10/06 09:19:30 INFO Vacuumed table table=pending_objects18162026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads18172026/10/06 09:19:30 INFO Vacuumed table table=closures1818=== NAME TestClientWithDependencies1819 client_integration_test.go:615: Found 1 dependencies (including self)18202026/10/06 09:19:30 INFO Vacuumed table table=objects18212026/10/06 09:19:30 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=018222026/10/06 09:19:30 INFO Vacuumed table table=pending_closures18232026/10/06 09:19:30 INFO Vacuumed table table=pending_objects18242026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads18252026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures18262026/10/06 09:19:30 INFO Vacuumed table table=closures18272026/10/06 09:19:30 INFO Vacuumed table table=objects18282026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=018292026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period18302026/10/06 09:19:30 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/present18312026/10/06 09:19:30 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=018322026/10/06 09:19:30 INFO Vacuumed table table=pending_closures18332026/10/06 09:19:30 INFO Vacuumed table table=pending_objects18342026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads18352026/10/06 09:19:30 INFO Vacuumed table table=closures18362026/10/06 09:19:30 INFO Vacuumed table table=objects1837=== NAME TestClientCADerivations1838 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1839 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1840 error: binary cache 's3://bucket73?endpoint=http://localhost:43923&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1363099113/001/store'1841 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11842--- PASS: TestClientCADerivations (0.79s)1843=== RUN TestService_RequireScope_OIDC/builder_may_write1844=== PAUSE TestService_RequireScope_OIDC/builder_may_write1845=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1846=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1847=== RUN TestService_RequireScope_OIDC/ops_may_admin1848=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1849=== RUN TestService_RequireScope_OIDC/ops_may_not_write1850=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1851=== RUN TestService_RequireScope_OIDC/reader_may_not_write1852=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1853=== RUN TestService_RequireScope_OIDC/static_token_may_admin1854=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1855=== RUN TestService_RequireScope_OIDC/static_token_may_write1856=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1857=== RUN TestService_RequireScope_OIDC/reader_may_read1858=== PAUSE TestService_RequireScope_OIDC/reader_may_read1859=== RUN TestService_RequireScope_OIDC/writer_implies_read1860=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1861=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1862=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1863=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1864=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1865=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1866=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1867=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1868=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1869=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1870=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1871=== CONT TestService_RequireScope_OIDC/builder_may_write1872=== CONT TestService_RequireScope_OIDC/reader_may_read1873=== CONT TestService_RequireScope_OIDC/reader_may_not_write1874=== CONT TestService_RequireScope_OIDC/static_token_may_write1875=== CONT TestService_RequireScope_OIDC/static_token_may_admin1876=== CONT TestService_RequireScope_OIDC/ops_may_admin1877=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1878--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1879 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.32s)1880 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.23s)1881=== CONT TestService_RequireScope_OIDC/writer_implies_read1882=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1883=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1884=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1885=== CONT TestService_RequireScope_OIDC/ops_may_not_write18862026/10/06 09:19:30 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]1887=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1888=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1889--- PASS: TestService_RequireScope_OIDC (0.48s)1890 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1891 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1892 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1893 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1894 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1895 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1896 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1897 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1898 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1899 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1900 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1901 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1902 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19042026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=019052026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period19062026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes1907--- PASS: TestPushWaitsForSweepHoldingRow (1.00s)19082026/10/06 09:19:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19092026/10/06 09:19:30 INFO Uploading yf8bdlm1pz8snknn0wwrha40pq31kdb9-test-script (136B)19102026/10/06 09:19:30 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:43923/bucket89/?delete=\": context canceled"19112026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19122026/10/06 09:19:30 WARN Failed to register uploaded object key=log/h7h6sa6944cigp1qw7rhxlj7zd7jbqng-test-script.drv error="server returned 404: 404 page not found\n"19132026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19142026/10/06 09:19:30 WARN Failed to register uploaded object key=yf8bdlm1pz8snknn0wwrha40pq31kdb9.ls error="server returned 404: 404 page not found\n"19152026/10/06 09:19:30 INFO Signed narinfos id=1 count=119162026/10/06 09:19:30 INFO Uploading 1 narinfos19172026/10/06 09:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete19182026/10/06 09:19:30 WARN Failed to register uploaded object key=yf8bdlm1pz8snknn0wwrha40pq31kdb9.narinfo error="server returned 404: 404 page not found\n"19192026/10/06 09:19:30 INFO Upload complete. (56ms)19202026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=01921=== NAME TestClientWithDependencies1922 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1755887840/001/store) requires matching store prefix19232026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period1924--- PASS: TestClientWithDependencies (0.59s)19252026-10-06 09:19:30.628 UTC [1763] ERROR: canceling statement due to user request19262026-10-06 09:19:30.628 UTC [1763] CONTEXT: SQL statement "UPDATE object_stats1927 SET object_count = object_count + d_count,1928 total_bytes = total_bytes + d_bytes1929 WHERE id"1930 PL/pgSQL function object_stats_apply() line 17 at SQL statement19312026-10-06 09:19:30.628 UTC [1763] STATEMENT: -- name: MarkStaleObjects :execrows1932 WITH RECURSIVE ct AS (1933 SELECT timezone('UTC', now()) AS now1934 ),1935 closure_reach AS (1936 -- Start with all closure keys1937 SELECT o.key, o.refs1938 FROM objects o1939 INNER JOIN closures c ON o.key = c.key1940 UNION1941 -- Recursively add all referenced objects1942 SELECT o.key, o.refs1943 FROM objects o1944 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1945 ),1946 reachable_objects AS (1947 SELECT DISTINCT key FROM closure_reach1948 ),1949 stale_objects AS (1950 SELECT o.key1951 FROM objects AS o, ct1952 WHERE1953 NOT EXISTS (1954 SELECT 11955 FROM reachable_objects ro1956 WHERE ro.key = o.key1957 )1958 AND NOT EXISTS (1959 SELECT 11960 FROM pending_objects AS po1961 WHERE po.key = o.key1962 )1963 AND o.deleted_at IS NULL -- Only mark fresh objects1964 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1965 FOR UPDATE1966 )1967 UPDATE objects1968 SET1969 deleted_at = ct.now,1970 first_deleted_at = COALESCE(first_deleted_at, ct.now)1971 FROM stale_objects, ct1972 WHERE objects.key = stale_objects.key1973 1974--- PASS: TestGCEndsOnShutdown (0.00s)1975 --- PASS: TestGCEndsOnShutdown/before_the_run (0.22s)1976 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.25s)1977 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.23s)19782026/10/06 09:19:30 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.329154ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19792026/10/06 09:19:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1980=== NAME TestOrphanedObjectsGCStressTest1981 orphaned_objects_gc_test.go:509: Stress test completed successfully:1982 orphaned_objects_gc_test.go:510: - Active objects preserved: 201983 orphaned_objects_gc_test.go:511: - Objects deleted: 2101984 orphaned_objects_gc_test.go:512: - Total GC'd: 2101985--- PASS: TestOrphanedObjectsGCStressTest (2.51s)19862026/10/06 09:19:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19872026/10/06 09:19:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=379.64959ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1988--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1989 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1990 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1991 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.95s)19922026/10/06 09:19:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=866.266123ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19932026/10/06 09:19:31 INFO lead: released remote=192.0.2.1:12341994--- PASS: TestPendingClosureWriteTimeout (0.00s)1995 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1996 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1997 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1998 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.05s)19992026/10/06 09:19:31 INFO lead: acquired remote=192.0.2.1:123420002026/10/06 09:19:31 INFO lead: released remote=192.0.2.1:12342001--- PASS: TestLeadEndsOnShutdown (1.43s)20022026/10/06 09:19:32 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.717632671s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20032026/10/06 09:19:32 INFO lead: released remote=192.0.2.1:12342004--- PASS: TestLeadElectsOneAndHandsOver (2.84s)20052026/10/06 09:19:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020062026/10/06 09:19:32 INFO Received create pin request method=POST path=/api/pins/myapp20072026/10/06 09:19:32 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC968176079/001/store/nx91ama5iglvbkj6z939kzsmij11anc0-pinned-file.txt narinfo_key=nx91ama5iglvbkj6z939kzsmij11anc0.narinfo20082026/10/06 09:19:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures20092026/10/06 09:19:32 INFO Garbage collection started20102026/10/06 09:19:32 INFO Aborted multipart uploads count=0 kept=020112026/10/06 09:19:32 WARN Force mode enabled - objects will be deleted immediately without grace period20122026/10/06 09:19:32 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=020132026/10/06 09:19:32 INFO Vacuumed table table=pending_closures20142026/10/06 09:19:32 INFO Vacuumed table table=pending_objects20152026/10/06 09:19:32 INFO Vacuumed table table=multipart_uploads20162026/10/06 09:19:32 INFO Vacuumed table table=closures20172026/10/06 09:19:32 INFO Vacuumed table table=objects20182026/10/06 09:19:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02019=== NAME TestClientIntegration2020 client_integration_test.go:323: Objects in database after GC:2021 client_integration_test.go:323: Successfully deleted all objects with GC --force2022--- PASS: TestClientIntegration (2.65s)2023--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.70s)20242026/10/06 09:19:33 WARN Rate limiter enabled after throttle name=s3-test rate=520252026/10/06 09:19:33 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2026=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2027 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102028 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002029--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.37s)20302026/10/06 09:19:33 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-config20312026/10/06 09:19:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.694681ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20322026/10/06 09:19:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=365.072617ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2033=== NAME TestPinProtectsFromGC2034 client_integration_test.go:840: Pin successfully protected closure from garbage collection2035--- PASS: TestPinProtectsFromGC (4.83s)20362026/10/06 09:19:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=875.247483ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2037--- PASS: TestConnectWaitsForAPeerMigration (5.14s)20382026/10/06 09:19:34 INFO Aborted multipart uploads count=1 kept=020392026/10/06 09:19:34 INFO Received cleanup request method=DELETE path=/api/pending_closures20402026/10/06 09:19:34 INFO Aborted multipart uploads count=1 kept=02041--- PASS: TestPendingCleanupUsesOneCutoff (6.64s)20422026/10/06 09:19:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.629484613s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20432026/10/06 09:19:37 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"20442026/10/06 09:19:37 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-config20452026/10/06 09:19:37 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.808546ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20462026/10/06 09:19:37 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.175701ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20472026/10/06 09:19:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=863.796397ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20482026/10/06 09:19:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.721808294s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20492026/10/06 09:19:40 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_closures20502026/10/06 09:19:40 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.548252ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20512026/10/06 09:19:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.960447ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20522026/10/06 09:19:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=824.589945ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20532026/10/06 09:19:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.468788343s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2054--- PASS: TestClientErrorHandling (0.00s)2055 --- PASS: TestClientErrorHandling/InvalidStorePath (0.24s)2056 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.29s)2057 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.82s)2058PASS20592026-10-06 09:19:43.535 UTC [129] LOG: received smart shutdown request20602026-10-06 09:19:43.538 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120612026-10-06 09:19:43.550 UTC [134] LOG: shutting down20622026-10-06 09:19:43.551 UTC [134] LOG: checkpoint starting: shutdown immediate20632026-10-06 09:19:45.394 UTC [134] LOG: checkpoint complete: wrote 10359 buffers (63.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.195 s, sync=1.618 s, total=1.844 s; sync files=31336, longest=0.002 s, average=0.001 s; distance=433077 kB, estimate=433077 kB; lsn=0/1BE53118, redo lsn=0/1BE5311820642026-10-06 09:19:45.471 UTC [129] LOG: database system is shut down2065Running OIDC tests...2066=== RUN TestAudienceForIssuer2067=== PAUSE TestAudienceForIssuer2068=== RUN TestGlobMatch2069=== PAUSE TestGlobMatch2070=== RUN TestValidateToken_ValidToken2071=== PAUSE TestValidateToken_ValidToken2072=== RUN TestValidateToken_WrongAudience2073=== PAUSE TestValidateToken_WrongAudience2074=== RUN TestValidateToken_Expired2075=== PAUSE TestValidateToken_Expired2076=== RUN TestValidateToken_BoundClaimsMismatch2077=== PAUSE TestValidateToken_BoundClaimsMismatch2078=== RUN TestValidateToken_BoundSubjectMismatch2079=== PAUSE TestValidateToken_BoundSubjectMismatch2080=== RUN TestValidateToken_MultipleProviders2081=== PAUSE TestValidateToken_MultipleProviders2082=== RUN TestValidateToken_NoMatchingProvider2083=== PAUSE TestValidateToken_NoMatchingProvider2084=== RUN TestValidateToken_KubernetesServiceAccount2085=== PAUSE TestValidateToken_KubernetesServiceAccount2086=== RUN TestNewValidator_KubernetesRequiresCA2087=== PAUSE TestNewValidator_KubernetesRequiresCA2088=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2089=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2090=== RUN TestPins_ReservedForMatchingRule2091=== PAUSE TestPins_ReservedForMatchingRule2092=== RUN TestPins_TopLevelShorthand2093=== PAUSE TestPins_TopLevelShorthand2094=== RUN TestPins_ConfigValidation2095=== PAUSE TestPins_ConfigValidation2096=== RUN TestScopes_LegacyProviderDefaultsToWrite2097=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2098=== RUN TestScopes_Rules2099=== PAUSE TestScopes_Rules2100=== RUN TestScopes_ConfigValidation2101=== PAUSE TestScopes_ConfigValidation2102=== CONT TestAudienceForIssuer2103=== CONT TestValidateToken_KubernetesServiceAccount2104=== CONT TestValidateToken_BoundClaimsMismatch2105--- PASS: TestAudienceForIssuer (0.00s)2106=== CONT TestValidateToken_ValidToken2107=== CONT TestGlobMatch2108=== RUN TestGlobMatch/foo_foo2109=== CONT TestPins_ConfigValidation2110=== CONT TestScopes_ConfigValidation2111=== CONT TestScopes_Rules2112=== CONT TestScopes_LegacyProviderDefaultsToWrite2113=== CONT TestValidateToken_Expired2114=== CONT TestPins_ReservedForMatchingRule2115=== CONT TestPins_TopLevelShorthand2116--- PASS: TestPins_ConfigValidation (0.00s)2117=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2118=== CONT TestValidateToken_MultipleProviders2119--- PASS: TestScopes_ConfigValidation (0.00s)2120=== CONT TestValidateToken_NoMatchingProvider2121=== CONT TestValidateToken_BoundSubjectMismatch2122=== CONT TestNewValidator_KubernetesRequiresCA2123=== CONT TestValidateToken_WrongAudience2124=== PAUSE TestGlobMatch/foo_foo2125=== RUN TestGlobMatch/foo_bar2126=== PAUSE TestGlobMatch/foo_bar2127=== RUN TestGlobMatch/*_2128=== PAUSE TestGlobMatch/*_2129=== RUN TestGlobMatch/*_anything2130=== PAUSE TestGlobMatch/*_anything2131=== RUN TestGlobMatch/foo*_foo2132=== PAUSE TestGlobMatch/foo*_foo2133=== RUN TestGlobMatch/foo*_foobar2134=== PAUSE TestGlobMatch/foo*_foobar2135=== RUN TestGlobMatch/foo*_bar2136=== PAUSE TestGlobMatch/foo*_bar2137=== RUN TestGlobMatch/*bar_bar2138=== PAUSE TestGlobMatch/*bar_bar2139=== RUN TestGlobMatch/*bar_foobar2140=== PAUSE TestGlobMatch/*bar_foobar2141=== RUN TestGlobMatch/*bar_foo2142=== PAUSE TestGlobMatch/*bar_foo2143=== RUN TestGlobMatch/foo*bar_foobar2144=== PAUSE TestGlobMatch/foo*bar_foobar2145=== RUN TestGlobMatch/foo*bar_foo123bar2146=== PAUSE TestGlobMatch/foo*bar_foo123bar2147=== RUN TestGlobMatch/foo*bar_foobarbaz2148=== PAUSE TestGlobMatch/foo*bar_foobarbaz2149=== RUN TestGlobMatch/*/*_foo/bar2150=== PAUSE TestGlobMatch/*/*_foo/bar2151=== RUN TestGlobMatch/*/*_foo2152=== PAUSE TestGlobMatch/*/*_foo2153=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2154=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2155=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02156=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02157=== RUN TestGlobMatch/refs/*/main_refs/heads/main2158=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2159=== RUN TestGlobMatch/fo?_foo2160=== PAUSE TestGlobMatch/fo?_foo2161=== RUN TestGlobMatch/fo?_fo2162=== PAUSE TestGlobMatch/fo?_fo2163=== RUN TestGlobMatch/fo?_fooo2164=== PAUSE TestGlobMatch/fo?_fooo2165=== RUN TestGlobMatch/?oo_foo2166=== PAUSE TestGlobMatch/?oo_foo2167=== RUN TestGlobMatch/?oo_boo2168=== PAUSE TestGlobMatch/?oo_boo2169=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2170=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2171=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2172=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2173=== CONT TestGlobMatch/foo_foo2174=== CONT TestGlobMatch/?oo_foo2175=== CONT TestGlobMatch/fo?_fooo2176=== CONT TestGlobMatch/fo?_fo2177=== CONT TestGlobMatch/fo?_foo2178=== CONT TestGlobMatch/refs/*/main_refs/heads/main2179=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02180=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2181=== CONT TestGlobMatch/*/*_foo2182=== CONT TestGlobMatch/*/*_foo/bar2183=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2184=== CONT TestGlobMatch/foo*_foo2185=== CONT TestGlobMatch/*_anything2186=== CONT TestGlobMatch/*_2187=== CONT TestGlobMatch/foo_bar2188=== CONT TestGlobMatch/?oo_boo2189=== CONT TestGlobMatch/foo*bar_foobarbaz2190=== CONT TestGlobMatch/foo*bar_foo123bar2191=== CONT TestGlobMatch/foo*bar_foobar2192=== CONT TestGlobMatch/*bar_foo2193=== CONT TestGlobMatch/*bar_foobar2194=== CONT TestGlobMatch/*bar_bar2195=== CONT TestGlobMatch/foo*_bar2196=== CONT TestGlobMatch/foo*_foobar2197=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2198--- PASS: TestGlobMatch (0.01s)2199 --- PASS: TestGlobMatch/foo_foo (0.00s)2200 --- PASS: TestGlobMatch/?oo_foo (0.00s)2201 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2202 --- PASS: TestGlobMatch/fo?_fo (0.00s)2203 --- PASS: TestGlobMatch/fo?_foo (0.00s)2204 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2205 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2206 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2207 --- PASS: TestGlobMatch/*/*_foo (0.00s)2208 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2209 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2210 --- PASS: TestGlobMatch/foo*_foo (0.00s)2211 --- PASS: TestGlobMatch/*_anything (0.00s)2212 --- PASS: TestGlobMatch/*_ (0.00s)2213 --- PASS: TestGlobMatch/foo_bar (0.00s)2214 --- PASS: TestGlobMatch/?oo_boo (0.00s)2215 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2216 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2217 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2218 --- PASS: TestGlobMatch/*bar_foo (0.00s)2219 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2220 --- PASS: TestGlobMatch/*bar_bar (0.00s)2221 --- PASS: TestGlobMatch/foo*_bar (0.00s)2222 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2223 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)22242026/10/06 09:19:47 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322252026/10/06 09:19:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45435/oidc22262026/10/06 09:19:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33099/oidc22272026/10/06 09:19:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46473/oidc2228--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)2229--- PASS: TestValidateToken_ValidToken (0.06s)2230--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)2231--- PASS: TestValidateToken_WrongAudience (0.06s)22322026/10/06 09:19:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39209/oidc22332026/10/06 09:19:47 http: TLS handshake error from 127.0.0.1:35566: remote error: tls: bad certificate2234--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)2235--- PASS: TestScopes_Rules (0.10s)22362026/10/06 09:19:47 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:338832237--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)22382026/10/06 09:19:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41599/oidc22392026/10/06 09:19:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35543/oidc2240--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.14s)2241--- PASS: TestValidateToken_BoundClaimsMismatch (0.14s)22422026/10/06 09:19:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41385/oidc2243--- PASS: TestValidateToken_Expired (0.17s)22442026/10/06 09:19:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33861/oidc2245--- PASS: TestPins_TopLevelShorthand (0.26s)22462026/10/06 09:19:47 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38121/oidc22472026/10/06 09:19:47 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33393/oidc2248--- PASS: TestValidateToken_MultipleProviders (0.31s)22492026/10/06 09:19:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35995/oidc2250--- PASS: TestPins_ReservedForMatchingRule (0.33s)22512026/10/06 09:19:47 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46205/oidc2252--- PASS: TestValidateToken_NoMatchingProvider (0.51s)2253PASS2254Running hook tests...2255=== RUN TestSendPathsEmpty2256=== PAUSE TestSendPathsEmpty2257=== RUN TestQueueEnqueueAndFetch2258=== PAUSE TestQueueEnqueueAndFetch2259=== RUN TestQueueDeduplication2260=== PAUSE TestQueueDeduplication2261=== RUN TestQueueRemove2262=== PAUSE TestQueueRemove2263=== RUN TestQueueFetchBatchLimit2264=== PAUSE TestQueueFetchBatchLimit2265=== RUN TestQueueRetryMovesToBack2266=== PAUSE TestQueueRetryMovesToBack2267=== RUN TestQueueFetchRemoveLifecycle2268=== PAUSE TestQueueFetchRemoveLifecycle2269=== RUN TestQueueConcurrentWriters2270=== PAUSE TestQueueConcurrentWriters2271=== RUN TestQueueRemoveLargeClosure2272=== PAUSE TestQueueRemoveLargeClosure2273=== RUN TestServerClientIntegration2274=== PAUSE TestServerClientIntegration2275=== RUN TestServerQueueError2276=== PAUSE TestServerQueueError2277=== RUN TestGetListenerSocketActivation2278 server_test.go:210: === RUN TestGetListenerSocketActivation2279 --- PASS: TestGetListenerSocketActivation (0.00s)2280 PASS2281 2282--- PASS: TestGetListenerSocketActivation (0.01s)2283=== RUN TestDrainIsolatesPoisonPath2284=== PAUSE TestDrainIsolatesPoisonPath2285=== RUN TestRunNotBlockedByPoisonHead2286=== PAUSE TestRunNotBlockedByPoisonHead2287=== RUN TestDrainGivesUpWhenServerDown2288=== PAUSE TestDrainGivesUpWhenServerDown2289=== RUN TestFailedPathPrunedByLaterClosure2290=== PAUSE TestFailedPathPrunedByLaterClosure2291=== RUN TestWorkerUploadsAndRemoves2292=== PAUSE TestWorkerUploadsAndRemoves2293=== RUN TestWorkerSkipsGCdPaths2294=== PAUSE TestWorkerSkipsGCdPaths2295=== RUN TestWorkerPrunesClosureDeps2296=== PAUSE TestWorkerPrunesClosureDeps2297=== RUN TestDrainTimeout2298=== PAUSE TestDrainTimeout2299=== CONT TestSendPathsEmpty2300--- PASS: TestSendPathsEmpty (0.00s)2301=== CONT TestWorkerSkipsGCdPaths2302=== CONT TestQueueRemoveLargeClosure2303=== CONT TestQueueFetchBatchLimit2304=== CONT TestDrainTimeout2305=== CONT TestRunNotBlockedByPoisonHead2306=== CONT TestWorkerUploadsAndRemoves2307=== CONT TestFailedPathPrunedByLaterClosure2308=== CONT TestDrainGivesUpWhenServerDown2309=== CONT TestQueueFetchRemoveLifecycle2310=== CONT TestQueueConcurrentWriters2311=== CONT TestQueueDeduplication2312=== CONT TestQueueRemove2313=== CONT TestQueueEnqueueAndFetch2314=== CONT TestServerQueueError2315=== CONT TestDrainIsolatesPoisonPath2316=== CONT TestServerClientIntegration2317=== CONT TestQueueRetryMovesToBack2318=== CONT TestWorkerPrunesClosureDeps23192026/10/06 09:19:47 ERROR Failed to queue paths error="permission denied" count=12320--- PASS: TestServerQueueError (0.00s)2321--- PASS: TestServerClientIntegration (0.00s)23222026/10/06 09:19:47 INFO Uploading batch count=123232026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=123242026/10/06 09:19:47 INFO Upload queue status pending=223252026/10/06 09:19:47 INFO Upload queue status pending=323262026/10/06 09:19:47 INFO Uploading batch count=223272026/10/06 09:19:47 INFO Uploading batch count=22328--- PASS: TestQueueEnqueueAndFetch (0.01s)23292026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=223302026/10/06 09:19:47 INFO Uploading batch count=123312026/10/06 09:19:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4129654746/002/a23322026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=123332026/10/06 09:19:47 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3356844680/002/nonexistent23342026/10/06 09:19:47 INFO Uploading batch count=123352026/10/06 09:19:47 INFO Upload queue status pending=223362026/10/06 09:19:47 INFO Uploading batch count=423372026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=42338--- PASS: TestQueueFetchBatchLimit (0.02s)23392026/10/06 09:19:47 INFO Uploading batch count=123402026/10/06 09:19:47 INFO Uploading batch count=123412026/10/06 09:19:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4129654746/002/b2342--- PASS: TestQueueRemove (0.01s)23432026/10/06 09:19:47 INFO Upload queue status pending=223442026/10/06 09:19:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2846029739/002/bbb23452026/10/06 09:19:47 INFO Uploading batch count=22346--- PASS: TestQueueRetryMovesToBack (0.01s)23472026/10/06 09:19:47 INFO Uploading batch count=223482026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=223492026/10/06 09:19:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4129654746/002/c23502026/10/06 09:19:47 INFO Uploading batch count=12351--- PASS: TestQueueDeduplication (0.02s)2352--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23532026/10/06 09:19:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4129654746/002/d23542026/10/06 09:19:47 INFO Uploading batch count=123552026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=123562026/10/06 09:19:47 INFO Uploading batch count=223572026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=223582026/10/06 09:19:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4129654746/002/e2359--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23602026/10/06 09:19:47 INFO Uploading batch count=123612026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=123622026/10/06 09:19:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4129654746/002/f23632026/10/06 09:19:47 INFO Uploading batch count=123642026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=123652026/10/06 09:19:47 ERROR Drain finished with paths left in queue remaining=1023662026/10/06 09:19:47 ERROR Drain finished with paths left in queue remaining=12367--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2368--- PASS: TestDrainIsolatesPoisonPath (0.02s)2369--- PASS: TestWorkerSkipsGCdPaths (0.03s)2370--- PASS: TestWorkerUploadsAndRemoves (0.04s)2371--- PASS: TestWorkerPrunesClosureDeps (0.03s)2372--- PASS: TestQueueRemoveLargeClosure (0.11s)2373--- PASS: TestQueueConcurrentWriters (0.16s)23742026/10/06 09:19:47 ERROR Upload failed error="context deadline exceeded" count=223752026/10/06 09:19:47 ERROR Drain finished with paths left in queue remaining=42376--- PASS: TestDrainTimeout (0.22s)23772026/10/06 09:19:48 INFO Uploading batch count=123782026/10/06 09:19:48 INFO Uploading batch count=123792026/10/06 09:19:48 INFO Uploading batch count=123802026/10/06 09:19:48 ERROR Upload failed error="upload failed" count=123812026/10/06 09:19:48 INFO Uploading batch count=123822026/10/06 09:19:48 ERROR Upload failed error="upload failed" count=123832026/10/06 09:19:48 INFO Uploading batch count=123842026/10/06 09:19:48 ERROR Upload failed error="upload failed" count=123852026/10/06 09:19:48 INFO Uploading batch count=123862026/10/06 09:19:48 ERROR Upload failed error="upload failed" count=123872026/10/06 09:19:48 ERROR Drain finished with paths left in queue remaining=12388--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2389PASS2390Running signing tests...2391=== RUN TestExternalSigner2392=== PAUSE TestExternalSigner2393=== RUN TestExternalSignerWrongPublicKey2394=== PAUSE TestExternalSignerWrongPublicKey2395=== RUN TestExternalSignerErrors2396=== PAUSE TestExternalSignerErrors2397=== RUN TestExternalSignerRestartsAfterCrash2398=== PAUSE TestExternalSignerRestartsAfterCrash2399=== RUN TestExternalSignerProgramErrorKeepsProcess2400=== PAUSE TestExternalSignerProgramErrorKeepsProcess2401=== RUN TestExternalSignerClose2402=== PAUSE TestExternalSignerClose2403=== RUN TestExternalSignerRejectsInvalidPublicKey2404=== PAUSE TestExternalSignerRejectsInvalidPublicKey2405=== RUN TestExternalSignerCancellation2406=== PAUSE TestExternalSignerCancellation2407=== RUN TestGenerateFingerprint2408=== PAUSE TestGenerateFingerprint2409=== RUN TestParseSigningKey2410=== PAUSE TestParseSigningKey2411=== RUN TestSign2412=== PAUSE TestSign2413=== RUN TestSignBatch2414=== PAUSE TestSignBatch2415=== RUN TestNilKeyPublicKey2416=== PAUSE TestNilKeyPublicKey2417=== RUN TestSignErrors2418=== PAUSE TestSignErrors2419=== CONT TestExternalSigner2420=== CONT TestExternalSignerCancellation2421=== CONT TestSignBatch2422=== CONT TestSignErrors2423=== CONT TestSign2424=== CONT TestParseSigningKey2425=== RUN TestParseSigningKey/valid_32-byte_key2426=== PAUSE TestParseSigningKey/valid_32-byte_key2427=== CONT TestGenerateFingerprint2428=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2429=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2430=== RUN TestParseSigningKey/no_colon2431=== PAUSE TestParseSigningKey/no_colon2432=== RUN TestGenerateFingerprint/basic_with_references2433=== PAUSE TestGenerateFingerprint/basic_with_references2434=== RUN TestGenerateFingerprint/no_references2435=== CONT TestExternalSignerRejectsInvalidPublicKey2436=== RUN TestExternalSignerRejectsInvalidPublicKey/#002437=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002438=== CONT TestExternalSignerClose2439=== CONT TestNilKeyPublicKey2440--- PASS: TestNilKeyPublicKey (0.00s)2441=== CONT TestExternalSignerErrors2442=== RUN TestExternalSignerErrors/invalid_JSON2443=== PAUSE TestExternalSignerErrors/invalid_JSON2444=== RUN TestExternalSignerErrors/wrong_shape2445=== PAUSE TestExternalSignerErrors/wrong_shape2446=== RUN TestExternalSignerErrors/null2447=== PAUSE TestExternalSignerErrors/null2448=== CONT TestExternalSignerWrongPublicKey2449=== CONT TestExternalSignerRestartsAfterCrash2450=== CONT TestExternalSignerProgramErrorKeepsProcess2451=== RUN TestParseSigningKey/empty_name2452=== PAUSE TestParseSigningKey/empty_name2453=== RUN TestParseSigningKey/invalid_base642454=== PAUSE TestParseSigningKey/invalid_base642455=== RUN TestParseSigningKey/wrong_length2456=== PAUSE TestParseSigningKey/wrong_length2457=== CONT TestParseSigningKey/valid_32-byte_key2458=== CONT TestParseSigningKey/invalid_base642459=== CONT TestParseSigningKey/no_colon2460=== PAUSE TestGenerateFingerprint/no_references2461=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2462=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2463=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2464=== CONT TestParseSigningKey/wrong_length2465=== CONT TestParseSigningKey/empty_name2466=== RUN TestExternalSignerErrors/missing_signature_name2467=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2468=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2469=== PAUSE TestExternalSignerErrors/missing_signature_name2470=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2471=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2472=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2473=== RUN TestGenerateFingerprint/invalid_nar_hash_length2474=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2475=== RUN TestGenerateFingerprint/invalid_store_path_prefix2476=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2477=== RUN TestGenerateFingerprint/invalid_reference_prefix2478=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2479=== CONT TestGenerateFingerprint/basic_with_references2480=== CONT TestGenerateFingerprint/invalid_store_path_prefix2481=== RUN TestExternalSignerErrors/wrong_signature_name2482=== PAUSE TestExternalSignerErrors/wrong_signature_name2483=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2484=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2485=== CONT TestGenerateFingerprint/invalid_nar_hash_length2486=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2487=== CONT TestGenerateFingerprint/invalid_reference_prefix2488=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2489=== CONT TestGenerateFingerprint/no_references2490=== RUN TestExternalSignerErrors/wrong_signature_length2491=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2492=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2493--- PASS: TestGenerateFingerprint (0.00s)2494 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2495 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2496 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2497 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2498 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2499 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2500 --- PASS: TestGenerateFingerprint/no_references (0.00s)2501=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2502=== CONT TestExternalSignerRejectsInvalidPublicKey/#002503=== PAUSE TestExternalSignerErrors/wrong_signature_length2504=== RUN TestExternalSignerErrors/program_error2505=== PAUSE TestExternalSignerErrors/program_error2506=== RUN TestExternalSignerErrors/missing_signatures2507=== PAUSE TestExternalSignerErrors/missing_signatures2508=== RUN TestExternalSignerErrors/null_signatures2509=== PAUSE TestExternalSignerErrors/null_signatures2510=== RUN TestExternalSignerErrors/wrong_signatures_shape2511=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2512=== RUN TestExternalSignerErrors/too_few_signatures2513=== PAUSE TestExternalSignerErrors/too_few_signatures2514=== RUN TestExternalSignerErrors/invalid_signature_base642515=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2516--- PASS: TestParseSigningKey (0.00s)2517 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2518 --- PASS: TestParseSigningKey/no_colon (0.00s)2519 --- PASS: TestParseSigningKey/wrong_length (0.00s)2520 --- PASS: TestParseSigningKey/empty_name (0.00s)2521 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2522 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2523--- PASS: TestSign (0.00s)2524=== RUN TestSignErrors/nil_key2525=== PAUSE TestSignErrors/nil_key2526=== RUN TestSignErrors/nil_narinfo2527=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2528=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2529=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2530--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2531 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2532 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2533 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2534 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2535 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2536=== PAUSE TestExternalSignerErrors/invalid_signature_base642537=== RUN TestExternalSignerErrors/exit_at_startup2538=== PAUSE TestSignErrors/nil_narinfo2539=== PAUSE TestExternalSignerErrors/exit_at_startup2540=== RUN TestExternalSignerErrors/wrong_id2541=== RUN TestSignErrors/invalid_narinfo2542=== PAUSE TestExternalSignerErrors/wrong_id2543=== PAUSE TestSignErrors/invalid_narinfo2544=== RUN TestSignErrors/canceled2545=== PAUSE TestSignErrors/canceled2546=== CONT TestSignErrors/nil_key2547=== RUN TestExternalSignerErrors/exit_on_request2548=== PAUSE TestExternalSignerErrors/exit_on_request2549=== RUN TestExternalSignerErrors/unrequested_key2550=== CONT TestSignErrors/invalid_narinfo2551--- PASS: TestSignBatch (0.00s)2552=== PAUSE TestExternalSignerErrors/unrequested_key2553=== CONT TestExternalSignerErrors/invalid_JSON2554=== CONT TestExternalSignerErrors/wrong_signatures_shape2555=== CONT TestExternalSignerErrors/program_error2556=== CONT TestExternalSignerErrors/missing_signature_name2557=== CONT TestExternalSignerErrors/wrong_signature_length2558=== CONT TestSignErrors/canceled2559=== CONT TestExternalSignerErrors/null_signatures2560=== CONT TestExternalSignerErrors/missing_signatures2561=== CONT TestExternalSignerErrors/wrong_signature_name2562=== CONT TestExternalSignerErrors/null2563=== CONT TestExternalSignerErrors/unrequested_key2564=== CONT TestExternalSignerErrors/wrong_id2565=== CONT TestSignErrors/nil_narinfo2566=== CONT TestExternalSignerErrors/exit_on_request2567=== CONT TestExternalSignerErrors/wrong_shape2568=== CONT TestExternalSignerErrors/invalid_signature_base642569=== CONT TestExternalSignerErrors/exit_at_startup2570=== CONT TestExternalSignerErrors/too_few_signatures2571--- PASS: TestSignErrors (0.00s)2572 --- PASS: TestSignErrors/nil_key (0.00s)2573 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2574 --- PASS: TestSignErrors/canceled (0.00s)2575 --- PASS: TestSignErrors/nil_narinfo (0.00s)2576--- PASS: TestExternalSignerWrongPublicKey (0.00s)2577--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2578--- PASS: TestExternalSignerClose (0.01s)2579--- PASS: TestExternalSigner (0.01s)2580--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2581--- PASS: TestExternalSignerErrors (0.00s)2582 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2583 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2584 --- PASS: TestExternalSignerErrors/program_error (0.00s)2585 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2586 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2587 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2588 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2589 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2590 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2591 --- PASS: TestExternalSignerErrors/null (0.00s)2592 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2593 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2594 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2595 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2596 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2597 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2598--- PASS: TestExternalSignerCancellation (0.02s)2599PASS2600Running OpenBao signer tests...2601=== RUN TestSign2602=== PAUSE TestSign2603=== RUN TestSignErrors2604=== PAUSE TestSignErrors2605=== RUN TestServe2606=== PAUSE TestServe2607=== RUN TestServeRejectsGarbage2608=== PAUSE TestServeRejectsGarbage2609=== CONT TestSign2610=== CONT TestServe2611=== CONT TestSignErrors2612=== RUN TestSignErrors/http_error2613=== PAUSE TestSignErrors/http_error2614=== RUN TestSignErrors/invalid_json2615=== PAUSE TestSignErrors/invalid_json2616=== RUN TestSignErrors/no_prefix2617=== PAUSE TestSignErrors/no_prefix2618=== RUN TestSignErrors/invalid_base642619=== PAUSE TestSignErrors/invalid_base642620=== CONT TestSignErrors/http_error2621=== CONT TestSignErrors/invalid_json2622=== CONT TestSignErrors/no_prefix2623=== CONT TestServeRejectsGarbage2624--- PASS: TestServeRejectsGarbage (0.00s)2625=== CONT TestSignErrors/invalid_base642626--- PASS: TestServe (0.00s)2627--- PASS: TestSign (0.00s)2628--- PASS: TestSignErrors (0.00s)2629 --- PASS: TestSignErrors/no_prefix (0.00s)2630 --- PASS: TestSignErrors/invalid_json (0.00s)2631 --- PASS: TestSignErrors/http_error (0.00s)2632 --- PASS: TestSignErrors/invalid_base64 (0.00s)2633PASS