niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #371
· 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.03s)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 TestScriptTokenEmptyToken102=== CONT TestScriptTokenBadJSON103=== CONT TestClientSignaturesByStorePath104--- PASS: TestClientSignaturesByStorePath (0.00s)105=== CONT TestParsePathInfoJSONMultiplePaths106=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths107=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths108=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths109=== CONT TestScriptTokenCachesUntilRefresh110=== CONT TestScriptTokenNoExpiryRerunsEveryCall111=== CONT TestFileTokenEmpty112=== CONT TestFileTokenMissing113=== CONT TestFileTokenReadsAndCaches114=== CONT TestStaticToken115=== CONT TestUploadMultipart_PartsInParallel116=== CONT TestSetClientTLSErrors117=== CONT TestSetClientTLSDoesNotMutateDefaultTransport118=== CONT TestSetClientTLS119=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess120=== CONT TestScriptTokenEmptyCommand121=== CONT TestStreamPushReportsEveryPath122=== CONT TestShellSplitErrors123=== CONT TestDumpPathWriterError124=== CONT TestShellSplit125=== CONT TestRateLimiterFeedback126=== CONT TestDoWithRetry_BodyReplayedViaGetBody127=== CONT TestPathInfoCACompatibility128=== CONT TestResolveStorePath129=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths130--- PASS: TestScriptTokenScriptFails (0.00s)131=== CONT TestParsePathInfoJSON132=== RUN TestParsePathInfoJSON/Nix_format133--- PASS: TestStaticToken (0.00s)134--- PASS: TestFileTokenMissing (0.00s)135--- PASS: TestFileTokenEmpty (0.00s)136=== CONT TestDumpPathMatchesNix137--- PASS: TestScriptTokenEmptyCommand (0.00s)138=== CONT TestGetStorePathHash139=== RUN TestGetStorePathHash/valid_store_path140=== PAUSE TestGetStorePathHash/valid_store_path141=== RUN TestGetStorePathHash/basename_without_hyphen_should_error142=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error143=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error144=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error145=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error146=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error147=== CONT TestUploadMultipart_SupersededByPeer148=== RUN TestUploadMultipart_SupersededByPeer/exists149=== PAUSE TestUploadMultipart_SupersededByPeer/exists150=== RUN TestUploadMultipart_SupersededByPeer/missing151=== PAUSE TestUploadMultipart_SupersededByPeer/missing152=== CONT TestConvertHashToNix32153=== RUN TestConvertHashToNix32/SRI_format_to_Nix32154=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32155=== RUN TestConvertHashToNix32/already_Nix32_format156=== PAUSE TestConvertHashToNix32/already_Nix32_format157=== RUN TestConvertHashToNix32/invalid_format158=== PAUSE TestConvertHashToNix32/invalid_format159=== CONT TestPartSizeForNAR160=== RUN TestPartSizeForNAR/zero_stays_at_minimum1612026/10/06 10:52:33 WARN Rate limiter enabled after throttle name=server-test rate=5162--- PASS: TestShellSplitErrors (0.00s)163=== CONT TestEncodeNixBase32WithRealHash164--- PASS: TestEncodeNixBase32WithRealHash (0.00s)165=== CONT TestEncodeNixBase32166=== RUN TestEncodeNixBase32/test_string_hash167=== RUN TestRateLimiterFeedback/429_enables_limiter168=== PAUSE TestRateLimiterFeedback/429_enables_limiter169=== RUN TestRateLimiterFeedback/503_enables_limiter170=== PAUSE TestRateLimiterFeedback/503_enables_limiter171=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter172=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum173--- PASS: TestStreamPushReportsEveryPath (0.00s)174=== PAUSE TestEncodeNixBase32/test_string_hash175=== RUN TestPathInfoCACompatibility/null_ca_field176=== CONT TestStreamPushRequestLine177=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter178=== CONT TestDumpPathSingleFile179=== CONT TestPathInfoHashCompatibility180--- PASS: TestShellSplit (0.00s)181=== RUN TestEncodeNixBase32/empty_input182=== PAUSE TestPathInfoCACompatibility/null_ca_field183=== RUN TestPathInfoCACompatibility/old_string_format_-_text184=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text185=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive186=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive187=== RUN TestPathInfoCACompatibility/new_structured_format_-_text188=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text189=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method190=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method191=== PAUSE TestEncodeNixBase32/empty_input192--- PASS: TestScriptTokenEmptyToken (0.03s)193=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)194=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)195=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon196=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon197=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI198=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI199=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512200=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512201=== CONT TestStreamPushIsolatesFailures2022026/10/06 10:52:33 ERROR Upload failed error=boom count=1203=== RUN TestPartSizeForNAR/small_stays_at_minimum204=== PAUSE TestPartSizeForNAR/small_stays_at_minimum205=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum206=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum207=== CONT TestStreamPushReportsSignatures208--- PASS: TestResolveStorePath (0.02s)209=== CONT TestCaseHackSuffix2102026/10/06 10:52:33 ERROR Upload failed error="bad path" count=3211=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts212=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts213=== RUN TestPartSizeForNAR/1_TiB214=== PAUSE TestPartSizeForNAR/1_TiB215=== RUN TestPartSizeForNAR/5_TiB_S3_max_object216=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object217=== RUN TestPartSizeForNAR/capped_at_5_GiB218=== PAUSE TestPartSizeForNAR/capped_at_5_GiB219=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun220=== CONT TestRegisterUploadedObjectReusesConnections221=== RUN TestSetClientTLSErrors/missing_cert_file222=== PAUSE TestSetClientTLSErrors/missing_cert_file223=== RUN TestSetClientTLSErrors/missing_key_file224=== PAUSE TestSetClientTLSErrors/missing_key_file225=== RUN TestSetClientTLSErrors/missing_ca_file226=== PAUSE TestSetClientTLSErrors/missing_ca_file227=== RUN TestSetClientTLSErrors/invalid_ca_file228=== PAUSE TestSetClientTLSErrors/invalid_ca_file2292026/10/06 10:52:33 WARN Rate limiter enabled after throttle name=server-test rate=5230=== CONT TestStreamPushBatchesUnderLoad2312026/10/06 10:52:33 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42003232=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter233=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter2342026/10/06 10:52:33 WARN Rate limiter backed off name=server-test rate=52352026/10/06 10:52:33 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42003236=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths237=== CONT TestGetStorePathHash/valid_store_path238=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error239=== CONT TestGetStorePathHash/basename_without_hyphen_should_error240=== CONT TestUploadMultipart_SupersededByPeer/exists241=== PAUSE TestParsePathInfoJSON/Nix_format242=== RUN TestParsePathInfoJSON/Lix_format243=== PAUSE TestParsePathInfoJSON/Lix_format244=== RUN TestParsePathInfoJSON/empty_input245=== PAUSE TestParsePathInfoJSON/empty_input246=== RUN TestParsePathInfoJSON/whitespace_only247=== PAUSE TestParsePathInfoJSON/whitespace_only248=== RUN TestParsePathInfoJSON/invalid_JSON249=== PAUSE TestParsePathInfoJSON/invalid_JSON250=== RUN TestSetClientTLS/rejects_connection_without_client_cert251=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert252=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA253=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA254=== RUN TestSetClientTLS/preserves_debug_logging_transport255=== PAUSE TestSetClientTLS/preserves_debug_logging_transport256=== CONT TestUploadMultipart_SupersededByPeer/missing257=== CONT TestConvertHashToNix32/invalid_format258=== CONT TestConvertHashToNix32/already_Nix32_format2592026/10/06 10:52:33 ERROR Upload failed error=boom count=1260=== CONT TestPathInfoCACompatibility/null_ca_field261=== CONT TestEncodeNixBase32/test_string_hash262=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)263=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method264=== CONT TestPathInfoCACompatibility/new_structured_format_-_text265--- PASS: TestStreamPushIsolatesFailures (0.00s)266--- PASS: TestFileTokenReadsAndCaches (0.03s)267--- PASS: TestScriptTokenBadJSON (0.03s)268=== CONT TestPathInfoCACompatibility/old_string_format_-_text269=== CONT TestEncodeNixBase32/empty_input270=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512271=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI272=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica273=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon274=== CONT TestPartSizeForNAR/zero_stays_at_minimum275=== CONT TestSetClientTLSErrors/missing_cert_file276=== CONT TestPartSizeForNAR/capped_at_5_GiB277=== CONT TestPartSizeForNAR/5_TiB_S3_max_object278=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive279=== CONT TestPartSizeForNAR/1_TiB280=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts281=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum282=== CONT TestPartSizeForNAR/small_stays_at_minimum283=== CONT TestSetClientTLSErrors/missing_ca_file284=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error285=== CONT TestSetClientTLSErrors/invalid_ca_file286=== CONT TestSetClientTLSErrors/missing_key_file2872026/10/06 10:52:33 INFO Garbage collection started288=== CONT TestRateLimiterFeedback/429_enables_limiter289=== CONT TestConvertHashToNix32/SRI_format_to_Nix32290=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths291=== CONT TestParsePathInfoJSON/Nix_format292=== CONT TestSetClientTLS/rejects_connection_without_client_cert293--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)294--- PASS: TestStreamPushReportsSignatures (0.00s)295--- PASS: TestEncodeNixBase32 (0.02s)296 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)297 --- PASS: TestEncodeNixBase32/empty_input (0.00s)298--- PASS: TestPathInfoHashCompatibility (0.00s)299 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)300 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)301 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)302 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)303--- PASS: TestPathInfoCACompatibility (0.02s)304 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)305 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)306 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)307 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)308 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)309--- PASS: TestPartSizeForNAR (0.02s)310 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)311 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)312 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)313 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)314 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)315 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)316 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)317--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)318--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)319 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)320 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)321=== CONT TestParsePathInfoJSON/invalid_JSON322=== CONT TestStreamPushGivesUpOnDeadServer323=== CONT TestParsePathInfoJSON/whitespace_only324--- PASS: TestGetStorePathHash (0.00s)325 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)326 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)327 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)328 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)329=== CONT TestFilterOversizedClosures330=== RUN TestFilterOversizedClosures/no_limit_keeps_everything3312026/10/06 10:52:33 ERROR Upload failed error="connection refused" count=20332=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything3332026/10/06 10:52:33 ERROR Server seems unavailable, giving up on batch untried=17334=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped335=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped336=== RUN TestFilterOversizedClosures/all_closures_skipped337=== PAUSE TestFilterOversizedClosures/all_closures_skipped338=== CONT TestParsePathInfoJSON/empty_input339=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA340--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)341--- PASS: TestDoServerRequestAttachesToken (0.04s)342=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter343=== CONT TestParsePathInfoJSON/Lix_format344--- PASS: TestParsePathInfoJSON (0.03s)345 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)346 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)347 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)348 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)349 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)350--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)351=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter352=== CONT TestSetClientTLS/preserves_debug_logging_transport353=== CONT TestFilterOversizedClosures/all_closures_skipped3542026/10/06 10:52:33 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=50355=== CONT TestFilterOversizedClosures/no_limit_keeps_everything356--- PASS: TestSetClientTLSErrors (0.03s)357 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)358 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)359 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)360 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)361=== CONT TestRateLimiterFeedback/503_enables_limiter362--- PASS: TestConvertHashToNix32 (0.00s)363 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)364 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)365 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)366=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3672026/10/06 10:52:33 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=2000368--- PASS: TestFilterOversizedClosures (0.00s)369 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)370 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)371 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)3722026/10/06 10:52:33 WARN Rate limiter enabled after throttle name=server-test rate=53732026/10/06 10:52:33 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:357273742026/10/06 10:52:33 WARN Rate limiter enabled after throttle name=server-test rate=53752026/10/06 10:52:33 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:415953762026/10/06 10:52:33 WARN Rate limiter backed off name=server-test rate=53772026/10/06 10:52:33 WARN Rate limiter backed off name=server-test rate=53782026/10/06 10:52:33 INFO Garbage collection started379--- PASS: TestRateLimiterFeedback (0.02s)380 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)381 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)382 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)383 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)384--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)385 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)386 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)387--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)3882026/10/06 10:52:33 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=0389--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)3902026/10/06 10:52:33 WARN Garbage collection finished on another replica. Its statistics are not available here391--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)3922026/10/06 10:52:33 http: TLS handshake error from 127.0.0.1:46384: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.03s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)397--- PASS: TestCaseHackSuffix (0.03s)398--- PASS: TestStreamPushRequestLine (0.04s)399--- PASS: TestDumpPathSingleFile (0.04s)400--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestDumpPathMatchesNix (0.11s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.66s)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/postgres3992480357/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/postgres3992480357/data -l logfile start434435/build/postgres3992480357:5432 - no response4362026-10-06 10:52:35.424 UTC [130] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 10:52:35.424 UTC [130] LOG: listening on Unix socket "/build/postgres3992480357/.s.PGSQL.5432"4382026-10-06 10:52:35.429 UTC [137] LOG: database system was shut down at 2026-10-06 10:52:35 UTC4392026-10-06 10:52:35.432 UTC [130] LOG: database system is ready to accept connections440/build/postgres3992480357: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 10:52:35 INFO lead: acquired remote=192.0.2.1:12344872026/10/06 10:52:36 INFO lead: released remote=192.0.2.1:12344882026/10/06 10:52:36 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 10:52:37 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/06 10:52:37 INFO lead: acquired remote=192.0.2.1:12344972026-10-06 10:52:39.113 UTC [382] FATAL: terminating connection due to administrator command4982026/10/06 10:52:39 INFO lead: acquired remote=192.0.2.1:12344992026/10/06 10:52:40 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/06 10:52:40 INFO lead: released remote=192.0.2.1:12345012026/10/06 10:52:40 INFO lead: released remote=192.0.2.1:1234502--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)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 10:52:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/06 10:52:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 10:52:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 10:52:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 10:52:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 10:52:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 10:52:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 10:52:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 10:52:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 10:52:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"668--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)669=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle670=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== RUN TestProxyWriteTimeout672=== PAUSE TestProxyWriteTimeout673=== RUN TestPendingClosureWriteTimeout674=== PAUSE TestPendingClosureWriteTimeout675=== RUN TestIsValidUploadKey676=== PAUSE TestIsValidUploadKey677=== RUN TestUploadHandlersRejectInvalidKeys678=== PAUSE TestUploadHandlersRejectInvalidKeys679=== RUN TestUploadHandlersRejectOversizedBody680=== PAUSE TestUploadHandlersRejectOversizedBody681=== RUN TestService_cleanupPendingClosuresHandler682=== PAUSE TestService_cleanupPendingClosuresHandler683=== RUN TestService_createPendingClosureHandler684=== PAUSE TestService_createPendingClosureHandler685=== RUN TestService_verifyS3Integrity686=== PAUSE TestService_verifyS3Integrity687=== RUN TestCompleteMultipartUnregistered688=== PAUSE TestCompleteMultipartUnregistered689=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT690=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT691=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle692=== CONT TestRedundantMultipartUpload693=== CONT TestGCTaskStore_GetReturnsLatest694--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)695=== CONT TestFailedS3DeleteKeepsTombstone696=== CONT TestService_cleanupPendingClosuresHandler697=== CONT TestService_AuthMiddleware698=== CONT TestSkippedUploadsHandler699=== CONT TestService_Rustfstest700=== CONT TestPresignedUploadRegisteredBeforeCommit7012026/10/06 10:52:40 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000702=== CONT TestCompletedNarNotReofferedAcrossClosures703=== CONT TestCompleteMultipartUpload_ErrorButObjectExists704=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT705=== CONT TestCompleteMultipartUnregistered706=== CONT TestService_verifyS3Integrity707=== CONT TestService_createPendingClosureHandler708=== CONT TestLeadEndsOnShutdown709=== CONT TestGCTaskStore_GetEmpty710--- PASS: TestGCTaskStore_GetEmpty (0.00s)711=== CONT TestGCTaskStore_ConflictDifferentParams712=== CONT TestForceGCDuringPushOffersSweptObject713=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection714=== CONT TestGCSweepDeliversEachKeyOnce715=== CONT TestTombstonedObjectOfferedWithoutWaiting716=== CONT TestGCSweepSkipsPendingObjects717=== CONT TestDeduplicatedObjectsRecordedAsPending718=== CONT TestParseSize719=== CONT TestPushDedupSurvivesConcurrentGC720=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows721--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)722=== CONT TestGCTaskStore_DeduplicateSameParams723--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)724=== CONT TestGCMetrics725--- PASS: TestParseSize (0.00s)726=== CONT TestGCTaskStore_StartNew727--- PASS: TestGCTaskStore_StartNew (0.00s)728=== CONT TestGCBugBareHashReferences729=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows730=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check731=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check732=== CONT TestGCEndsOnShutdown733=== RUN TestGCEndsOnShutdown/before_the_run734=== PAUSE TestGCEndsOnShutdown/before_the_run735=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete736=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete737=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark738=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark739=== CONT TestGCAdvisoryLockBlocksConcurrentRun740--- PASS: TestSkippedUploadsHandler (0.01s)741=== CONT TestCommitRacingPendingCleanupKeepsObjects742--- PASS: TestService_Rustfstest (0.34s)743=== CONT TestPushWaitsForSweepHoldingRow7442026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7452026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7462026/10/06 10:52:41 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7472026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures748--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.38s)749=== CONT TestSweepRechecksPendingAfterLocking750--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.39s)751=== CONT TestClientMultipleUploads7522026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7532026/10/06 10:52:41 INFO Received cleanup request method=DELETE path=/api/pending_closures7542026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=07552026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7562026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7572026/10/06 10:52:41 INFO Received cleanup request method=DELETE path=/api/pending_closures7582026/10/06 10:52:41 INFO Aborted multipart uploads count=1 kept=07592026/10/06 10:52:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7602026-10-06 10:52:41.381 UTC [452] ERROR: Closure does not exist: id=17612026-10-06 10:52:41.381 UTC [452] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE7622026-10-06 10:52:41.381 UTC [452] STATEMENT: -- name: CommitPendingClosure :exec763 SELECT commit_pending_closure($1::bigint)764 765--- PASS: TestService_cleanupPendingClosuresHandler (0.44s)766=== CONT TestGetExistingObjectsLocksRows7672026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7682026/10/06 10:52:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7692026/10/06 10:52:41 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzRmZWIwNGEtODNlYS00MzkxLTgzOTItNjdiODg2Mjk3ZTAzLjRkOWU3MTI4LTRjYWEtNGI0Ni04N2ExLThmMTYxMjZlNmFmY3gxNzkxMjgzOTYxMzgwNzUyMTc07702026/10/06 10:52:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7712026/10/06 10:52:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzRmZWIwNGEtODNlYS00MzkxLTgzOTItNjdiODg2Mjk3ZTAzLjRkOWU3MTI4LTRjYWEtNGI0Ni04N2ExLThmMTYxMjZlNmFmY3gxNzkxMjgzOTYxMzgwNzUyMTc0 parts=17722026/10/06 10:52:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete773--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.47s)774=== CONT TestLeadIncumbentAnnouncesAtOnce7752026/10/06 10:52:41 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst776--- PASS: TestCompleteMultipartUnregistered (0.47s)777=== CONT TestRegisterCompletedObjectNeedsPendingRow7782026/10/06 10:52:41 INFO lead: acquired remote=192.0.2.1:12347792026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7802026/10/06 10:52:41 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"781--- PASS: TestService_AuthMiddleware (0.53s)782=== CONT TestLeadElectsOneAndHandsOver7832026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7842026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7852026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=07862026/10/06 10:52:41 WARN Force mode enabled - objects will be deleted immediately without grace period7872026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7882026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7892026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures7902026/10/06 10:52:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07912026/10/06 10:52:41 INFO Vacuumed table table=pending_closures7922026/10/06 10:52:41 INFO Vacuumed table table=pending_objects7932026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=07942026/10/06 10:52:41 INFO Vacuumed table table=multipart_uploads7952026/10/06 10:52:41 INFO Vacuumed table table=closures7962026/10/06 10:52:41 INFO Vacuumed table table=objects7972026/10/06 10:52:41 WARN Force mode enabled - objects will be deleted immediately without grace period798--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.62s)799=== CONT TestSweepSkipsRowsLockedByPush8002026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures8012026/10/06 10:52:41 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=08022026/10/06 10:52:41 INFO Vacuumed table table=pending_closures8032026/10/06 10:52:41 INFO Vacuumed table table=pending_objects8042026/10/06 10:52:41 INFO Vacuumed table table=multipart_uploads8052026/10/06 10:52:41 INFO Vacuumed table table=closures8062026/10/06 10:52:41 INFO Vacuumed table table=objects807--- PASS: TestGCSweepDeliversEachKeyOnce (0.64s)808=== CONT TestConnectWaitsForAPeerMigration8092026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=08102026/10/06 10:52:41 WARN Force mode enabled - objects will be deleted immediately without grace period8112026/10/06 10:52:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08122026/10/06 10:52:41 INFO Vacuumed table table=pending_closures8132026/10/06 10:52:41 INFO Vacuumed table table=pending_objects8142026/10/06 10:52:41 INFO Vacuumed table table=multipart_uploads8152026/10/06 10:52:41 INFO Vacuumed table table=closures8162026/10/06 10:52:41 INFO Vacuumed table table=objects8172026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures818--- PASS: TestGCMetrics (0.67s)819=== CONT TestClientPushesUseOnePush8202026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures821--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.72s)822=== CONT TestPinProtectsFromGC8232026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=08242026/10/06 10:52:41 WARN Force mode enabled - objects will be deleted immediately without grace period8252026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures8262026/10/06 10:52:41 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8272026/10/06 10:52:41 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."8282026/10/06 10:52:41 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"829--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.77s)830=== CONT TestResolveDBConnectionString831=== RUN TestResolveDBConnectionString/flag_wins832=== PAUSE TestResolveDBConnectionString/flag_wins833=== RUN TestResolveDBConnectionString/file_when_flag_empty834=== PAUSE TestResolveDBConnectionString/file_when_flag_empty835=== RUN TestResolveDBConnectionString/missing_file_is_an_error836=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error837=== RUN TestResolveDBConnectionString/PGHOST_allows_empty838=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty839=== RUN TestResolveDBConnectionString/nothing_configured840=== PAUSE TestResolveDBConnectionString/nothing_configured841=== CONT TestClientSharedPathCommittedMidPush842--- PASS: TestFailedS3DeleteKeepsTombstone (0.78s)843=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock8442026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures8452026/10/06 10:52:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8462026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=08472026/10/06 10:52:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8482026/10/06 10:52:41 WARN Force mode enabled - objects will be deleted immediately without grace period8492026/10/06 10:52:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08502026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures8512026/10/06 10:52:41 INFO Vacuumed table table=pending_closures8522026/10/06 10:52:41 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NzRmZWIwNGEtODNlYS00MzkxLTgzOTItNjdiODg2Mjk3ZTAzLmNiNmRkMWE4LWRkZmMtNGM0MC1iODNmLWJlMjIzMmY4NGFmMngxNzkxMjgzOTYxMzk5MjI0MjY3 parts=128532026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=08542026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures8552026/10/06 10:52:41 INFO Vacuumed table table=pending_objects8562026/10/06 10:52:41 INFO Vacuumed table table=multipart_uploads8572026/10/06 10:52:41 INFO Vacuumed table table=closures858--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.83s)859=== CONT TestClientWithDependencies8602026/10/06 10:52:41 INFO Vacuumed table table=objects861--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.84s)862=== CONT TestClientFallsBackToClosures863--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.83s)864=== CONT TestClientCADerivations8652026/10/06 10:52:41 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NzRmZWIwNGEtODNlYS00MzkxLTgzOTItNjdiODg2Mjk3ZTAzLjY1OTE2ZjRhLWFjYjEtNDViMi05YjgxLTllM2RlNGE0YTE4MngxNzkxMjgzOTYxNDY0NDgwMDE1 parts=108662026/10/06 10:52:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8672026/10/06 10:52:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08682026/10/06 10:52:41 INFO Completed upload id=1869--- PASS: TestGCSweepSkipsPendingObjects (0.84s)870=== CONT TestCacheStatsHandler8712026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures8722026/10/06 10:52:41 INFO Vacuumed table table=pending_closures8732026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures8742026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures8752026/10/06 10:52:41 INFO Vacuumed table table=pending_objects8762026/10/06 10:52:41 INFO Vacuumed table table=multipart_uploads8772026/10/06 10:52:41 INFO Vacuumed table table=closures8782026/10/06 10:52:41 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8792026/10/06 10:52:41 WARN Found objects in DB but missing from S3, will re-upload count=1880--- PASS: TestService_verifyS3Integrity (0.85s)881=== CONT TestClientIntegration8822026/10/06 10:52:41 INFO Vacuumed table table=objects8832026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=08842026/10/06 10:52:41 WARN Force mode enabled - objects will be deleted immediately without grace period8852026/10/06 10:52:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08862026/10/06 10:52:41 INFO Vacuumed table table=pending_closures8872026/10/06 10:52:41 INFO Vacuumed table table=pending_objects8882026/10/06 10:52:41 INFO Vacuumed table table=multipart_uploads8892026/10/06 10:52:41 INFO Vacuumed table table=closures8902026/10/06 10:52:41 INFO Vacuumed table table=objects891--- PASS: TestPushDedupSurvivesConcurrentGC (0.86s)892=== CONT TestClientErrorHandling893=== RUN TestClientErrorHandling/InvalidStorePath894=== PAUSE TestClientErrorHandling/InvalidStorePath895=== RUN TestClientErrorHandling/InvalidAuthToken896=== PAUSE TestClientErrorHandling/InvalidAuthToken897=== RUN TestClientErrorHandling/ServerNotAvailable898=== PAUSE TestClientErrorHandling/ServerNotAvailable899=== CONT TestService_ReadAuthMiddleware9002026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=09012026/10/06 10:52:41 WARN Force mode enabled - objects will be deleted immediately without grace period9022026/10/06 10:52:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09032026/10/06 10:52:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9042026/10/06 10:52:41 INFO Vacuumed table table=pending_closures9052026/10/06 10:52:41 INFO Vacuumed table table=pending_objects9062026/10/06 10:52:41 INFO Vacuumed table table=multipart_uploads9072026/10/06 10:52:41 INFO Vacuumed table table=closures9082026/10/06 10:52:41 INFO Vacuumed table table=objects909--- PASS: TestSweepRechecksPendingAfterLocking (0.53s)910=== CONT TestService_RequireScope_OIDC911--- PASS: TestGCBugBareHashReferences (0.92s)912=== CONT TestService_AuthMiddleware_OIDC9132026/10/06 10:52:41 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NzRmZWIwNGEtODNlYS00MzkxLTgzOTItNjdiODg2Mjk3ZTAzLjE0M2EzNjRjLTFmNjEtNGRlMC05ZGNmLTE4NjNkYTk3NDY2Y3gxNzkxMjgzOTYxNTU0Njg0Njc2 parts=109142026/10/06 10:52:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete915--- PASS: TestGetExistingObjectsLocksRows (0.48s)916=== CONT TestService_ReadScope_PublicByDefault9172026/10/06 10:52:41 INFO Completed upload id=19182026/10/06 10:52:41 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009192026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures920=== NAME TestClientMultipleUploads921 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads86499665/001/store/wimm2mjhxllak7xh9pzv4b3dvpkc47c1-test-file-0.txt9222026/10/06 10:52:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures9232026/10/06 10:52:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9242026/10/06 10:52:41 INFO lead: acquired remote=192.0.2.1:12349252026/10/06 10:52:41 INFO lead: released remote=192.0.2.1:1234926--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.46s)927=== CONT TestService_AuthMiddleware_MTLSProxyHeader9282026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=09292026/10/06 10:52:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09302026/10/06 10:52:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NzRmZWIwNGEtODNlYS00MzkxLTgzOTItNjdiODg2Mjk3ZTAzLjNmOGVhYTM0LTI4YjMtNDkxYi04NjRjLWVkZDBmZjZmMjBmM3gxNzkxMjgzOTYxNDk3Mjg5MjAx parts=12931--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.49s)932=== CONT TestService_AuthMiddleware_MTLSBoundSubjects9332026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures9342026/10/06 10:52:41 INFO Vacuumed table table=pending_closures9352026/10/06 10:52:41 INFO Vacuumed table table=pending_objects936=== NAME TestClientMultipleUploads937 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads86499665/001/store/w0635y4kv2hq4f8by4d2ababdvaffvd3-test-file-1.txt9382026/10/06 10:52:41 INFO Vacuumed table table=multipart_uploads9392026/10/06 10:52:41 INFO Received uploads request method=POST path=/api/pending_closures9402026/10/06 10:52:41 INFO Vacuumed table table=closures9412026/10/06 10:52:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46841/oidc9422026/10/06 10:52:41 INFO Vacuumed table table=objects9432026/10/06 10:52:41 INFO lead: acquired remote=192.0.2.1:12349442026/10/06 10:52:41 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000945--- PASS: TestService_createPendingClosureHandler (0.98s)946=== CONT TestIsValidUploadKey947=== RUN TestIsValidUploadKey/narinfo948=== PAUSE TestIsValidUploadKey/narinfo949=== RUN TestIsValidUploadKey/nar_zst950=== PAUSE TestIsValidUploadKey/nar_zst951=== RUN TestIsValidUploadKey/nar_xz952=== PAUSE TestIsValidUploadKey/nar_xz953=== RUN TestIsValidUploadKey/nar_plain954=== PAUSE TestIsValidUploadKey/nar_plain955=== RUN TestIsValidUploadKey/listing956=== PAUSE TestIsValidUploadKey/listing957=== RUN TestIsValidUploadKey/build_log958=== PAUSE TestIsValidUploadKey/build_log959=== RUN TestIsValidUploadKey/build_log_home-manager_file960=== PAUSE TestIsValidUploadKey/build_log_home-manager_file961=== RUN TestIsValidUploadKey/build_log_plus_in_name962=== PAUSE TestIsValidUploadKey/build_log_plus_in_name963=== RUN TestIsValidUploadKey/build_log_question_mark964=== PAUSE TestIsValidUploadKey/build_log_question_mark965=== RUN TestIsValidUploadKey/build_log_equals966=== PAUSE TestIsValidUploadKey/build_log_equals967=== RUN TestIsValidUploadKey/realisation968=== PAUSE TestIsValidUploadKey/realisation969=== RUN TestIsValidUploadKey/realisation_plus_in_output970=== PAUSE TestIsValidUploadKey/realisation_plus_in_output971=== RUN TestIsValidUploadKey/nix-cache-info972=== PAUSE TestIsValidUploadKey/nix-cache-info973=== RUN TestIsValidUploadKey/index.html974=== PAUSE TestIsValidUploadKey/index.html975=== RUN TestIsValidUploadKey/narinfo_key,_nar_type976=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type977=== RUN TestIsValidUploadKey/nar_key,_narinfo_type978=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type979=== RUN TestIsValidUploadKey/listing_key,_narinfo_type980=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type981=== RUN TestIsValidUploadKey/traversal982=== PAUSE TestIsValidUploadKey/traversal983=== RUN TestIsValidUploadKey/traversal_nar984=== PAUSE TestIsValidUploadKey/traversal_nar985=== RUN TestIsValidUploadKey/absolute986=== PAUSE TestIsValidUploadKey/absolute987=== RUN TestIsValidUploadKey/empty_key988=== PAUSE TestIsValidUploadKey/empty_key989=== RUN TestIsValidUploadKey/unknown_type990=== PAUSE TestIsValidUploadKey/unknown_type991=== CONT TestPendingClosureWriteTimeout992=== RUN TestPendingClosureWriteTimeout/empty993=== PAUSE TestPendingClosureWriteTimeout/empty994=== RUN TestPendingClosureWriteTimeout/400_objects995=== PAUSE TestPendingClosureWriteTimeout/400_objects996=== RUN TestPendingClosureWriteTimeout/670k_objects997=== PAUSE TestPendingClosureWriteTimeout/670k_objects998=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline999=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1000=== CONT TestUploadHandlersRejectOversizedBody10012026/10/06 10:52:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36215/oidc1002=== NAME TestClientMultipleUploads1003 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads86499665/001/store/mrhp0zpdv9s57g2c5lbrpj1ngc9j6pkg-test-file-2.txt10042026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=010052026/10/06 10:52:41 WARN Force mode enabled - objects will be deleted immediately without grace period10062026/10/06 10:52:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010072026/10/06 10:52:41 INFO Vacuumed table table=pending_closures10082026/10/06 10:52:41 INFO Vacuumed table table=pending_objects10092026/10/06 10:52:41 INFO Vacuumed table table=multipart_uploads10102026/10/06 10:52:41 INFO Vacuumed table table=closures10112026/10/06 10:52:41 INFO Vacuumed table table=objects10122026/10/06 10:52:41 INFO Aborted multipart uploads count=0 kept=010132026/10/06 10:52:41 WARN Force mode enabled - objects will be deleted immediately without grace period10142026/10/06 10:52:42 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=010152026/10/06 10:52:42 INFO Vacuumed table table=pending_closures10162026/10/06 10:52:42 INFO Vacuumed table table=pending_objects10172026/10/06 10:52:42 INFO Vacuumed table table=multipart_uploads10182026/10/06 10:52:42 INFO Vacuumed table table=closures10192026/10/06 10:52:42 INFO Vacuumed table table=objects1020--- PASS: TestSweepSkipsRowsLockedByPush (0.44s)1021=== CONT TestProxyWriteTimeout1022=== RUN TestProxyWriteTimeout/narinfo1023=== PAUSE TestProxyWriteTimeout/narinfo1024=== RUN TestProxyWriteTimeout/1_GiB_nar1025=== PAUSE TestProxyWriteTimeout/1_GiB_nar1026=== RUN TestProxyWriteTimeout/10_GiB_nar1027=== PAUSE TestProxyWriteTimeout/10_GiB_nar1028=== RUN TestProxyWriteTimeout/unknown_size1029=== PAUSE TestProxyWriteTimeout/unknown_size1030=== CONT TestUploadHandlersRejectInvalidKeys1031=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1032=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1033=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1034=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1035=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1036=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1037=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1038=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1039=== CONT TestCacheConfigHandler1040=== RUN TestCacheConfigHandler/full_config,_no_issuer1041=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1042=== RUN TestCacheConfigHandler/no_cache_url_configured1043=== PAUSE TestCacheConfigHandler/no_cache_url_configured1044=== RUN TestCacheConfigHandler/no_signing_keys1045=== PAUSE TestCacheConfigHandler/no_signing_keys1046=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1047=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1048=== CONT TestReadProxyRootRedirectsToIndexHTML10492026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes10502026/10/06 10:52:42 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10512026/10/06 10:52:42 INFO Uploading wimm2mjhxllak7xh9pzv4b3dvpkc47c1-test-file-0.txt (160B)10522026/10/06 10:52:42 INFO Uploading mrhp0zpdv9s57g2c5lbrpj1ngc9j6pkg-test-file-2.txt (160B)10532026/10/06 10:52:42 INFO Uploading w0635y4kv2hq4f8by4d2ababdvaffvd3-test-file-1.txt (160B)10542026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10552026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10562026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10572026/10/06 10:52:42 WARN Failed to register uploaded object key=mrhp0zpdv9s57g2c5lbrpj1ngc9j6pkg.ls error="server returned 404: 404 page not found\n"10582026/10/06 10:52:42 WARN Failed to register uploaded object key=w0635y4kv2hq4f8by4d2ababdvaffvd3.ls error="server returned 404: 404 page not found\n"10592026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10602026/10/06 10:52:42 WARN Failed to register uploaded object key=wimm2mjhxllak7xh9pzv4b3dvpkc47c1.ls error="server returned 404: 404 page not found\n"10612026/10/06 10:52:42 INFO Signed narinfos id=1 count=310622026/10/06 10:52:42 INFO Uploading 3 narinfos10632026/10/06 10:52:42 WARN Failed to register uploaded object key=w0635y4kv2hq4f8by4d2ababdvaffvd3.narinfo error="server returned 404: 404 page not found\n"10642026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete10652026/10/06 10:52:42 WARN Failed to register uploaded object key=mrhp0zpdv9s57g2c5lbrpj1ngc9j6pkg.narinfo error="server returned 404: 404 page not found\n"10662026/10/06 10:52:42 WARN Failed to register uploaded object key=wimm2mjhxllak7xh9pzv4b3dvpkc47c1.narinfo error="server returned 404: 404 page not found\n"10672026/10/06 10:52:42 INFO Upload complete. (68ms)1068=== NAME TestClientMultipleUploads1069 client_integration_test.go:369: Uploaded 3 paths in 102.942119ms1070--- PASS: TestClientMultipleUploads (0.72s)1071=== CONT TestParseSingleRange1072=== RUN TestParseSingleRange/none1073=== PAUSE TestParseSingleRange/none1074=== RUN TestParseSingleRange/unknown_unit1075=== PAUSE TestParseSingleRange/unknown_unit1076=== RUN TestParseSingleRange/multi-range_ignored1077=== PAUSE TestParseSingleRange/multi-range_ignored1078=== RUN TestParseSingleRange/malformed_no_dash1079=== PAUSE TestParseSingleRange/malformed_no_dash1080=== RUN TestParseSingleRange/malformed_both_empty1081=== PAUSE TestParseSingleRange/malformed_both_empty1082=== RUN TestParseSingleRange/malformed_end_before_start1083=== PAUSE TestParseSingleRange/malformed_end_before_start1084=== RUN TestParseSingleRange/closed1085=== PAUSE TestParseSingleRange/closed1086=== RUN TestParseSingleRange/open-ended1087=== PAUSE TestParseSingleRange/open-ended1088=== RUN TestParseSingleRange/end_clamped_to_size1089=== PAUSE TestParseSingleRange/end_clamped_to_size1090=== RUN TestParseSingleRange/suffix1091=== PAUSE TestParseSingleRange/suffix1092=== RUN TestParseSingleRange/suffix_exceeds_size1093=== PAUSE TestParseSingleRange/suffix_exceeds_size1094=== RUN TestParseSingleRange/single_byte1095=== PAUSE TestParseSingleRange/single_byte1096=== RUN TestParseSingleRange/start_past_EOF1097=== PAUSE TestParseSingleRange/start_past_EOF1098=== RUN TestParseSingleRange/start_far_past_EOF1099=== PAUSE TestParseSingleRange/start_far_past_EOF1100=== CONT TestPush_SignsNarinfosOfItsPendingObjects1101=== NAME TestPinProtectsFromGC1102 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2858146830/001/store/7g2ya4zpbx5cs98d2198rcg93mybs8b9-pinned-file.txt1103 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2858146830/001/store/m00qvlh5xnlla0jb9cdnlj85q9k8qcif-unpinned-file.txt1104=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1105=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1106=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1107=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1108=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1109=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1110=== CONT TestMetricsInventory1111--- PASS: TestCacheStatsHandler (0.30s)1112=== CONT TestReadProxyConditionalGet11132026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes11142026/10/06 10:52:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11152026/10/06 10:52:42 INFO Uploading 7g2ya4zpbx5cs98d2198rcg93mybs8b9-pinned-file.txt (128B)11162026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11172026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11182026/10/06 10:52:42 WARN Failed to register uploaded object key=7g2ya4zpbx5cs98d2198rcg93mybs8b9.ls error="server returned 404: 404 page not found\n"11192026/10/06 10:52:42 INFO Signed narinfos id=1 count=111202026/10/06 10:52:42 INFO Uploading 1 narinfos11212026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete11222026/10/06 10:52:42 WARN Failed to register uploaded object key=7g2ya4zpbx5cs98d2198rcg93mybs8b9.narinfo error="server returned 404: 404 page not found\n"11232026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes1124--- PASS: TestService_ReadAuthMiddleware (0.34s)1125=== CONT TestPendingCleanupUsesOneCutoff11262026/10/06 10:52:42 INFO Upload complete. (61ms)11272026/10/06 10:52:42 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11282026/10/06 10:52:42 INFO Uploading 2h052pwr0yj7fvmc5xknkyvmnjjxny3z-shared-dep (136B)11292026/10/06 10:52:42 INFO Uploading q2kb9y66l85fl0sxq51y4d54q5rjjdg6-b (216B)11302026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes11312026/10/06 10:52:42 WARN Failed to register uploaded object key=phmyv3xk7655a202fb6ywixq5c9biirc.ls error="server returned 404: 404 page not found\n"11322026/10/06 10:52:42 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11332026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11342026/10/06 10:52:42 INFO Uploading 7iaqxzq3fas03i0sazlh7ixnf5lav65n-shared-dep (136B)11352026/10/06 10:52:42 INFO Uploading k3x84hvqabmz89zbrqablr67m1clb8iy-top (224B)11362026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/0dc5waz6n44nk85qyd8q21m1mn5i4w0lzqy0h0ncipl7ykc80rj2.nar.zst error="server returned 404: 404 page not found\n"11372026/10/06 10:52:42 WARN Failed to register uploaded object key=2h052pwr0yj7fvmc5xknkyvmnjjxny3z.ls error="server returned 404: 404 page not found\n"11382026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11392026/10/06 10:52:42 WARN Failed to register uploaded object key=q2kb9y66l85fl0sxq51y4d54q5rjjdg6.ls error="server returned 404: 404 page not found\n"11402026/10/06 10:52:42 INFO Signed narinfos id=1 count=311412026/10/06 10:52:42 INFO Uploading 3 narinfos11422026/10/06 10:52:42 WARN Failed to register uploaded object key=k3x84hvqabmz89zbrqablr67m1clb8iy.ls error="server returned 404: 404 page not found\n"11432026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/0dq7n3gvzwhardvdxhiq8cj6j154pl0qp90k1dh9hccqz25z4g8a.nar.zst error="server returned 404: 404 page not found\n"11442026/10/06 10:52:42 WARN Failed to register uploaded object key=7iaqxzq3fas03i0sazlh7ixnf5lav65n.ls error="server returned 404: 404 page not found\n"11452026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11462026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11472026/10/06 10:52:42 INFO Signed narinfos id=1 count=211482026/10/06 10:52:42 WARN Failed to register uploaded object key=2h052pwr0yj7fvmc5xknkyvmnjjxny3z.narinfo error="server returned 404: 404 page not found\n"11492026/10/06 10:52:42 INFO Uploading 2 narinfos11502026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete11512026/10/06 10:52:42 WARN Failed to register uploaded object key=q2kb9y66l85fl0sxq51y4d54q5rjjdg6.narinfo error="server returned 404: 404 page not found\n"11522026/10/06 10:52:42 WARN Failed to register uploaded object key=phmyv3xk7655a202fb6ywixq5c9biirc.narinfo error="server returned 404: 404 page not found\n"11532026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete11542026/10/06 10:52:42 WARN Failed to register uploaded object key=7iaqxzq3fas03i0sazlh7ixnf5lav65n.narinfo error="server returned 404: 404 page not found\n"11552026/10/06 10:52:42 WARN Failed to register uploaded object key=k3x84hvqabmz89zbrqablr67m1clb8iy.narinfo error="server returned 404: 404 page not found\n"11562026/10/06 10:52:42 INFO Upload complete. (61ms)1157=== NAME TestClientIntegration1158 client_integration_test.go:286: Created store path: /build/TestClientIntegration1443873238/002/store/h2s3yccicpasnwls7acs8hk6qxmlv85z-test-file.txt1159--- PASS: TestService_ReadScope_PublicByDefault (0.31s)1160=== CONT TestPush_RejectsBadRequests1161=== NAME TestClientPushesUseOnePush1162 client_pushes_test.go:97: Retrieved narinfo from S3:1163 StorePath: /build/TestClientPushesUseOnePush1027692849/001/store/2h052pwr0yj7fvmc5xknkyvmnjjxny3z-shared-dep1164 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1165 Compression: zstd1166 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821167 NarSize: 1361168 References: 1169 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11702026/10/06 10:52:42 INFO Upload complete. (63ms)1171=== NAME TestClientCADerivations1172 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3033279779/001/store/f91kgvvg84kx0wbl93p51d7h1wlghhhv-ca-test1173=== NAME TestClientPushesUseOnePush1174 client_pushes_test.go:97: Retrieved narinfo from S3:1175 StorePath: /build/TestClientPushesUseOnePush1027692849/001/store/phmyv3xk7655a202fb6ywixq5c9biirc-a1176 URL: nar/0dc5waz6n44nk85qyd8q21m1mn5i4w0lzqy0h0ncipl7ykc80rj2.nar.zst1177 Compression: zstd1178 NarHash: sha256:0dc5waz6n44nk85qyd8q21m1mn5i4w0lzqy0h0ncipl7ykc80rj21179 NarSize: 2161180 References: /build/TestClientPushesUseOnePush1027692849/001/store/2h052pwr0yj7fvmc5xknkyvmnjjxny3z-shared-dep1181 CA: text:sha256:0k5k76wxnd9fb5a7m2pphy7k7zc4kb3cxh9yhqa6api0lcjf8qvi1182=== NAME TestClientSharedPathCommittedMidPush1183 client_integration_test.go:680: Retrieved narinfo from S3:1184 StorePath: /build/TestClientSharedPathCommittedMidPush561947282/001/store/7iaqxzq3fas03i0sazlh7ixnf5lav65n-shared-dep1185 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1186 Compression: zstd1187 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821188 NarSize: 1361189 References: 1190 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1191 client_integration_test.go:680: Retrieved narinfo from S3:1192 StorePath: /build/TestClientSharedPathCommittedMidPush561947282/001/store/k3x84hvqabmz89zbrqablr67m1clb8iy-top1193 URL: nar/0dq7n3gvzwhardvdxhiq8cj6j154pl0qp90k1dh9hccqz25z4g8a.nar.zst1194 Compression: zstd1195 NarHash: sha256:0dq7n3gvzwhardvdxhiq8cj6j154pl0qp90k1dh9hccqz25z4g8a1196 NarSize: 2241197 References: /build/TestClientSharedPathCommittedMidPush561947282/001/store/7iaqxzq3fas03i0sazlh7ixnf5lav65n-shared-dep1198 CA: text:sha256:0nr3cssj24n251j5w668y3xb730ldf737b1wxr9ndin38yxplf6g1199=== NAME TestClientPushesUseOnePush1200 client_pushes_test.go:97: Retrieved narinfo from S3:1201 StorePath: /build/TestClientPushesUseOnePush1027692849/001/store/q2kb9y66l85fl0sxq51y4d54q5rjjdg6-b1202 URL: nar/0dc5waz6n44nk85qyd8q21m1mn5i4w0lzqy0h0ncipl7ykc80rj2.nar.zst1203 Compression: zstd1204 NarHash: sha256:0dc5waz6n44nk85qyd8q21m1mn5i4w0lzqy0h0ncipl7ykc80rj21205 NarSize: 2161206 References: /build/TestClientPushesUseOnePush1027692849/001/store/2h052pwr0yj7fvmc5xknkyvmnjjxny3z-shared-dep1207 CA: text:sha256:0k5k76wxnd9fb5a7m2pphy7k7zc4kb3cxh9yhqa6api0lcjf8qvi1208--- PASS: TestClientSharedPathCommittedMidPush (0.47s)1209=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1210--- PASS: TestClientPushesUseOnePush (0.57s)1211=== CONT TestReadProxyOutlastsServerWriteTimeout1212--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.32s)1213=== CONT TestMultipartCleanup1214=== NAME TestClientWithDependencies1215 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1085667096/001/store/xwyf7hl1anv3hp3mbgbkyi8xqk3vq14g-test-script1216=== NAME TestClientCADerivations1217 client_ca_test.go:139: Found 1 dependencies (including self)12182026/10/06 10:52:42 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12192026/10/06 10:52:42 WARN mTLS auth: bound subjects configured but subject DN unavailable12202026/10/06 10:52:42 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1221--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)1222=== CONT TestReadProxyHead12232026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes12242026/10/06 10:52:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12252026/10/06 10:52:42 INFO Uploading m00qvlh5xnlla0jb9cdnlj85q9k8qcif-unpinned-file.txt (128B)12262026/10/06 10:52:42 INFO Received uploads request method=POST path=/api/pending_closures1227=== NAME TestClientWithDependencies1228 client_integration_test.go:615: Found 1 dependencies (including self)12292026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12302026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12312026/10/06 10:52:42 WARN Failed to register uploaded object key=m00qvlh5xnlla0jb9cdnlj85q9k8qcif.ls error="server returned 404: 404 page not found\n"12322026/10/06 10:52:42 INFO Signed narinfos id=2 count=112332026/10/06 10:52:42 INFO Uploading 1 narinfos12342026/10/06 10:52:42 INFO Received uploads request method=POST path=/api/pending_closures12352026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/2/complete12362026/10/06 10:52:42 WARN Failed to register uploaded object key=m00qvlh5xnlla0jb9cdnlj85q9k8qcif.narinfo error="server returned 404: 404 page not found\n"12372026/10/06 10:52:42 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12382026/10/06 10:52:42 INFO Uploading j2hr0ms2yj6aawk21fhg60gmmmakfhq1-b (216B)12392026/10/06 10:52:42 INFO Uploading 7gnibd640a9jvvz97n15nisplfx5c0qz-shared-dep (136B)12402026/10/06 10:52:42 INFO Upload complete. (51ms)12412026/10/06 10:52:42 WARN Failed to register uploaded object key=fgvdqmi82976zi5975k0s954vdk4yhs3.ls error="server returned 404: 404 page not found\n"12422026/10/06 10:52:42 WARN Failed to register uploaded object key=7gnibd640a9jvvz97n15nisplfx5c0qz.ls error="server returned 404: 404 page not found\n"12432026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12442026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/1vr1b94abvm81laqm1fbbi978llmr11czlbj0c6nxqmhqkp01jvr.nar.zst error="server returned 404: 404 page not found\n"12452026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12462026/10/06 10:52:42 WARN Failed to register uploaded object key=j2hr0ms2yj6aawk21fhg60gmmmakfhq1.ls error="server returned 404: 404 page not found\n"12472026/10/06 10:52:42 INFO Signed narinfos id=1 count=212482026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12492026/10/06 10:52:42 INFO Signed narinfos id=2 count=212502026/10/06 10:52:42 INFO Uploading 4 narinfos12512026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes12522026/10/06 10:52:42 WARN Failed to register uploaded object key=7gnibd640a9jvvz97n15nisplfx5c0qz.narinfo error="server returned 404: 404 page not found\n"12532026/10/06 10:52:42 WARN Failed to register uploaded object key=fgvdqmi82976zi5975k0s954vdk4yhs3.narinfo error="server returned 404: 404 page not found\n"12542026/10/06 10:52:42 WARN Failed to register uploaded object key=j2hr0ms2yj6aawk21fhg60gmmmakfhq1.narinfo error="server returned 404: 404 page not found\n"12552026/10/06 10:52:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12562026/10/06 10:52:42 WARN Failed to register uploaded object key=7gnibd640a9jvvz97n15nisplfx5c0qz.narinfo error="server returned 404: 404 page not found\n"12572026/10/06 10:52:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12582026/10/06 10:52:42 INFO Uploading h2s3yccicpasnwls7acs8hk6qxmlv85z-test-file.txt (152B)12592026/10/06 10:52:42 INFO Completed upload id=11260=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1261=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1262=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected12632026/10/06 10:52:42 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1264=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1265=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1266=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1267=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1268=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1269=== CONT TestReadProxyInvalidPath12702026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12712026/10/06 10:52:42 WARN Failed to register uploaded object key=h2s3yccicpasnwls7acs8hk6qxmlv85z.ls error="server returned 404: 404 page not found\n"12722026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12732026/10/06 10:52:42 INFO Completed upload id=21274=== RUN TestService_RequireScope_OIDC/builder_may_write1275=== PAUSE TestService_RequireScope_OIDC/builder_may_write12762026/10/06 10:52:42 INFO Upload complete. (72ms)1277=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1278=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1279=== RUN TestService_RequireScope_OIDC/ops_may_admin1280=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1281=== RUN TestService_RequireScope_OIDC/ops_may_not_write1282=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1283=== RUN TestService_RequireScope_OIDC/reader_may_not_write1284=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write12852026/10/06 10:52:42 INFO Signed narinfos id=1 count=11286=== RUN TestService_RequireScope_OIDC/static_token_may_admin1287=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1288=== RUN TestService_RequireScope_OIDC/static_token_may_write1289=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1290=== RUN TestService_RequireScope_OIDC/reader_may_read1291=== PAUSE TestService_RequireScope_OIDC/reader_may_read12922026/10/06 10:52:42 INFO Uploading 1 narinfos1293=== RUN TestService_RequireScope_OIDC/writer_implies_read1294=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1295=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1296=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1297=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1298=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1299=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1300=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1301=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1302=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1303=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1304=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1305=== CONT TestReadProxy4041306=== NAME TestClientFallsBackToClosures1307 client_pushes_test.go:112: Retrieved narinfo from S3:1308 StorePath: /build/TestClientFallsBackToClosures1825553838/001/store/7gnibd640a9jvvz97n15nisplfx5c0qz-shared-dep1309 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1310 Compression: zstd1311 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821312 NarSize: 1361313 References: 1314 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13152026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete13162026/10/06 10:52:42 WARN Failed to register uploaded object key=h2s3yccicpasnwls7acs8hk6qxmlv85z.narinfo error="server returned 404: 404 page not found\n"1317 client_pushes_test.go:112: Retrieved narinfo from S3:1318 StorePath: /build/TestClientFallsBackToClosures1825553838/001/store/fgvdqmi82976zi5975k0s954vdk4yhs3-a1319 URL: nar/1vr1b94abvm81laqm1fbbi978llmr11czlbj0c6nxqmhqkp01jvr.nar.zst1320 Compression: zstd1321 NarHash: sha256:1vr1b94abvm81laqm1fbbi978llmr11czlbj0c6nxqmhqkp01jvr1322 NarSize: 2161323 References: /build/TestClientFallsBackToClosures1825553838/001/store/7gnibd640a9jvvz97n15nisplfx5c0qz-shared-dep1324 CA: text:sha256:1pdg9656whdlmz3cgd33swicq8rdq7ffk33gbbkn31xbcz17nn001325 client_pushes_test.go:112: Retrieved narinfo from S3:1326 StorePath: /build/TestClientFallsBackToClosures1825553838/001/store/j2hr0ms2yj6aawk21fhg60gmmmakfhq1-b1327 URL: nar/1vr1b94abvm81laqm1fbbi978llmr11czlbj0c6nxqmhqkp01jvr.nar.zst1328 Compression: zstd1329 NarHash: sha256:1vr1b94abvm81laqm1fbbi978llmr11czlbj0c6nxqmhqkp01jvr1330 NarSize: 2161331 References: /build/TestClientFallsBackToClosures1825553838/001/store/7gnibd640a9jvvz97n15nisplfx5c0qz-shared-dep1332 CA: text:sha256:1pdg9656whdlmz3cgd33swicq8rdq7ffk33gbbkn31xbcz17nn0013332026/10/06 10:52:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures13342026/10/06 10:52:42 INFO Garbage collection started13352026/10/06 10:52:42 INFO Upload complete. (65ms)1336--- PASS: TestClientFallsBackToClosures (0.50s)1337=== CONT TestObjectStatsTrigger13382026/10/06 10:52:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13392026/10/06 10:52:42 INFO Aborted multipart uploads count=0 kept=01340--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.28s)1341=== CONT TestReadProxyNarStreaming1342--- PASS: TestPushWaitsForSweepHoldingRow (1.00s)1343=== CONT TestReadProxyContentNegotiation13442026/10/06 10:52:42 WARN Force mode enabled - objects will be deleted immediately without grace period13452026/10/06 10:52:42 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NzRmZWIwNGEtODNlYS00MzkxLTgzOTItNjdiODg2Mjk3ZTAzLjNjOTFiZGEyLTY3MTQtNDgzZi1hZDcwLWZmNWJhNTg0M2IxZXgxNzkxMjgzOTYxOTEwOTkwNjc4 error="Get \"http://127.0.0.1:1/bucket14/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13462026/10/06 10:52:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NzRmZWIwNGEtODNlYS00MzkxLTgzOTItNjdiODg2Mjk3ZTAzLmUwNTU1ZDk1LTlkYWEtNDk2My1iMzFiLWNhNmIxMDliMTRiN3gxNzkxMjgzOTYxOTA0NDEwODc2 parts=1213472026/10/06 10:52:42 INFO Received cleanup request method=DELETE path=/api/pending_closures13482026/10/06 10:52:42 INFO Aborted multipart uploads count=1 kept=01349--- PASS: TestRedundantMultipartUpload (1.36s)1350=== CONT TestPresentNotReportedWhileGCDeletesClosure13512026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes13522026/10/06 10:52:42 INFO All 1 paths already cached13532026/10/06 10:52:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=013542026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes1355=== NAME TestClientIntegration1356 client_integration_test.go:312: Retrieved narinfo from S3:1357 StorePath: /build/TestClientIntegration1443873238/002/store/h2s3yccicpasnwls7acs8hk6qxmlv85z-test-file.txt1358 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1359 Compression: zstd1360 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11361 NarSize: 1521362 References: 1363 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk113642026/10/06 10:52:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13652026/10/06 10:52:42 INFO Uploading xwyf7hl1anv3hp3mbgbkyi8xqk3vq14g-test-script (136B)1366 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1367 client_integration_test.go:313: Decompressed .ls content (64 bytes):1368 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1369 client_integration_test.go:316: Testing garbage collection...13702026/10/06 10:52:42 INFO Vacuumed table table=pending_closures13712026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes13722026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13732026/10/06 10:52:42 WARN Failed to register uploaded object key=xwyf7hl1anv3hp3mbgbkyi8xqk3vq14g.ls error="server returned 404: 404 page not found\n"13742026/10/06 10:52:42 WARN Failed to register uploaded object key=log/grbia62i31sjynzg3rk7i17i10bxv4pk-test-script.drv error="server returned 404: 404 page not found\n"13752026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13762026/10/06 10:52:42 INFO Signed narinfos id=1 count=113772026/10/06 10:52:42 INFO Uploading 1 narinfos13782026/10/06 10:52:42 WARN Failed to register uploaded object key=xwyf7hl1anv3hp3mbgbkyi8xqk3vq14g.narinfo error="server returned 404: 404 page not found\n"13792026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete13802026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13812026/10/06 10:52:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13822026/10/06 10:52:42 INFO Uploading f91kgvvg84kx0wbl93p51d7h1wlghhhv-ca-test (144B)13832026/10/06 10:52:42 INFO Vacuumed table table=pending_objects13842026/10/06 10:52:42 INFO Vacuumed table table=multipart_uploads13852026/10/06 10:52:42 INFO Signed narinfos id=1 count=113862026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13872026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13882026/10/06 10:52:42 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"13892026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13902026/10/06 10:52:42 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"13912026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13922026/10/06 10:52:42 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=113932026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13942026/10/06 10:52:42 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1395--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.27s)1396=== CONT TestReadProxyNarinfoAlreadyDecompressed13972026/10/06 10:52:42 INFO Vacuumed table table=closures13982026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13992026/10/06 10:52:42 WARN Failed to register uploaded object key=log/ivmkz582v42vvzpvwiav0jm1vzqylaal-ca-test.drv error="server returned 404: 404 page not found\n"14002026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14012026/10/06 10:52:42 WARN Failed to register uploaded object key=f91kgvvg84kx0wbl93p51d7h1wlghhhv.ls error="server returned 404: 404 page not found\n"14022026/10/06 10:52:42 INFO Signed narinfos id=1 count=114032026/10/06 10:52:42 INFO Upload complete. (64ms)14042026/10/06 10:52:42 INFO Uploading 1 narinfos14052026/10/06 10:52:42 INFO Vacuumed table table=objects1406=== NAME TestClientWithDependencies1407 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1085667096/001/store) requires matching store prefix14082026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete14092026/10/06 10:52:42 WARN Failed to register uploaded object key=f91kgvvg84kx0wbl93p51d7h1wlghhhv.narinfo error="server returned 404: 404 page not found\n"1410--- PASS: TestClientWithDependencies (0.56s)1411=== CONT TestReadProxyNarinfo14122026/10/06 10:52:42 INFO Upload complete. (97ms)1413=== NAME TestClientCADerivations1414 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3033279779/001/store/f91kgvvg84kx0wbl93p51d7h1wlghhhv-ca-test1415 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1416 Compression: zstd1417 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1418 NarSize: 1441419 References: 1420 Deriver: /build/TestClientCADerivations3033279779/001/store/ivmkz582v42vvzpvwiav0jm1vzqylaal-ca-test.drv1421 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1422 client_ca_test.go:185: Checking for realisation files in S3...1423--- PASS: TestMetricsInventory (0.28s)1424=== CONT TestService_NativeMTLS1425=== NAME TestClientCADerivations1426 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1427 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14282026/10/06 10:52:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures14292026/10/06 10:52:42 INFO Garbage collection started14302026/10/06 10:52:42 INFO Aborted multipart uploads count=0 kept=01431--- PASS: TestReadProxyConditionalGet (0.28s)1432=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit14332026/10/06 10:52:42 WARN Force mode enabled - objects will be deleted immediately without grace period14342026/10/06 10:52:42 INFO Received uploads request method=POST path=/api/pending_closures14352026/10/06 10:52:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=014362026/10/06 10:52:42 INFO Vacuumed table table=pending_closures14372026/10/06 10:52:42 INFO Vacuumed table table=pending_objects14382026/10/06 10:52:42 INFO Vacuumed table table=multipart_uploads14392026/10/06 10:52:42 INFO Received uploads request method=POST path=/api/pending_closures14402026/10/06 10:52:42 INFO Vacuumed table table=closures14412026/10/06 10:52:42 INFO Vacuumed table table=objects14422026/10/06 10:52:42 INFO Received cleanup request method=DELETE path=/api/pending_closures1443=== RUN TestPush_RejectsBadRequests/no_roots1444=== PAUSE TestPush_RejectsBadRequests/no_roots1445=== RUN TestPush_RejectsBadRequests/no_objects1446=== PAUSE TestPush_RejectsBadRequests/no_objects1447=== RUN TestPush_RejectsBadRequests/bad_root1448=== PAUSE TestPush_RejectsBadRequests/bad_root1449=== RUN TestPush_RejectsBadRequests/root_not_in_objects1450=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1451=== CONT TestIsValidCachePath1452=== RUN TestIsValidCachePath/narinfo1453=== PAUSE TestIsValidCachePath/narinfo1454=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1455=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1456=== RUN TestIsValidCachePath/nar_zst1457=== PAUSE TestIsValidCachePath/nar_zst1458=== RUN TestIsValidCachePath/nar_xz1459=== PAUSE TestIsValidCachePath/nar_xz1460=== RUN TestIsValidCachePath/nar_bz21461=== PAUSE TestIsValidCachePath/nar_bz21462=== RUN TestIsValidCachePath/nar_uncompressed1463=== PAUSE TestIsValidCachePath/nar_uncompressed1464=== RUN TestIsValidCachePath/ls1465=== PAUSE TestIsValidCachePath/ls1466=== RUN TestIsValidCachePath/log1467=== PAUSE TestIsValidCachePath/log1468=== RUN TestIsValidCachePath/realisation1469=== PAUSE TestIsValidCachePath/realisation1470=== RUN TestIsValidCachePath/nix-cache-info1471=== PAUSE TestIsValidCachePath/nix-cache-info1472=== RUN TestIsValidCachePath/index.html1473=== PAUSE TestIsValidCachePath/index.html1474=== RUN TestIsValidCachePath/traversal_parent1475=== PAUSE TestIsValidCachePath/traversal_parent1476=== RUN TestIsValidCachePath/traversal_in_middle1477=== PAUSE TestIsValidCachePath/traversal_in_middle1478=== RUN TestIsValidCachePath/invalid_char_e1479=== PAUSE TestIsValidCachePath/invalid_char_e1480=== RUN TestIsValidCachePath/invalid_char_u1481=== PAUSE TestIsValidCachePath/invalid_char_u1482=== RUN TestIsValidCachePath/random_path1483=== PAUSE TestIsValidCachePath/random_path1484=== RUN TestIsValidCachePath/empty1485=== PAUSE TestIsValidCachePath/empty1486=== RUN TestIsValidCachePath/leading_slash1487=== PAUSE TestIsValidCachePath/leading_slash1488=== RUN TestIsValidCachePath/wrong_extension1489=== PAUSE TestIsValidCachePath/wrong_extension1490=== RUN TestIsValidCachePath/short_hash1491=== PAUSE TestIsValidCachePath/short_hash1492=== CONT TestProxyHeadersOnlyTrustedOnSocket1493--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.73s)1494=== CONT TestPush_CompleteCommitsEveryRoot1495=== NAME TestClientCADerivations1496 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1497 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1498 error: binary cache 's3://bucket41?endpoint=http://localhost:40715®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3033279779/001/store'1499 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 115002026/10/06 10:52:42 INFO Received uploads request method=POST path=/api/pending_closures1501--- PASS: TestClientCADerivations (0.69s)1502=== CONT TestOrphanedObjectsGCStressTest1503--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.29s)1504=== CONT TestService_healthCheckHandler15052026/10/06 10:52:42 INFO Received uploads request method=POST path=/api/pending_closures1506--- PASS: TestReadProxyHead (0.29s)1507=== CONT TestCreatePin_ReservedPins1508--- PASS: TestReadProxyInvalidPath (0.26s)1509=== CONT TestPush_OverlappingRootsStoreOneRowPerKey15102026/10/06 10:52:42 INFO lead: released remote=192.0.2.1:12341511--- PASS: TestLeadEndsOnShutdown (1.59s)1512=== CONT TestNARDeduplicationMetadataUploadBug1513--- PASS: TestReadProxy404 (0.30s)1514=== CONT TestOrphanedObjectsGC1515--- PASS: TestReadProxyNarStreaming (0.28s)1516=== CONT TestReadRedirectUsesPublicS3URL15172026/10/06 10:52:42 INFO Received cleanup request method=DELETE path=/api/pending_closures15182026/10/06 10:52:42 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket58/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15192026/10/06 10:52:42 INFO Aborted multipart uploads count=0 kept=115202026/10/06 10:52:42 INFO Received cleanup request method=DELETE path=/api/pending_closures15212026/10/06 10:52:42 INFO Aborted multipart uploads count=1 kept=01522--- PASS: TestMultipartCleanup (0.41s)1523=== CONT TestCreatePendingClosureRejectsOversizedNAR15242026/10/06 10:52:42 INFO Received uploads request method=POST path=/api/pending_closures1525--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1526=== CONT TestGCTaskStore_PhaseUpdates1527--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1528=== CONT TestReadProxyRangeRequest1529--- PASS: TestObjectStatsTrigger (0.34s)1530=== CONT TestCacheConfigHandlerMaxNarSize1531--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1532=== CONT TestGracefulShutdownDrainsInflight15332026/10/06 10:52:42 INFO Starting HTTP server address=127.0.0.1:4262315342026/10/06 10:52:42 INFO Shutdown signal received, draining in-flight requests timeout=10s1535--- PASS: TestReadProxyContentNegotiation (0.34s)1536=== CONT TestReadRedirectKeepsNarinfoProxied1537--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.34s)1538=== CONT TestGenerateLandingPage1539--- PASS: TestGenerateLandingPage (0.00s)1540=== CONT TestGCTaskStore_Fail1541--- PASS: TestGCTaskStore_Fail (0.00s)1542=== CONT TestReadRedirectNar15432026/10/06 10:52:42 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15442026/10/06 10:52:42 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1545--- PASS: TestService_NativeMTLS (0.33s)1546=== CONT TestService_readinessHandler1547--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1548=== CONT TestReadProxyDisabled15492026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes15502026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete15512026/10/06 10:52:42 INFO Starting HTTP server address=127.0.0.1:4680115522026/10/06 10:52:42 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1753621637/001/proxy.sock15532026/10/06 10:52:42 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15542026/10/06 10:52:42 INFO Shutdown signal received, draining in-flight requests timeout=10s1555--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.32s)1556=== CONT TestGCTaskStore_CompletedAllowsNewTask1557--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1558=== CONT TestPresentReportsOnlyClosureRoots15592026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes15602026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes15612026/10/06 10:52:42 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1562--- PASS: TestReadProxyNarinfo (0.41s)1563=== CONT TestServerTLSConfig1564=== RUN TestServerTLSConfig/no_client_CA1565=== PAUSE TestServerTLSConfig/no_client_CA1566=== RUN TestServerTLSConfig/missing_CA_file1567=== PAUSE TestServerTLSConfig/missing_CA_file1568=== RUN TestServerTLSConfig/not_a_PEM_file1569=== PAUSE TestServerTLSConfig/not_a_PEM_file1570=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows15712026/10/06 10:52:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37939/oidc15722026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete1573--- PASS: TestPush_CompleteCommitsEveryRoot (0.32s)1574=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1575--- PASS: TestService_healthCheckHandler (0.30s)1576=== CONT TestGCEndsOnShutdown/before_the_run15772026/10/06 10:52:42 INFO Aborted multipart uploads count=0 kept=015782026/10/06 10:52:42 WARN Force mode enabled - objects will be deleted immediately without grace period15792026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes15802026/10/06 10:52:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=015812026/10/06 10:52:42 INFO Vacuumed table table=pending_closures15822026/10/06 10:52:42 INFO Vacuumed table table=pending_objects15832026/10/06 10:52:42 INFO Vacuumed table table=multipart_uploads15842026/10/06 10:52:42 INFO Vacuumed table table=closures15852026/10/06 10:52:42 INFO Vacuumed table table=objects15862026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/2/complete1587--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.46s)1588=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1589--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.30s)1590=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1591=== NAME TestNARDeduplicationMetadataUploadBug1592 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1164739271/001/store/wh1jhwxfibrb4bqkxs7fnfi6v5ia140x-file1.txt1593--- PASS: TestReadRedirectUsesPublicS3URL (0.31s)1594=== CONT TestResolveDBConnectionString/flag_wins1595=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1596=== CONT TestResolveDBConnectionString/missing_file_is_an_error1597=== CONT TestResolveDBConnectionString/file_when_flag_empty1598=== CONT TestResolveDBConnectionString/nothing_configured1599=== CONT TestClientErrorHandling/InvalidStorePath1600--- PASS: TestResolveDBConnectionString (0.00s)1601 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1602 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1603 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1604 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1605 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1606--- PASS: TestReadProxyRangeRequest (0.28s)1607=== CONT TestClientErrorHandling/InvalidAuthToken1608--- PASS: TestReadRedirectKeepsNarinfoProxied (0.29s)1609=== CONT TestClientErrorHandling/ServerNotAvailable1610--- PASS: TestReadRedirectNar (0.25s)1611=== CONT TestIsValidUploadKey/narinfo1612=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1613=== CONT TestIsValidUploadKey/index.html1614=== CONT TestIsValidUploadKey/nix-cache-info1615=== CONT TestIsValidUploadKey/realisation_plus_in_output1616=== CONT TestIsValidUploadKey/realisation1617=== CONT TestIsValidUploadKey/build_log_equals1618=== CONT TestIsValidUploadKey/build_log_question_mark1619=== CONT TestIsValidUploadKey/build_log_plus_in_name1620=== CONT TestIsValidUploadKey/build_log_home-manager_file1621=== CONT TestIsValidUploadKey/build_log1622=== CONT TestIsValidUploadKey/listing1623=== CONT TestIsValidUploadKey/nar_plain1624=== CONT TestIsValidUploadKey/nar_xz1625=== CONT TestIsValidUploadKey/nar_zst1626=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1627=== CONT TestIsValidUploadKey/absolute1628=== CONT TestIsValidUploadKey/traversal_nar1629=== CONT TestIsValidUploadKey/traversal1630=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1631=== CONT TestIsValidUploadKey/empty_key1632=== CONT TestIsValidUploadKey/unknown_type1633=== CONT TestPendingClosureWriteTimeout/empty1634--- PASS: TestIsValidUploadKey (0.00s)1635 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1636 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1637 --- PASS: TestIsValidUploadKey/index.html (0.00s)1638 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1639 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1640 --- PASS: TestIsValidUploadKey/realisation (0.00s)1641 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1642 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1643 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1644 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1645 --- PASS: TestIsValidUploadKey/build_log (0.00s)1646 --- PASS: TestIsValidUploadKey/listing (0.00s)1647 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1648 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1649 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1650 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1651 --- PASS: TestIsValidUploadKey/absolute (0.00s)1652 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1653 --- PASS: TestIsValidUploadKey/traversal (0.00s)1654 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1655 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1656 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1657=== CONT TestPendingClosureWriteTimeout/670k_objects1658=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline16592026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes16602026/10/06 10:52:42 WARN readiness check failed error="closed pool"1661--- PASS: TestService_readinessHandler (0.25s)1662=== CONT TestPendingClosureWriteTimeout/400_objects1663=== CONT TestProxyWriteTimeout/narinfo1664=== CONT TestProxyWriteTimeout/10_GiB_nar1665=== CONT TestProxyWriteTimeout/1_GiB_nar1666=== CONT TestProxyWriteTimeout/unknown_size1667--- PASS: TestProxyWriteTimeout (0.00s)1668 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1669 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1670 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1671 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1672=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16732026/10/06 10:52:42 INFO Received uploads request method=POST path=/1674=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16752026/10/06 10:52:42 INFO Received complete multipart upload request method=POST path=/1676=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16772026/10/06 10:52:42 INFO Received uploads request method=POST path=/1678=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16792026/10/06 10:52:42 INFO Received request for more parts method=POST path=/1680=== CONT TestCacheConfigHandler/full_config,_no_issuer1681=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1682=== CONT TestCacheConfigHandler/no_signing_keys1683--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1684 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1685 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1686 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1687 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1688=== CONT TestCacheConfigHandler/no_cache_url_configured1689--- PASS: TestCacheConfigHandler (0.00s)1690 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1691 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1692 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1693 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1694=== CONT TestParseSingleRange/none1695=== CONT TestParseSingleRange/single_byte1696=== CONT TestParseSingleRange/suffix_exceeds_size1697=== CONT TestParseSingleRange/suffix1698=== CONT TestParseSingleRange/end_clamped_to_size1699=== CONT TestParseSingleRange/open-ended1700=== CONT TestParseSingleRange/closed1701=== CONT TestParseSingleRange/malformed_end_before_start1702=== CONT TestParseSingleRange/malformed_both_empty1703=== CONT TestParseSingleRange/start_past_EOF1704=== CONT TestParseSingleRange/malformed_no_dash1705=== CONT TestParseSingleRange/multi-range_ignored1706=== CONT TestParseSingleRange/unknown_unit1707=== CONT TestParseSingleRange/start_far_past_EOF1708--- PASS: TestParseSingleRange (0.00s)1709 --- PASS: TestParseSingleRange/none (0.00s)1710 --- PASS: TestParseSingleRange/single_byte (0.00s)1711 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1712 --- PASS: TestParseSingleRange/suffix (0.00s)1713 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1714 --- PASS: TestParseSingleRange/open-ended (0.00s)1715 --- PASS: TestParseSingleRange/closed (0.00s)1716 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1717 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1718 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1719 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1720 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1721 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1722 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1723=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17242026/10/06 10:52:42 INFO Received uploads request method=POST path=/17252026/10/06 10:52:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17262026/10/06 10:52:42 INFO Uploading wh1jhwxfibrb4bqkxs7fnfi6v5ia140x-file1.txt (160B)17272026/10/06 10:52:42 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17282026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17292026/10/06 10:52:42 WARN Failed to register uploaded object key=wh1jhwxfibrb4bqkxs7fnfi6v5ia140x.ls error="server returned 404: 404 page not found\n"17302026/10/06 10:52:42 INFO Signed narinfos id=1 count=117312026/10/06 10:52:42 INFO Uploading 1 narinfos17322026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/1/complete17332026/10/06 10:52:42 WARN Failed to register uploaded object key=wh1jhwxfibrb4bqkxs7fnfi6v5ia140x.narinfo error="server returned 404: 404 page not found\n"1734--- PASS: TestReadProxyDisabled (0.27s)1735=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17362026/10/06 10:52:42 INFO Received request for more parts method=POST path=/17372026/10/06 10:52:42 INFO Upload complete. (58ms)1738=== NAME TestNARDeduplicationMetadataUploadBug1739 metadata_upload_test.go:54: Retrieved narinfo from S3:1740 StorePath: /build/TestNARDeduplicationMetadataUploadBug1164739271/001/store/wh1jhwxfibrb4bqkxs7fnfi6v5ia140x-file1.txt1741 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1742 Compression: zstd1743 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1744 NarSize: 1601745 References: 1746 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1747 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1748 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1749 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1750--- PASS: TestPresentReportsOnlyClosureRoots (0.26s)1751=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17522026/10/06 10:52:42 INFO Received complete multipart upload request method=POST path=/1753=== NAME TestNARDeduplicationMetadataUploadBug1754 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1164739271/001/store/gr2bnsp4s5f9719ksvbhp138s8iska76-file2.txt17552026/10/06 10:52:42 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17562026/10/06 10:52:42 INFO Received uploads request method=POST path=/api/pending_closures17572026/10/06 10:52:43 INFO Aborted multipart uploads count=0 kept=017582026/10/06 10:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period17592026/10/06 10:52:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17602026/10/06 10:52:43 WARN Refused reserved pin name=worker-x86_64-linux17612026/10/06 10:52:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17622026/10/06 10:52:43 INFO Received create pin request method=POST path=/api/pins/my-app17632026/10/06 10:52:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1764--- PASS: TestCreatePin_ReservedPins (0.51s)1765=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token17662026/10/06 10:52:43 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=017672026/10/06 10:52:43 INFO Vacuumed table table=pending_closures17682026/10/06 10:52:43 INFO Vacuumed table table=pending_objects17692026/10/06 10:52:43 INFO Vacuumed table table=multipart_uploads17702026/10/06 10:52:43 INFO Vacuumed table table=closures1771=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17722026/10/06 10:52:43 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]1773=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17742026/10/06 10:52:43 INFO Vacuumed table table=objects1775=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1776=== CONT TestService_RequireScope_OIDC/builder_may_write17772026/10/06 10:52:43 WARN Authentication failed token_preview=eyJhbGciOi...hYpI3R400g token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1778=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1779=== CONT TestService_RequireScope_OIDC/writer_implies_read1780=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1781=== CONT TestService_RequireScope_OIDC/reader_may_read1782--- PASS: TestService_AuthMiddleware_OIDC (0.40s)1783 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1784 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1785 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1786 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1787=== CONT TestService_RequireScope_OIDC/static_token_may_write1788=== CONT TestService_RequireScope_OIDC/static_token_may_admin1789=== CONT TestService_RequireScope_OIDC/reader_may_not_write1790=== CONT TestService_RequireScope_OIDC/ops_may_not_write1791=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1792=== CONT TestService_RequireScope_OIDC/ops_may_admin1793=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1794=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1795=== CONT TestPush_RejectsBadRequests/no_roots17962026/10/06 10:52:43 INFO Received push request method=POST path=/api/pushes1797=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1798=== CONT TestPush_RejectsBadRequests/bad_root17992026/10/06 10:52:43 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]18002026/10/06 10:52:43 INFO Received push request method=POST path=/api/pushes1801=== CONT TestPush_RejectsBadRequests/no_objects18022026/10/06 10:52:43 INFO Received push request method=POST path=/api/pushes1803=== CONT TestIsValidCachePath/narinfo1804=== CONT TestIsValidCachePath/index.html1805=== CONT TestIsValidCachePath/short_hash1806=== CONT TestIsValidCachePath/wrong_extension1807=== CONT TestIsValidCachePath/leading_slash1808=== CONT TestIsValidCachePath/empty1809=== CONT TestIsValidCachePath/random_path1810=== CONT TestIsValidCachePath/traversal_in_middle1811=== CONT TestPush_RejectsBadRequests/root_not_in_objects18122026/10/06 10:52:43 INFO Received push request method=POST path=/api/pushes1813=== CONT TestIsValidCachePath/invalid_char_e1814=== CONT TestIsValidCachePath/traversal_parent1815=== CONT TestIsValidCachePath/nar_uncompressed1816=== CONT TestIsValidCachePath/realisation1817=== CONT TestIsValidCachePath/nar_xz1818--- PASS: TestService_RequireScope_OIDC (0.41s)1819 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1820 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1821 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1822 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1823 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1824 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1825 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1826 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1827 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1828 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1829 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1830 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1831 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1832 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1833=== CONT TestIsValidCachePath/invalid_char_u1834--- PASS: TestPush_RejectsBadRequests (0.23s)1835 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1836 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1837 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1838 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1839=== CONT TestIsValidCachePath/log1840=== CONT TestIsValidCachePath/nar_bz21841=== CONT TestIsValidCachePath/ls1842=== CONT TestIsValidCachePath/nar_zst1843=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1844=== CONT TestIsValidCachePath/nix-cache-info1845--- PASS: TestIsValidCachePath (0.00s)1846 --- PASS: TestIsValidCachePath/narinfo (0.00s)1847 --- PASS: TestIsValidCachePath/index.html (0.00s)1848 --- PASS: TestIsValidCachePath/short_hash (0.00s)1849 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1850 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1851 --- PASS: TestIsValidCachePath/empty (0.00s)1852 --- PASS: TestIsValidCachePath/random_path (0.00s)1853 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1854 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1855 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1856 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1857 --- PASS: TestIsValidCachePath/realisation (0.00s)1858 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1859 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1860 --- PASS: TestIsValidCachePath/log (0.00s)1861 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1862 --- PASS: TestIsValidCachePath/ls (0.00s)1863 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1864 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1865 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1866=== CONT TestServerTLSConfig/no_client_CA1867=== CONT TestServerTLSConfig/not_a_PEM_file1868=== CONT TestServerTLSConfig/missing_CA_file1869--- PASS: TestServerTLSConfig (0.00s)1870 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1871 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1872 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)18732026/10/06 10:52:43 INFO Received uploads request method=POST path=/api/pending_closures18742026/10/06 10:52:43 INFO Aborted multipart uploads count=0 kept=018752026/10/06 10:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period18762026/10/06 10:52:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018772026/10/06 10:52:43 INFO Vacuumed table table=pending_closures18782026/10/06 10:52:43 INFO Vacuumed table table=pending_objects18792026/10/06 10:52:43 INFO Vacuumed table table=multipart_uploads18802026/10/06 10:52:43 INFO Vacuumed table table=closures18812026/10/06 10:52:43 INFO Vacuumed table table=objects1882--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1883 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.28s)1884 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.29s)18852026/10/06 10:52:43 INFO Received push request method=POST path=/api/pushes18862026/10/06 10:52:43 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18872026/10/06 10:52:43 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18882026/10/06 10:52:43 INFO Signed narinfos id=2 count=118892026/10/06 10:52:43 WARN Failed to register uploaded object key=gr2bnsp4s5f9719ksvbhp138s8iska76.ls error="server returned 404: 404 page not found\n"18902026/10/06 10:52:43 INFO Aborted multipart uploads count=0 kept=018912026/10/06 10:52:43 INFO Uploading 1 narinfos18922026/10/06 10:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period18932026/10/06 10:52:43 INFO Received complete push request method=POST path=/api/pushes/2/complete18942026/10/06 10:52:43 WARN Failed to register uploaded object key=gr2bnsp4s5f9719ksvbhp138s8iska76.narinfo error="server returned 404: 404 page not found\n"18952026/10/06 10:52:43 INFO Upload complete. (47ms)1896=== NAME TestNARDeduplicationMetadataUploadBug1897 metadata_upload_test.go:76: Retrieved narinfo from S3:1898 StorePath: /build/TestNARDeduplicationMetadataUploadBug1164739271/001/store/gr2bnsp4s5f9719ksvbhp138s8iska76-file2.txt1899 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1900 Compression: zstd1901 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1902 NarSize: 1601903 References: 1904 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1905 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1906 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1907 {"version":1,"root":{"type":"regular","size":44}}19082026/10/06 10:52:43 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:40715/bucket88/?delete=\": context canceled"1909--- PASS: TestNARDeduplicationMetadataUploadBug (0.55s)19102026/10/06 10:52:43 INFO Aborted multipart uploads count=0 kept=019112026/10/06 10:52:43 WARN Force mode enabled - objects will be deleted immediately without grace period19122026/10/06 10:52:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.408686ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19132026-10-06 10:52:43.094 UTC [1735] ERROR: canceling statement due to user request19142026-10-06 10:52:43.094 UTC [1735] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block19152026-10-06 10:52:43.094 UTC [1735] STATEMENT: -- name: MarkStaleObjects :execrows1916 WITH RECURSIVE ct AS (1917 SELECT timezone('UTC', now()) AS now1918 ),1919 closure_reach AS (1920 -- Start with all closure keys1921 SELECT o.key, o.refs1922 FROM objects o1923 INNER JOIN closures c ON o.key = c.key1924 UNION1925 -- Recursively add all referenced objects1926 SELECT o.key, o.refs1927 FROM objects o1928 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1929 ),1930 reachable_objects AS (1931 SELECT DISTINCT key FROM closure_reach1932 ),1933 stale_objects AS (1934 SELECT o.key1935 FROM objects AS o, ct1936 WHERE1937 NOT EXISTS (1938 SELECT 11939 FROM reachable_objects ro1940 WHERE ro.key = o.key1941 )1942 AND NOT EXISTS (1943 SELECT 11944 FROM pending_objects AS po1945 WHERE po.key = o.key1946 )1947 AND o.deleted_at IS NULL -- Only mark fresh objects1948 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1949 FOR UPDATE1950 )1951 UPDATE objects1952 SET1953 deleted_at = ct.now,1954 first_deleted_at = COALESCE(first_deleted_at, ct.now)1955 FROM stale_objects, ct1956 WHERE objects.key = stale_objects.key1957 1958--- PASS: TestGCEndsOnShutdown (0.00s)1959 --- PASS: TestGCEndsOnShutdown/before_the_run (0.26s)1960 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.25s)1961 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.28s)19622026/10/06 10:52:43 INFO Received uploads request method=POST path=/api/pending_closures1963=== NAME TestOrphanedObjectsGC1964 orphaned_objects_gc_test.go:290: GC Test Summary:1965 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1966 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1967 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1968 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1969 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1970--- PASS: TestOrphanedObjectsGC (0.56s)1971--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.82s)19722026/10/06 10:52:43 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19732026/10/06 10:52:43 INFO lead: released remote=192.0.2.1:123419742026/10/06 10:52:43 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19752026/10/06 10:52:43 INFO lead: acquired remote=192.0.2.1:123419762026/10/06 10:52:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=431.34097ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19772026/10/06 10:52:43 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=849.948401ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1978=== NAME TestOrphanedObjectsGCStressTest1979 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1980 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1981--- PASS: TestPendingClosureWriteTimeout (0.00s)1982 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1983 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1984 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1985 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.00s)1986=== NAME TestOrphanedObjectsGCStressTest1987 orphaned_objects_gc_test.go:509: Stress test completed successfully:1988 orphaned_objects_gc_test.go:510: - Active objects preserved: 201989 orphaned_objects_gc_test.go:511: - Objects deleted: 2101990 orphaned_objects_gc_test.go:512: - Total GC'd: 2101991--- PASS: TestOrphanedObjectsGCStressTest (1.53s)1992--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)1993 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1994 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1995 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.09s)19962026/10/06 10:52:44 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019972026/10/06 10:52:44 INFO Received create pin request method=POST path=/api/pins/myapp19982026/10/06 10:52:44 INFO lead: released remote=192.0.2.1:12341999--- PASS: TestLeadElectsOneAndHandsOver (2.81s)20002026/10/06 10:52:44 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2858146830/001/store/7g2ya4zpbx5cs98d2198rcg93mybs8b9-pinned-file.txt narinfo_key=7g2ya4zpbx5cs98d2198rcg93mybs8b9.narinfo20012026/10/06 10:52:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures20022026/10/06 10:52:44 INFO Garbage collection started20032026/10/06 10:52:44 INFO Aborted multipart uploads count=0 kept=020042026/10/06 10:52:44 WARN Force mode enabled - objects will be deleted immediately without grace period20052026/10/06 10:52:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020062026/10/06 10:52:44 INFO Vacuumed table table=pending_closures20072026/10/06 10:52:44 INFO Vacuumed table table=pending_objects20082026/10/06 10:52:44 INFO Vacuumed table table=multipart_uploads20092026/10/06 10:52:44 INFO Vacuumed table table=closures20102026/10/06 10:52:44 INFO Vacuumed table table=objects20112026/10/06 10:52:44 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02012=== NAME TestClientIntegration2013 client_integration_test.go:323: Objects in database after GC:2014 client_integration_test.go:323: Successfully deleted all objects with GC --force2015--- PASS: TestClientIntegration (2.56s)20162026/10/06 10:52:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.672398955s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20172026/10/06 10:52:45 WARN Rate limiter enabled after throttle name=s3-test rate=520182026/10/06 10:52:45 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2019=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2020 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102021 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002022--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.00s)2023=== NAME TestPinProtectsFromGC2024 client_integration_test.go:840: Pin successfully protected closure from garbage collection20252026/10/06 10:52:46 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-config2026--- PASS: TestPinProtectsFromGC (4.62s)20272026/10/06 10:52:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.706055ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/06 10:52:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=398.17188ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2029--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.46s)2030--- PASS: TestConnectWaitsForAPeerMigration (5.12s)20312026/10/06 10:52:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=857.883295ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20322026/10/06 10:52:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.572289536s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20332026/10/06 10:52:48 INFO Aborted multipart uploads count=1 kept=020342026/10/06 10:52:48 INFO Received cleanup request method=DELETE path=/api/pending_closures20352026/10/06 10:52:48 INFO Aborted multipart uploads count=1 kept=02036--- PASS: TestPendingCleanupUsesOneCutoff (6.26s)20372026/10/06 10:52:49 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"20382026/10/06 10:52:49 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20392026/10/06 10:52:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.558587ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20402026/10/06 10:52:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=416.776103ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20412026/10/06 10:52:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=806.847254ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20422026/10/06 10:52:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.490143494s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20432026/10/06 10:52:52 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20442026/10/06 10:52:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.710518ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20452026/10/06 10:52:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.830777ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20462026/10/06 10:52:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=809.483912ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20472026/10/06 10:52:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.674241363s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2048--- PASS: TestClientErrorHandling (0.00s)2049 --- PASS: TestClientErrorHandling/InvalidStorePath (0.24s)2050 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.32s)2051 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.68s)2052PASS20532026-10-06 10:52:55.819 UTC [130] LOG: received smart shutdown request20542026-10-06 10:52:55.822 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 120552026-10-06 10:52:55.833 UTC [135] LOG: shutting down20562026-10-06 10:52:55.833 UTC [135] LOG: checkpoint starting: shutdown immediate20572026-10-06 10:52:56.712 UTC [135] LOG: checkpoint complete: wrote 11026 buffers (67.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.181 s, sync=0.668 s, total=0.880 s; sync files=31336, longest=0.002 s, average=0.001 s; distance=433054 kB, estimate=433054 kB; lsn=0/1BE4D6B0, redo lsn=0/1BE4D6B020582026-10-06 10:52:56.787 UTC [130] LOG: database system is shut down2059Running OIDC tests...2060=== RUN TestAudienceForIssuer2061=== PAUSE TestAudienceForIssuer2062=== RUN TestGlobMatch2063=== PAUSE TestGlobMatch2064=== RUN TestValidateToken_ValidToken2065=== PAUSE TestValidateToken_ValidToken2066=== RUN TestValidateToken_WrongAudience2067=== PAUSE TestValidateToken_WrongAudience2068=== RUN TestValidateToken_Expired2069=== PAUSE TestValidateToken_Expired2070=== RUN TestValidateToken_BoundClaimsMismatch2071=== PAUSE TestValidateToken_BoundClaimsMismatch2072=== RUN TestValidateToken_BoundSubjectMismatch2073=== PAUSE TestValidateToken_BoundSubjectMismatch2074=== RUN TestValidateToken_MultipleProviders2075=== PAUSE TestValidateToken_MultipleProviders2076=== RUN TestValidateToken_NoMatchingProvider2077=== PAUSE TestValidateToken_NoMatchingProvider2078=== RUN TestValidateToken_KubernetesServiceAccount2079=== PAUSE TestValidateToken_KubernetesServiceAccount2080=== RUN TestNewValidator_KubernetesRequiresCA2081=== PAUSE TestNewValidator_KubernetesRequiresCA2082=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2083=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2084=== RUN TestPins_ReservedForMatchingRule2085=== PAUSE TestPins_ReservedForMatchingRule2086=== RUN TestPins_TopLevelShorthand2087=== PAUSE TestPins_TopLevelShorthand2088=== RUN TestPins_ConfigValidation2089=== PAUSE TestPins_ConfigValidation2090=== RUN TestScopes_LegacyProviderDefaultsToWrite2091=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2092=== RUN TestScopes_Rules2093=== PAUSE TestScopes_Rules2094=== RUN TestScopes_ConfigValidation2095=== PAUSE TestScopes_ConfigValidation2096=== CONT TestAudienceForIssuer2097=== CONT TestValidateToken_KubernetesServiceAccount2098=== CONT TestScopes_LegacyProviderDefaultsToWrite2099=== CONT TestScopes_ConfigValidation2100=== CONT TestScopes_Rules2101=== CONT TestNewValidator_KubernetesRequiresCA2102=== CONT TestPins_ConfigValidation2103--- PASS: TestAudienceForIssuer (0.00s)2104=== CONT TestValidateToken_MultipleProviders2105=== CONT TestValidateToken_BoundSubjectMismatch2106--- PASS: TestScopes_ConfigValidation (0.00s)2107--- PASS: TestPins_ConfigValidation (0.00s)2108=== CONT TestValidateToken_NoMatchingProvider2109=== CONT TestValidateToken_Expired2110=== CONT TestValidateToken_BoundClaimsMismatch2111=== CONT TestValidateToken_ValidToken2112=== CONT TestValidateToken_WrongAudience2113=== CONT TestPins_ReservedForMatchingRule2114=== CONT TestPins_TopLevelShorthand2115=== CONT TestGlobMatch2116=== RUN TestGlobMatch/foo_foo2117=== PAUSE TestGlobMatch/foo_foo2118=== RUN TestGlobMatch/foo_bar2119=== PAUSE TestGlobMatch/foo_bar2120=== RUN TestGlobMatch/*_2121=== PAUSE TestGlobMatch/*_2122=== RUN TestGlobMatch/*_anything2123=== PAUSE TestGlobMatch/*_anything2124=== RUN TestGlobMatch/foo*_foo2125=== PAUSE TestGlobMatch/foo*_foo2126=== RUN TestGlobMatch/foo*_foobar2127=== PAUSE TestGlobMatch/foo*_foobar2128=== RUN TestGlobMatch/foo*_bar2129=== PAUSE TestGlobMatch/foo*_bar2130=== RUN TestGlobMatch/*bar_bar2131=== PAUSE TestGlobMatch/*bar_bar2132=== RUN TestGlobMatch/*bar_foobar2133=== PAUSE TestGlobMatch/*bar_foobar2134=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2135=== RUN TestGlobMatch/*bar_foo2136=== PAUSE TestGlobMatch/*bar_foo2137=== RUN TestGlobMatch/foo*bar_foobar2138=== PAUSE TestGlobMatch/foo*bar_foobar2139=== RUN TestGlobMatch/foo*bar_foo123bar2140=== PAUSE TestGlobMatch/foo*bar_foo123bar2141=== RUN TestGlobMatch/foo*bar_foobarbaz2142=== PAUSE TestGlobMatch/foo*bar_foobarbaz2143=== RUN TestGlobMatch/*/*_foo/bar2144=== PAUSE TestGlobMatch/*/*_foo/bar2145=== RUN TestGlobMatch/*/*_foo2146=== PAUSE TestGlobMatch/*/*_foo2147=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2148=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2149=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02150=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02151=== RUN TestGlobMatch/refs/*/main_refs/heads/main2152=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2153=== RUN TestGlobMatch/fo?_foo2154=== PAUSE TestGlobMatch/fo?_foo2155=== RUN TestGlobMatch/fo?_fo2156=== PAUSE TestGlobMatch/fo?_fo2157=== RUN TestGlobMatch/fo?_fooo2158=== PAUSE TestGlobMatch/fo?_fooo2159=== RUN TestGlobMatch/?oo_foo2160=== PAUSE TestGlobMatch/?oo_foo2161=== RUN TestGlobMatch/?oo_boo2162=== PAUSE TestGlobMatch/?oo_boo2163=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2164=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2165=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2166=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2167=== CONT TestGlobMatch/foo_foo2168=== CONT TestGlobMatch/?oo_boo2169=== CONT TestGlobMatch/?oo_foo2170=== CONT TestGlobMatch/fo?_fooo2171=== CONT TestGlobMatch/fo?_fo2172=== CONT TestGlobMatch/fo?_foo2173=== CONT TestGlobMatch/*bar_foo2174=== CONT TestGlobMatch/foo_bar2175=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2176=== CONT TestGlobMatch/refs/*/main_refs/heads/main2177=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02178=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2179=== CONT TestGlobMatch/foo*bar_foobarbaz2180=== CONT TestGlobMatch/*/*_foo/bar2181=== CONT TestGlobMatch/foo*bar_foo123bar2182=== CONT TestGlobMatch/foo*bar_foobar2183=== CONT TestGlobMatch/*/*_foo2184=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2185=== CONT TestGlobMatch/*bar_foobar2186=== CONT TestGlobMatch/*bar_bar2187=== CONT TestGlobMatch/foo*_bar2188=== CONT TestGlobMatch/foo*_foobar2189=== CONT TestGlobMatch/foo*_foo2190=== CONT TestGlobMatch/*_anything2191=== CONT TestGlobMatch/*_2192--- PASS: TestGlobMatch (0.00s)2193 --- PASS: TestGlobMatch/foo_foo (0.00s)2194 --- PASS: TestGlobMatch/?oo_boo (0.00s)2195 --- PASS: TestGlobMatch/?oo_foo (0.00s)2196 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2197 --- PASS: TestGlobMatch/fo?_fo (0.00s)2198 --- PASS: TestGlobMatch/fo?_foo (0.00s)2199 --- PASS: TestGlobMatch/*bar_foo (0.00s)2200 --- PASS: TestGlobMatch/foo_bar (0.00s)2201 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2202 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2203 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2204 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2205 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2206 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2207 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2208 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2209 --- PASS: TestGlobMatch/*/*_foo (0.00s)2210 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2211 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2212 --- PASS: TestGlobMatch/*bar_bar (0.00s)2213 --- PASS: TestGlobMatch/foo*_bar (0.00s)2214 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2215 --- PASS: TestGlobMatch/foo*_foo (0.00s)2216 --- PASS: TestGlobMatch/*_anything (0.00s)2217 --- PASS: TestGlobMatch/*_ (0.00s)22182026/10/06 10:52:58 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:444312219--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)22202026/10/06 10:52:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41703/oidc2221--- PASS: TestValidateToken_WrongAudience (0.06s)22222026/10/06 10:52:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44995/oidc2223--- PASS: TestValidateToken_Expired (0.08s)22242026/10/06 10:52:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45891/oidc2225--- PASS: TestPins_TopLevelShorthand (0.08s)22262026/10/06 10:52:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43273/oidc22272026/10/06 10:52:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34145/oidc2228--- PASS: TestValidateToken_ValidToken (0.12s)2229--- PASS: TestValidateToken_BoundClaimsMismatch (0.12s)22302026/10/06 10:52:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44375/oidc22312026/10/06 10:52:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42771/oidc2232--- PASS: TestScopes_Rules (0.15s)2233--- PASS: TestValidateToken_BoundSubjectMismatch (0.16s)22342026/10/06 10:52:58 http: TLS handshake error from 127.0.0.1:47192: remote error: tls: bad certificate2235--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)22362026/10/06 10:52:58 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34523/oidc2237--- PASS: TestValidateToken_NoMatchingProvider (0.18s)22382026/10/06 10:52:58 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232239--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.21s)22402026/10/06 10:52:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40223/oidc2241--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.25s)22422026/10/06 10:52:58 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34557/oidc22432026/10/06 10:52:58 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45339/oidc2244--- PASS: TestValidateToken_MultipleProviders (0.27s)22452026/10/06 10:52:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35945/oidc2246--- PASS: TestPins_ReservedForMatchingRule (0.33s)2247PASS2248Running hook tests...2249=== RUN TestSendPathsEmpty2250=== PAUSE TestSendPathsEmpty2251=== RUN TestQueueEnqueueAndFetch2252=== PAUSE TestQueueEnqueueAndFetch2253=== RUN TestQueueDeduplication2254=== PAUSE TestQueueDeduplication2255=== RUN TestQueueRemove2256=== PAUSE TestQueueRemove2257=== RUN TestQueueFetchBatchLimit2258=== PAUSE TestQueueFetchBatchLimit2259=== RUN TestQueueRetryMovesToBack2260=== PAUSE TestQueueRetryMovesToBack2261=== RUN TestQueueFetchRemoveLifecycle2262=== PAUSE TestQueueFetchRemoveLifecycle2263=== RUN TestQueueConcurrentWriters2264=== PAUSE TestQueueConcurrentWriters2265=== RUN TestQueueRemoveLargeClosure2266=== PAUSE TestQueueRemoveLargeClosure2267=== RUN TestServerClientIntegration2268=== PAUSE TestServerClientIntegration2269=== RUN TestServerQueueError2270=== PAUSE TestServerQueueError2271=== RUN TestGetListenerSocketActivation2272 server_test.go:210: === RUN TestGetListenerSocketActivation2273 --- PASS: TestGetListenerSocketActivation (0.00s)2274 PASS2275 2276--- PASS: TestGetListenerSocketActivation (0.01s)2277=== RUN TestDrainIsolatesPoisonPath2278=== PAUSE TestDrainIsolatesPoisonPath2279=== RUN TestRunNotBlockedByPoisonHead2280=== PAUSE TestRunNotBlockedByPoisonHead2281=== RUN TestDrainGivesUpWhenServerDown2282=== PAUSE TestDrainGivesUpWhenServerDown2283=== RUN TestFailedPathPrunedByLaterClosure2284=== PAUSE TestFailedPathPrunedByLaterClosure2285=== RUN TestWorkerUploadsAndRemoves2286=== PAUSE TestWorkerUploadsAndRemoves2287=== RUN TestWorkerSkipsGCdPaths2288=== PAUSE TestWorkerSkipsGCdPaths2289=== RUN TestWorkerPrunesClosureDeps2290=== PAUSE TestWorkerPrunesClosureDeps2291=== RUN TestDrainTimeout2292=== PAUSE TestDrainTimeout2293=== CONT TestSendPathsEmpty2294=== CONT TestDrainGivesUpWhenServerDown2295=== CONT TestQueueConcurrentWriters2296=== CONT TestFailedPathPrunedByLaterClosure2297=== CONT TestQueueFetchRemoveLifecycle2298=== CONT TestQueueRetryMovesToBack2299=== CONT TestQueueFetchBatchLimit2300=== CONT TestQueueRemove2301=== CONT TestQueueDeduplication2302=== CONT TestQueueEnqueueAndFetch2303=== CONT TestWorkerSkipsGCdPaths2304=== CONT TestDrainTimeout2305=== CONT TestWorkerPrunesClosureDeps2306=== CONT TestServerQueueError2307=== CONT TestRunNotBlockedByPoisonHead2308=== CONT TestDrainIsolatesPoisonPath2309=== CONT TestWorkerUploadsAndRemoves2310=== CONT TestQueueRemoveLargeClosure2311=== CONT TestServerClientIntegration23122026/10/06 10:52:58 ERROR Failed to queue paths error="permission denied" count=12313--- PASS: TestSendPathsEmpty (0.00s)2314--- PASS: TestServerQueueError (0.00s)2315--- PASS: TestServerClientIntegration (0.00s)23162026/10/06 10:52:58 INFO Upload queue status pending=323172026/10/06 10:52:58 INFO Uploading batch count=123182026/10/06 10:52:58 ERROR Upload failed error="upload failed" count=123192026/10/06 10:52:58 INFO Uploading batch count=12320--- PASS: TestQueueEnqueueAndFetch (0.01s)23212026/10/06 10:52:58 ERROR Upload failed error="upload failed" count=123222026/10/06 10:52:58 INFO Uploading batch count=22323--- PASS: TestQueueDeduplication (0.01s)23242026/10/06 10:52:58 INFO Uploading batch count=223252026/10/06 10:52:58 ERROR Upload failed error="upload failed" count=223262026/10/06 10:52:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1493104758/002/a23272026/10/06 10:52:58 INFO Uploading batch count=423282026/10/06 10:52:58 INFO Uploading batch count=123292026/10/06 10:52:58 ERROR Upload failed error="upload failed" count=42330--- PASS: TestQueueFetchBatchLimit (0.01s)23312026/10/06 10:52:58 INFO Upload queue status pending=223322026/10/06 10:52:58 INFO Uploading batch count=223332026/10/06 10:52:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1493104758/002/b2334--- PASS: TestQueueRetryMovesToBack (0.01s)23352026/10/06 10:52:58 INFO Uploading batch count=123362026/10/06 10:52:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3272033802/002/bbb23372026/10/06 10:52:58 INFO Upload queue status pending=223382026/10/06 10:52:58 INFO Uploading batch count=223392026/10/06 10:52:58 ERROR Upload failed error="upload failed" count=223402026/10/06 10:52:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2088404058/002/nonexistent2341--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23422026/10/06 10:52:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1493104758/002/c23432026/10/06 10:52:58 INFO Upload queue status pending=223442026/10/06 10:52:58 INFO Uploading batch count=12345--- PASS: TestQueueRemove (0.02s)23462026/10/06 10:52:58 INFO Uploading batch count=123472026/10/06 10:52:58 ERROR Upload failed error="upload failed" count=123482026/10/06 10:52:58 INFO Uploading batch count=123492026/10/06 10:52:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1493104758/002/d23502026/10/06 10:52:58 INFO Uploading batch count=123512026/10/06 10:52:58 ERROR Upload failed error="upload failed" count=123522026/10/06 10:52:58 INFO Uploading batch count=223532026/10/06 10:52:58 ERROR Upload failed error="upload failed" count=223542026/10/06 10:52:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1493104758/002/e2355--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23562026/10/06 10:52:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1493104758/002/f23572026/10/06 10:52:58 INFO Uploading batch count=123582026/10/06 10:52:58 ERROR Upload failed error="upload failed" count=123592026/10/06 10:52:58 ERROR Drain finished with paths left in queue remaining=1023602026/10/06 10:52:58 ERROR Drain finished with paths left in queue remaining=12361--- PASS: TestDrainIsolatesPoisonPath (0.02s)2362--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2363--- PASS: TestWorkerUploadsAndRemoves (0.03s)2364--- PASS: TestWorkerSkipsGCdPaths (0.03s)2365--- PASS: TestWorkerPrunesClosureDeps (0.03s)2366--- PASS: TestQueueRemoveLargeClosure (0.08s)2367--- PASS: TestQueueConcurrentWriters (0.16s)23682026/10/06 10:52:58 ERROR Upload failed error="context deadline exceeded" count=223692026/10/06 10:52:58 ERROR Drain finished with paths left in queue remaining=42370--- PASS: TestDrainTimeout (0.21s)23712026/10/06 10:52:59 INFO Uploading batch count=123722026/10/06 10:52:59 INFO Uploading batch count=123732026/10/06 10:52:59 INFO Uploading batch count=123742026/10/06 10:52:59 ERROR Upload failed error="upload failed" count=123752026/10/06 10:52:59 INFO Uploading batch count=123762026/10/06 10:52:59 ERROR Upload failed error="upload failed" count=123772026/10/06 10:52:59 INFO Uploading batch count=123782026/10/06 10:52:59 ERROR Upload failed error="upload failed" count=123792026/10/06 10:52:59 INFO Uploading batch count=123802026/10/06 10:52:59 ERROR Upload failed error="upload failed" count=123812026/10/06 10:52:59 ERROR Drain finished with paths left in queue remaining=12382--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2383PASS2384Running signing tests...2385=== RUN TestExternalSigner2386=== PAUSE TestExternalSigner2387=== RUN TestExternalSignerWrongPublicKey2388=== PAUSE TestExternalSignerWrongPublicKey2389=== RUN TestExternalSignerErrors2390=== PAUSE TestExternalSignerErrors2391=== RUN TestExternalSignerRestartsAfterCrash2392=== PAUSE TestExternalSignerRestartsAfterCrash2393=== RUN TestExternalSignerProgramErrorKeepsProcess2394=== PAUSE TestExternalSignerProgramErrorKeepsProcess2395=== RUN TestExternalSignerClose2396=== PAUSE TestExternalSignerClose2397=== RUN TestExternalSignerRejectsInvalidPublicKey2398=== PAUSE TestExternalSignerRejectsInvalidPublicKey2399=== RUN TestExternalSignerCancellation2400=== PAUSE TestExternalSignerCancellation2401=== RUN TestGenerateFingerprint2402=== PAUSE TestGenerateFingerprint2403=== RUN TestParseSigningKey2404=== PAUSE TestParseSigningKey2405=== RUN TestSign2406=== PAUSE TestSign2407=== RUN TestSignBatch2408=== PAUSE TestSignBatch2409=== RUN TestNilKeyPublicKey2410=== PAUSE TestNilKeyPublicKey2411=== RUN TestSignErrors2412=== PAUSE TestSignErrors2413=== CONT TestExternalSigner2414=== CONT TestExternalSignerCancellation2415=== CONT TestExternalSignerWrongPublicKey2416=== CONT TestSignBatch2417=== CONT TestParseSigningKey2418=== RUN TestParseSigningKey/valid_32-byte_key2419=== PAUSE TestParseSigningKey/valid_32-byte_key2420=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2421=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2422=== RUN TestParseSigningKey/no_colon2423=== PAUSE TestParseSigningKey/no_colon2424=== RUN TestParseSigningKey/empty_name2425=== PAUSE TestParseSigningKey/empty_name2426=== CONT TestSignErrors2427=== CONT TestNilKeyPublicKey2428--- PASS: TestNilKeyPublicKey (0.00s)2429=== CONT TestSign2430=== CONT TestGenerateFingerprint2431=== RUN TestGenerateFingerprint/basic_with_references2432=== CONT TestExternalSignerProgramErrorKeepsProcess2433=== CONT TestExternalSignerRejectsInvalidPublicKey2434=== RUN TestExternalSignerRejectsInvalidPublicKey/#002435=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002436=== CONT TestExternalSignerClose2437=== CONT TestExternalSignerErrors2438=== RUN TestExternalSignerErrors/program_error2439=== CONT TestExternalSignerRestartsAfterCrash2440=== RUN TestParseSigningKey/invalid_base642441=== PAUSE TestExternalSignerErrors/program_error2442=== RUN TestExternalSignerErrors/exit_at_startup2443=== PAUSE TestExternalSignerErrors/exit_at_startup2444=== RUN TestExternalSignerErrors/wrong_shape2445=== PAUSE TestParseSigningKey/invalid_base642446=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2447=== RUN TestParseSigningKey/wrong_length2448=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2449=== PAUSE TestParseSigningKey/wrong_length2450=== CONT TestParseSigningKey/valid_32-byte_key2451=== CONT TestParseSigningKey/wrong_length2452=== PAUSE TestGenerateFingerprint/basic_with_references2453=== CONT TestParseSigningKey/no_colon2454=== PAUSE TestExternalSignerErrors/wrong_shape2455=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2456=== CONT TestParseSigningKey/empty_name2457=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2458=== CONT TestParseSigningKey/invalid_base642459=== RUN TestGenerateFingerprint/no_references2460=== PAUSE TestGenerateFingerprint/no_references2461=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2462=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2463=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2464=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2465=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2466=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2467=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2468=== CONT TestExternalSignerRejectsInvalidPublicKey/#002469=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2470=== RUN TestExternalSignerErrors/wrong_signatures_shape2471=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2472=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2473=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2474=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2475=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2476=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2477--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2478 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2479 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2480 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2481 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2482 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2483=== RUN TestExternalSignerErrors/too_few_signatures2484=== PAUSE TestExternalSignerErrors/too_few_signatures2485=== RUN TestExternalSignerErrors/missing_signature_name2486=== PAUSE TestExternalSignerErrors/missing_signature_name2487=== RUN TestExternalSignerErrors/wrong_signature_name2488=== PAUSE TestExternalSignerErrors/wrong_signature_name2489=== RUN TestExternalSignerErrors/invalid_JSON2490=== PAUSE TestExternalSignerErrors/invalid_JSON2491=== RUN TestExternalSignerErrors/null2492=== PAUSE TestExternalSignerErrors/null2493=== RUN TestExternalSignerErrors/wrong_id2494=== PAUSE TestExternalSignerErrors/wrong_id2495=== RUN TestExternalSignerErrors/missing_signatures2496=== PAUSE TestExternalSignerErrors/missing_signatures2497=== RUN TestGenerateFingerprint/invalid_nar_hash_length2498=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2499=== RUN TestGenerateFingerprint/invalid_store_path_prefix2500=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2501=== RUN TestGenerateFingerprint/invalid_reference_prefix2502=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2503=== CONT TestGenerateFingerprint/basic_with_references2504=== RUN TestSignErrors/nil_key2505=== PAUSE TestSignErrors/nil_key2506=== RUN TestSignErrors/nil_narinfo2507--- PASS: TestParseSigningKey (0.00s)2508 --- PASS: TestParseSigningKey/wrong_length (0.00s)2509 --- PASS: TestParseSigningKey/no_colon (0.00s)2510 --- PASS: TestParseSigningKey/empty_name (0.00s)2511 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2512 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2513 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2514=== RUN TestExternalSignerErrors/wrong_signature_length2515=== CONT TestGenerateFingerprint/invalid_nar_hash_length2516=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2517=== CONT TestGenerateFingerprint/invalid_reference_prefix2518=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2519=== CONT TestGenerateFingerprint/no_references2520=== CONT TestGenerateFingerprint/invalid_store_path_prefix2521=== PAUSE TestSignErrors/nil_narinfo2522=== RUN TestSignErrors/invalid_narinfo2523--- PASS: TestSign (0.00s)2524=== PAUSE TestExternalSignerErrors/wrong_signature_length2525=== RUN TestExternalSignerErrors/invalid_signature_base642526--- PASS: TestGenerateFingerprint (0.00s)2527 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2528 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2529 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2530 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2531 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2532 --- PASS: TestGenerateFingerprint/no_references (0.00s)2533 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2534--- PASS: TestSignBatch (0.00s)2535=== PAUSE TestExternalSignerErrors/invalid_signature_base642536=== PAUSE TestSignErrors/invalid_narinfo2537=== RUN TestExternalSignerErrors/exit_on_request2538=== PAUSE TestExternalSignerErrors/exit_on_request2539=== RUN TestExternalSignerErrors/null_signatures2540=== PAUSE TestExternalSignerErrors/null_signatures2541=== RUN TestExternalSignerErrors/unrequested_key2542=== PAUSE TestExternalSignerErrors/unrequested_key2543=== CONT TestExternalSignerErrors/program_error2544=== CONT TestExternalSignerErrors/wrong_id2545=== CONT TestExternalSignerErrors/exit_on_request2546=== CONT TestExternalSignerErrors/exit_at_startup2547=== CONT TestExternalSignerErrors/missing_signature_name2548=== RUN TestSignErrors/canceled2549=== PAUSE TestSignErrors/canceled2550=== CONT TestSignErrors/nil_key2551=== CONT TestSignErrors/canceled2552=== CONT TestSignErrors/invalid_narinfo2553=== CONT TestExternalSignerErrors/wrong_signature_length2554=== CONT TestSignErrors/nil_narinfo2555--- PASS: TestSignErrors (0.00s)2556 --- PASS: TestSignErrors/nil_key (0.00s)2557 --- PASS: TestSignErrors/canceled (0.00s)2558 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2559 --- PASS: TestSignErrors/nil_narinfo (0.00s)2560=== CONT TestExternalSignerErrors/wrong_signature_name2561=== CONT TestExternalSignerErrors/invalid_JSON2562=== CONT TestExternalSignerErrors/null2563=== CONT TestExternalSignerErrors/invalid_signature_base642564=== CONT TestExternalSignerErrors/missing_signatures2565=== CONT TestExternalSignerErrors/wrong_signatures_shape2566=== CONT TestExternalSignerErrors/too_few_signatures2567=== CONT TestExternalSignerErrors/unrequested_key2568=== CONT TestExternalSignerErrors/null_signatures2569=== CONT TestExternalSignerErrors/wrong_shape2570--- PASS: TestExternalSignerClose (0.01s)2571--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2572--- PASS: TestExternalSignerWrongPublicKey (0.01s)2573--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2574--- PASS: TestExternalSigner (0.01s)2575--- PASS: TestExternalSignerErrors (0.00s)2576 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2577 --- PASS: TestExternalSignerErrors/program_error (0.01s)2578 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2579 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2580 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2581 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2582 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2583 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2584 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2585 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2586 --- PASS: TestExternalSignerErrors/null (0.00s)2587 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2588 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2589 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2590 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2591 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2592--- PASS: TestExternalSignerCancellation (0.02s)2593PASS2594Running OpenBao signer tests...2595=== RUN TestSign2596=== PAUSE TestSign2597=== RUN TestSignErrors2598=== PAUSE TestSignErrors2599=== RUN TestServe2600=== PAUSE TestServe2601=== RUN TestServeRejectsGarbage2602=== PAUSE TestServeRejectsGarbage2603=== CONT TestSign2604=== CONT TestSignErrors2605=== CONT TestServe2606=== CONT TestServeRejectsGarbage2607--- PASS: TestServeRejectsGarbage (0.00s)2608=== RUN TestSignErrors/http_error2609=== PAUSE TestSignErrors/http_error2610=== RUN TestSignErrors/invalid_json2611=== PAUSE TestSignErrors/invalid_json2612=== RUN TestSignErrors/no_prefix2613=== PAUSE TestSignErrors/no_prefix2614=== RUN TestSignErrors/invalid_base642615=== PAUSE TestSignErrors/invalid_base642616=== CONT TestSignErrors/http_error2617=== CONT TestSignErrors/no_prefix2618--- PASS: TestServe (0.00s)2619=== CONT TestSignErrors/invalid_json2620=== CONT TestSignErrors/invalid_base642621--- PASS: TestSign (0.00s)2622--- PASS: TestSignErrors (0.00s)2623 --- PASS: TestSignErrors/invalid_json (0.00s)2624 --- PASS: TestSignErrors/invalid_base64 (0.00s)2625 --- PASS: TestSignErrors/no_prefix (0.00s)2626 --- PASS: TestSignErrors/http_error (0.00s)2627PASS