niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #388
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestEncodeNixBase32102=== CONT TestParsePathInfoJSON103=== RUN TestParsePathInfoJSON/Nix_format104=== PAUSE TestParsePathInfoJSON/Nix_format105=== RUN TestParsePathInfoJSON/Lix_format106=== PAUSE TestParsePathInfoJSON/Lix_format107=== RUN TestParsePathInfoJSON/empty_input108=== PAUSE TestParsePathInfoJSON/empty_input109=== RUN TestParsePathInfoJSON/whitespace_only110=== PAUSE TestParsePathInfoJSON/whitespace_only111=== RUN TestParsePathInfoJSON/invalid_JSON112=== PAUSE TestParsePathInfoJSON/invalid_JSON113=== CONT TestPathInfoHashCompatibility114=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)115=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)116=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon117=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon118=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI119=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI120=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512121=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512122=== CONT TestScriptTokenBadJSON123=== CONT TestGetStorePathHash124=== RUN TestGetStorePathHash/valid_store_path125=== PAUSE TestGetStorePathHash/valid_store_path126=== CONT TestConvertHashToNix32127=== CONT TestEncodeNixBase32WithRealHash128=== CONT TestParsePathInfoJSONMultiplePaths129=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess130=== CONT TestRateLimiterFeedback131=== CONT TestResolveStorePath132=== CONT TestPathInfoCACompatibility133=== CONT TestStreamPushGivesUpOnDeadServer134=== CONT TestSetClientTLSDoesNotMutateDefaultTransport135=== CONT TestUploadMultipart_PartsInParallel136=== CONT TestSetClientTLSErrors137=== CONT TestDumpPathWriterError138=== CONT TestSetClientTLS139=== CONT TestScriptTokenEmptyCommand140=== CONT TestDumpPathSingleFile141=== CONT TestScriptTokenScriptFails142=== CONT TestClientSignaturesByStorePath143=== CONT TestDumpPathMatchesNix144=== RUN TestEncodeNixBase32/test_string_hash145=== CONT TestStreamPushReportsSignatures146=== RUN TestRateLimiterFeedback/429_enables_limiter147=== RUN TestConvertHashToNix32/SRI_format_to_Nix32148=== RUN TestGetStorePathHash/basename_without_hyphen_should_error149=== PAUSE TestRateLimiterFeedback/429_enables_limiter150=== CONT TestUploadMultipart_SupersededByPeer151--- PASS: TestScriptTokenEmptyCommand (0.00s)152=== CONT TestScriptTokenEmptyToken153--- PASS: TestEncodeNixBase32WithRealHash (0.00s)154--- PASS: TestResolveStorePath (0.00s)155--- PASS: TestScriptTokenBadJSON (0.00s)156--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)157=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths158--- PASS: TestClientSignaturesByStorePath (0.00s)159=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths160=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths161=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths162=== RUN TestUploadMultipart_SupersededByPeer/exists163=== PAUSE TestUploadMultipart_SupersededByPeer/exists164=== RUN TestUploadMultipart_SupersededByPeer/missing165=== PAUSE TestUploadMultipart_SupersededByPeer/missing166=== CONT TestFileTokenReadsAndCaches167=== CONT TestStreamPushRequestLine1682026/10/06 21:27:29 ERROR Upload failed error=boom count=1169=== CONT TestScriptTokenCachesUntilRefresh1702026/10/06 21:27:29 WARN Rate limiter enabled after throttle name=server-test rate=51712026/10/06 21:27:29 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40299172=== RUN TestRateLimiterFeedback/503_enables_limiter173=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun1742026/10/06 21:27:29 WARN Rate limiter backed off name=server-test rate=5175=== CONT TestStaticToken1762026/10/06 21:27:29 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40299177=== CONT TestFilterOversizedClosures1782026/10/06 21:27:29 ERROR Upload failed error=boom count=1179=== RUN TestFilterOversizedClosures/no_limit_keeps_everything180=== CONT TestCaseHackSuffix181=== CONT TestPartSizeForNAR182=== RUN TestPartSizeForNAR/zero_stays_at_minimum183=== CONT TestShellSplitErrors184=== CONT TestStreamPushReportsEveryPath185=== CONT TestShellSplit186=== CONT TestStreamPushIsolatesFailures1872026/10/06 21:27:29 ERROR Upload failed error="bad path" count=3188=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica1892026/10/06 21:27:29 INFO Garbage collection started1902026/10/06 21:27:29 ERROR Upload failed error="connection refused" count=201912026/10/06 21:27:29 ERROR Server seems unavailable, giving up on batch untried=17192--- PASS: TestStreamPushReportsSignatures (0.04s)193--- PASS: TestDoServerRequestAttachesToken (0.04s)194--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)195--- PASS: TestScriptTokenScriptFails (0.03s)196--- PASS: TestShellSplitErrors (0.00s)197--- PASS: TestFileTokenReadsAndCaches (0.00s)198--- PASS: TestShellSplit (0.00s)199--- PASS: TestStreamPushIsolatesFailures (0.00s)200--- PASS: TestScriptTokenEmptyToken (0.03s)201--- PASS: TestStreamPushReportsEveryPath (0.00s)202--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)203=== CONT TestScriptTokenNoExpiryRerunsEveryCall204=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything205=== CONT TestStreamPushBatchesUnderLoad206=== CONT TestRegisterUploadedObjectReusesConnections207=== RUN TestPathInfoCACompatibility/null_ca_field208=== CONT TestFileTokenEmpty209=== RUN TestSetClientTLSErrors/missing_cert_file210=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error211=== PAUSE TestRateLimiterFeedback/503_enables_limiter212=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error213=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32214=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error215=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter216=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter217=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter218=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter219=== PAUSE TestSetClientTLSErrors/missing_cert_file220=== RUN TestConvertHashToNix32/already_Nix32_format221=== CONT TestFileTokenMissing222=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error223=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error224=== RUN TestSetClientTLSErrors/missing_key_file225=== PAUSE TestSetClientTLSErrors/missing_key_file226=== RUN TestSetClientTLSErrors/missing_ca_file227=== PAUSE TestSetClientTLSErrors/missing_ca_file228=== RUN TestSetClientTLSErrors/invalid_ca_file229=== PAUSE TestSetClientTLSErrors/invalid_ca_file230=== CONT TestParsePathInfoJSON/Nix_format231=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)2322026/10/06 21:27:29 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=0233--- PASS: TestStaticToken (0.00s)234=== PAUSE TestConvertHashToNix32/already_Nix32_format235=== CONT TestParsePathInfoJSON/whitespace_only236=== RUN TestConvertHashToNix32/invalid_format237=== PAUSE TestEncodeNixBase32/test_string_hash238=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum239=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon240=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512241=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI242--- PASS: TestFileTokenEmpty (0.00s)2432026/10/06 21:27:29 WARN Rate limiter enabled after throttle name=server-test rate=5244=== CONT TestParsePathInfoJSON/invalid_JSON245=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2462026/10/06 21:27:29 INFO Garbage collection started247=== CONT TestUploadMultipart_SupersededByPeer/missing248=== RUN TestSetClientTLS/rejects_connection_without_client_cert249=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert250=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA251=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA252=== PAUSE TestConvertHashToNix32/invalid_format253=== CONT TestParsePathInfoJSON/empty_input254=== RUN TestEncodeNixBase32/empty_input255=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped256=== RUN TestPartSizeForNAR/small_stays_at_minimum257=== CONT TestParsePathInfoJSON/Lix_format258=== PAUSE TestPathInfoCACompatibility/null_ca_field2592026/10/06 21:27:29 WARN Garbage collection finished on another replica. Its statistics are not available here260=== CONT TestUploadMultipart_SupersededByPeer/exists261=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths262--- PASS: TestFileTokenMissing (0.00s)263=== RUN TestSetClientTLS/preserves_debug_logging_transport264=== CONT TestRateLimiterFeedback/429_enables_limiter265=== PAUSE TestPartSizeForNAR/small_stays_at_minimum266=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum267=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum268=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts269=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts270=== RUN TestPartSizeForNAR/1_TiB271=== PAUSE TestPartSizeForNAR/1_TiB272=== RUN TestPartSizeForNAR/5_TiB_S3_max_object273=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object274=== RUN TestPartSizeForNAR/capped_at_5_GiB275=== PAUSE TestPartSizeForNAR/capped_at_5_GiB276=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter277=== RUN TestPathInfoCACompatibility/old_string_format_-_text278=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text279=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive280=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive281=== RUN TestPathInfoCACompatibility/new_structured_format_-_text282=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text283=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method284=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method285=== CONT TestRateLimiterFeedback/503_enables_limiter286=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2872026/10/06 21:27:29 WARN Rate limiter enabled after throttle name=server-test rate=52882026/10/06 21:27:29 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:43329289=== CONT TestGetStorePathHash/valid_store_path290=== CONT TestSetClientTLSErrors/invalid_ca_file291=== CONT TestSetClientTLSErrors/missing_key_file2922026/10/06 21:27:29 WARN Rate limiter backed off name=server-test rate=5293=== CONT TestGetStorePathHash/basename_without_hyphen_should_error294=== CONT TestConvertHashToNix32/SRI_format_to_Nix32295=== CONT TestPartSizeForNAR/zero_stays_at_minimum296=== CONT TestPartSizeForNAR/1_TiB297=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts298=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum299=== CONT TestPartSizeForNAR/small_stays_at_minimum300=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method301=== CONT TestPathInfoCACompatibility/new_structured_format_-_text302=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive303=== CONT TestPathInfoCACompatibility/old_string_format_-_text304=== CONT TestConvertHashToNix32/invalid_format305=== CONT TestConvertHashToNix32/already_Nix32_format306=== CONT TestPartSizeForNAR/capped_at_5_GiB307=== CONT TestSetClientTLSErrors/missing_ca_file308=== CONT TestPathInfoCACompatibility/null_ca_field309--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)310=== CONT TestPartSizeForNAR/5_TiB_S3_max_object311=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error312=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error313=== PAUSE TestSetClientTLS/preserves_debug_logging_transport314=== CONT TestSetClientTLS/rejects_connection_without_client_cert3152026/10/06 21:27:29 WARN Rate limiter enabled after throttle name=server-test rate=5316=== CONT TestSetClientTLS/preserves_debug_logging_transport3172026/10/06 21:27:29 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39475318=== CONT TestSetClientTLSErrors/missing_cert_file319=== PAUSE TestEncodeNixBase32/empty_input320=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped321--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)322--- PASS: TestParsePathInfoJSON (0.00s)323 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)324 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)325 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)326 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)327 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3282026/10/06 21:27:29 WARN Rate limiter backed off name=server-test rate=5329=== CONT TestEncodeNixBase32/test_string_hash330=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA331=== CONT TestEncodeNixBase32/empty_input332=== RUN TestFilterOversizedClosures/all_closures_skipped333=== PAUSE TestFilterOversizedClosures/all_closures_skipped334=== CONT TestFilterOversizedClosures/no_limit_keeps_everything335=== CONT TestFilterOversizedClosures/all_closures_skipped3362026/10/06 21:27:29 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=50337--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)338 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)339 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)340=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3412026/10/06 21:27:29 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=2000342--- PASS: TestPathInfoHashCompatibility (0.00s)343 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)344 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)345 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)346 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)347--- PASS: TestConvertHashToNix32 (0.04s)348 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)349 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)350 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)351--- PASS: TestPartSizeForNAR (0.01s)352 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)353 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)354 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)355 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)356 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)357 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)358 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)359--- PASS: TestEncodeNixBase32 (0.05s)360 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)361 --- PASS: TestEncodeNixBase32/empty_input (0.00s)362--- PASS: TestFilterOversizedClosures (0.01s)363 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)364 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)365 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)366--- PASS: TestRateLimiterFeedback (0.04s)367 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)368 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)369 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)370 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)371--- PASS: TestGetStorePathHash (0.04s)372 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)373 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)374 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)375 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)376--- PASS: TestPathInfoCACompatibility (0.00s)377 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)378 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)379 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)380 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)381 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)382--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)383 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)384 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)385--- PASS: TestSetClientTLSErrors (0.00s)386 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)387 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)388 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)390--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)391--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)3922026/10/06 21:27:29 http: TLS handshake error from 127.0.0.1:50294: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.01s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)397--- PASS: TestStreamPushRequestLine (0.02s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)399--- PASS: TestCaseHackSuffix (0.04s)400--- PASS: TestDumpPathSingleFile (0.07s)401--- PASS: TestDumpPathWriterError (0.08s)402--- PASS: TestDumpPathMatchesNix (0.08s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres2878205599/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/postgres2878205599/data -l logfile start434435/build/postgres2878205599:5432 - no response4362026-10-06 21:27:31.161 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 21:27:31.161 UTC [129] LOG: listening on Unix socket "/build/postgres2878205599/.s.PGSQL.5432"4382026-10-06 21:27:31.165 UTC [136] LOG: database system was shut down at 2026-10-06 21:27:30 UTC4392026-10-06 21:27:31.171 UTC [129] LOG: database system is ready to accept connections440/build/postgres2878205599:5432 - accepting connections441{"timestamp":"2026-10-06T21:27:31.468311674Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a9b17151-a4ad-4f7c-97fe-9c164d2555a6","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(392)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/06 21:27:31 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 21:27:32 INFO lead: released remote=192.0.2.1:12344912026/10/06 21:27:32 INFO lead: acquired remote=192.0.2.1:12344922026/10/06 21:27:33 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/06 21:27:33 INFO lead: acquired remote=192.0.2.1:12345002026-10-06 21:27:34.975 UTC [580] FATAL: terminating connection due to administrator command5012026/10/06 21:27:35 INFO lead: acquired remote=192.0.2.1:12345022026/10/06 21:27:36 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/06 21:27:36 INFO lead: released remote=192.0.2.1:12345042026/10/06 21:27:36 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (2.92s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestService_NativeMTLS575=== PAUSE TestService_NativeMTLS576=== RUN TestServerTLSConfig577=== PAUSE TestServerTLSConfig578=== RUN TestMultipartCleanup579=== PAUSE TestMultipartCleanup580=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== RUN TestPendingCleanupUsesOneCutoff583=== PAUSE TestPendingCleanupUsesOneCutoff584=== RUN TestObjectStatsTrigger585=== PAUSE TestObjectStatsTrigger586=== RUN TestOrphanedObjectsGC587=== PAUSE TestOrphanedObjectsGC588=== RUN TestOrphanedObjectsGCStressTest589=== PAUSE TestOrphanedObjectsGCStressTest590=== RUN TestCreatePin_ReservedPins591=== PAUSE TestCreatePin_ReservedPins592=== RUN TestPresentReportsOnlyClosureRoots593=== PAUSE TestPresentReportsOnlyClosureRoots594=== RUN TestPresentRefreshesOnlyStaleClosures595=== PAUSE TestPresentRefreshesOnlyStaleClosures596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyContentNegotiation609=== PAUSE TestReadProxyContentNegotiation610=== RUN TestReadProxyNarStreaming611=== PAUSE TestReadProxyNarStreaming612=== RUN TestReadProxy404613=== PAUSE TestReadProxy404614=== RUN TestReadProxyInvalidPath615=== PAUSE TestReadProxyInvalidPath616=== RUN TestReadProxyHead617=== PAUSE TestReadProxyHead618=== RUN TestReadProxyOutlastsServerWriteTimeout619=== PAUSE TestReadProxyOutlastsServerWriteTimeout620=== RUN TestReadProxyConditionalGet621=== PAUSE TestReadProxyConditionalGet622=== RUN TestReadProxyRootRedirectsToIndexHTML623=== PAUSE TestReadProxyRootRedirectsToIndexHTML624=== RUN TestReadProxyDisabled625=== PAUSE TestReadProxyDisabled626=== RUN TestReadRedirectNar627=== PAUSE TestReadRedirectNar628=== RUN TestReadRedirectKeepsNarinfoProxied629=== PAUSE TestReadRedirectKeepsNarinfoProxied630=== RUN TestReadProxyRangeRequest631=== PAUSE TestReadProxyRangeRequest632=== RUN TestReadRedirectUsesPublicS3URL633=== PAUSE TestReadRedirectUsesPublicS3URL634=== RUN TestPush_OverlappingRootsStoreOneRowPerKey635=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey636=== RUN TestPush_CompleteCommitsEveryRoot637=== PAUSE TestPush_CompleteCommitsEveryRoot638=== RUN TestPush_RepeatedRootCommitsOnce639=== PAUSE TestPush_RepeatedRootCommitsOnce640=== RUN TestPush_CompleteWaitsForCleanupOfThePush641=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush642=== RUN TestPush_RootsAreLockedInByteOrder643=== PAUSE TestPush_RootsAreLockedInByteOrder644=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit645=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit646=== RUN TestPush_RejectsBadRequests647=== PAUSE TestPush_RejectsBadRequests648=== RUN TestPush_SignsNarinfosOfItsPendingObjects649=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects650=== RUN TestRedundantMultipartUpload651=== PAUSE TestRedundantMultipartUpload652=== RUN TestCompleteMultipartUpload_ErrorButObjectExists653=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists654=== RUN TestCompletedNarNotReofferedAcrossClosures655=== PAUSE TestCompletedNarNotReofferedAcrossClosures656=== RUN TestPresignedUploadRegisteredBeforeCommit657=== PAUSE TestPresignedUploadRegisteredBeforeCommit658=== RUN TestService_Rustfstest659=== PAUSE TestService_Rustfstest660=== RUN TestParseSize661=== PAUSE TestParseSize662=== RUN TestSkippedUploadsHandler663=== PAUSE TestSkippedUploadsHandler664=== RUN TestSystemdListenerNotActivated665--- PASS: TestSystemdListenerNotActivated (0.00s)666=== RUN TestWatchdogBeatsWhenHealthy667--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)668=== RUN TestWatchdogSkipsWhenUnhealthy6692026/10/06 21:27:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:27:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:27:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 21:27:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 21:27:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 21:27:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/06 21:27:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6762026/10/06 21:27:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/06 21:27:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/06 21:27:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"679--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)680=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle681=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle682=== RUN TestProxyWriteTimeout683=== PAUSE TestProxyWriteTimeout684=== RUN TestPendingClosureWriteTimeout685=== PAUSE TestPendingClosureWriteTimeout686=== RUN TestIsValidUploadKey687=== PAUSE TestIsValidUploadKey688=== RUN TestUploadHandlersRejectInvalidKeys689=== PAUSE TestUploadHandlersRejectInvalidKeys690=== RUN TestUploadHandlersRejectOversizedBody691=== PAUSE TestUploadHandlersRejectOversizedBody692=== RUN TestService_cleanupPendingClosuresHandler693=== PAUSE TestService_cleanupPendingClosuresHandler694=== RUN TestService_createPendingClosureHandler695=== PAUSE TestService_createPendingClosureHandler696=== RUN TestService_verifyS3Integrity697=== PAUSE TestService_verifyS3Integrity698=== RUN TestCompleteMultipartUnregistered699=== PAUSE TestCompleteMultipartUnregistered700=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT701=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT702=== CONT TestService_AuthMiddleware703=== CONT TestSkippedUploadsHandler704=== CONT TestMultipartCleanup705=== CONT TestTombstonedObjectOfferedWithoutWaiting7062026/10/06 21:27:36 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000707=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT708=== CONT TestCompleteMultipartUnregistered709=== CONT TestService_verifyS3Integrity710=== CONT TestService_createPendingClosureHandler711=== CONT TestService_cleanupPendingClosuresHandler712=== CONT TestUploadHandlersRejectOversizedBody713=== CONT TestUploadHandlersRejectInvalidKeys714=== CONT TestIsValidUploadKey715=== CONT TestPendingClosureWriteTimeout716=== RUN TestPendingClosureWriteTimeout/empty717=== CONT TestProxyWriteTimeout718=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle719=== CONT TestServerTLSConfig720=== CONT TestService_NativeMTLS721=== CONT TestMetricsInventory722=== CONT TestNARDeduplicationMetadataUploadBug723=== CONT TestCreatePendingClosureRejectsOversizedNAR724=== CONT TestCacheConfigHandlerMaxNarSize725=== CONT TestGenerateLandingPage726=== CONT TestService_readinessHandler727=== CONT TestService_healthCheckHandler728=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info729=== RUN TestIsValidUploadKey/narinfo730=== PAUSE TestIsValidUploadKey/narinfo731=== RUN TestIsValidUploadKey/nar_zst732=== PAUSE TestIsValidUploadKey/nar_zst733=== RUN TestIsValidUploadKey/nar_xz734=== PAUSE TestIsValidUploadKey/nar_xz735=== RUN TestIsValidUploadKey/nar_plain736=== PAUSE TestIsValidUploadKey/nar_plain737=== RUN TestIsValidUploadKey/listing738=== PAUSE TestIsValidUploadKey/listing739=== RUN TestIsValidUploadKey/build_log740=== PAUSE TestIsValidUploadKey/build_log741=== RUN TestIsValidUploadKey/build_log_home-manager_file742=== PAUSE TestPendingClosureWriteTimeout/empty743=== RUN TestPendingClosureWriteTimeout/400_objects744=== RUN TestProxyWriteTimeout/narinfo745=== RUN TestServerTLSConfig/no_client_CA746--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)7472026/10/06 21:27:36 INFO Received uploads request method=POST path=/api/pending_closures748=== CONT TestGracefulShutdownDrainsInflight749--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)750=== CONT TestGCTaskStore_Fail751--- PASS: TestGCTaskStore_Fail (0.00s)752=== PAUSE TestIsValidUploadKey/build_log_home-manager_file753=== CONT TestGCTaskStore_PhaseUpdates754--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)755=== CONT TestGCTaskStore_CompletedAllowsNewTask756--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)757=== RUN TestIsValidUploadKey/build_log_plus_in_name758=== PAUSE TestIsValidUploadKey/build_log_plus_in_name759=== RUN TestIsValidUploadKey/build_log_question_mark760=== PAUSE TestIsValidUploadKey/build_log_question_mark761=== PAUSE TestProxyWriteTimeout/narinfo762=== CONT TestGCTaskStore_GetReturnsLatest763=== RUN TestProxyWriteTimeout/1_GiB_nar764=== RUN TestIsValidUploadKey/build_log_equals765--- PASS: TestGenerateLandingPage (0.00s)766=== CONT TestGCTaskStore_GetEmpty767=== CONT TestGCTaskStore_DeduplicateSameParams7682026/10/06 21:27:36 INFO Starting HTTP server address=127.0.0.1:34721769--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)770=== CONT TestGCTaskStore_ConflictDifferentParams771--- PASS: TestGCTaskStore_GetEmpty (0.00s)772--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)773--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)774=== CONT TestGCEndsOnShutdown775=== RUN TestGCEndsOnShutdown/before_the_run776=== PAUSE TestIsValidUploadKey/build_log_equals7772026/10/06 21:27:36 INFO Shutdown signal received, draining in-flight requests timeout=10s778=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info779=== PAUSE TestPendingClosureWriteTimeout/400_objects780=== PAUSE TestServerTLSConfig/no_client_CA781=== CONT TestGCTaskStore_StartNew782=== PAUSE TestProxyWriteTimeout/1_GiB_nar783=== PAUSE TestGCEndsOnShutdown/before_the_run784=== CONT TestCommitRacingPendingCleanupKeepsObjects785=== RUN TestIsValidUploadKey/realisation786=== PAUSE TestIsValidUploadKey/realisation787=== RUN TestIsValidUploadKey/realisation_plus_in_output788=== PAUSE TestIsValidUploadKey/realisation_plus_in_output789=== RUN TestIsValidUploadKey/nix-cache-info790=== PAUSE TestIsValidUploadKey/nix-cache-info791=== RUN TestPendingClosureWriteTimeout/670k_objects792=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal793=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal794=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key795--- PASS: TestGCTaskStore_StartNew (0.00s)796--- PASS: TestSkippedUploadsHandler (0.10s)797=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete798=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete799=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark800=== RUN TestServerTLSConfig/missing_CA_file801=== RUN TestProxyWriteTimeout/10_GiB_nar802=== PAUSE TestProxyWriteTimeout/10_GiB_nar803=== RUN TestIsValidUploadKey/index.html804=== PAUSE TestIsValidUploadKey/index.html805=== CONT TestPushWaitsForSweepHoldingRow806=== PAUSE TestPendingClosureWriteTimeout/670k_objects807=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline808=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline809=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key810=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key811=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key812=== CONT TestGetExistingObjectsLocksRows813=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark814=== PAUSE TestServerTLSConfig/missing_CA_file815=== RUN TestServerTLSConfig/not_a_PEM_file816=== RUN TestProxyWriteTimeout/unknown_size817=== RUN TestIsValidUploadKey/narinfo_key,_nar_type818=== CONT TestSweepRechecksPendingAfterLocking819=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type820=== CONT TestRegisterCompletedObjectNeedsPendingRow821=== PAUSE TestServerTLSConfig/not_a_PEM_file822=== PAUSE TestProxyWriteTimeout/unknown_size823=== RUN TestIsValidUploadKey/nar_key,_narinfo_type824=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type825=== RUN TestIsValidUploadKey/listing_key,_narinfo_type826=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type827=== RUN TestIsValidUploadKey/traversal828=== PAUSE TestIsValidUploadKey/traversal829=== RUN TestIsValidUploadKey/traversal_nar830=== PAUSE TestIsValidUploadKey/traversal_nar831=== RUN TestIsValidUploadKey/absolute832=== PAUSE TestIsValidUploadKey/absolute833=== CONT TestSweepSkipsRowsLockedByPush834=== CONT TestFailedS3DeleteKeepsTombstone835=== RUN TestIsValidUploadKey/empty_key836=== PAUSE TestIsValidUploadKey/empty_key837=== RUN TestIsValidUploadKey/unknown_type838=== PAUSE TestIsValidUploadKey/unknown_type839=== CONT TestForceGCDuringPushOffersSweptObject840=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows841=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows842=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check843=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check844=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection845--- PASS: TestGracefulShutdownDrainsInflight (0.16s)846=== CONT TestGCSweepDeliversEachKeyOnce847=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure848=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure849=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart850=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart851=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts852=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts853=== CONT TestClientPushesUseOnePush8542026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures8552026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures8562026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures8572026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures8582026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures859--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.47s)860=== CONT TestGCSweepSkipsPendingObjects8612026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures862--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.50s)863=== CONT TestDeduplicatedObjectsRecordedAsPending8642026/10/06 21:27:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8652026/10/06 21:27:37 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst866--- PASS: TestCompleteMultipartUnregistered (0.51s)867=== CONT TestPushDedupSurvivesConcurrentGC8682026/10/06 21:27:37 INFO Received cleanup request method=DELETE path=/api/pending_closures8692026/10/06 21:27:37 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket3/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""8702026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=18712026/10/06 21:27:37 INFO Received cleanup request method=DELETE path=/api/pending_closures8722026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=08732026/10/06 21:27:37 INFO Received cleanup request method=DELETE path=/api/pending_closures8742026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures8752026/10/06 21:27:37 INFO Aborted multipart uploads count=1 kept=0876--- PASS: TestMultipartCleanup (0.56s)877=== CONT TestGCMetrics8782026/10/06 21:27:37 INFO Received cleanup request method=DELETE path=/api/pending_closures8792026/10/06 21:27:37 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"880--- PASS: TestService_AuthMiddleware (0.57s)881=== CONT TestGCBugBareHashReferences8822026/10/06 21:27:37 INFO Aborted multipart uploads count=1 kept=08832026/10/06 21:27:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8842026-10-06 21:27:37.179 UTC [658] ERROR: Closure does not exist: id=18852026-10-06 21:27:37.179 UTC [658] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8862026-10-06 21:27:37.179 UTC [658] STATEMENT: -- name: CommitPendingClosure :exec887 SELECT commit_pending_closure($1::bigint)888 889--- PASS: TestService_cleanupPendingClosuresHandler (0.57s)890=== CONT TestGCAdvisoryLockBlocksConcurrentRun8912026/10/06 21:27:37 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8922026/10/06 21:27:37 WARN mTLS auth: subject not in bound subjects subject="CN=reader"893--- PASS: TestService_NativeMTLS (0.59s)894=== CONT TestLeadEndsOnShutdown8952026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures896--- PASS: TestMetricsInventory (0.66s)897=== CONT TestLeadIncumbentAnnouncesAtOnce8982026/10/06 21:27:37 WARN readiness check failed error="closed pool"899--- PASS: TestService_readinessHandler (0.62s)900=== CONT TestLeadElectsOneAndHandsOver9012026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures9022026/10/06 21:27:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9032026/10/06 21:27:37 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"904--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.19s)905=== CONT TestConnectWaitsForAPeerMigration906=== NAME TestNARDeduplicationMetadataUploadBug907 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4056051174/001/store/fpbqxmyzk6lcbc4di4asqcv79rpy5c40-file1.txt9082026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=09092026/10/06 21:27:37 WARN Force mode enabled - objects will be deleted immediately without grace period9102026/10/06 21:27:37 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=09112026/10/06 21:27:37 INFO Vacuumed table table=pending_closures9122026/10/06 21:27:37 INFO Vacuumed table table=pending_objects9132026/10/06 21:27:37 INFO Vacuumed table table=multipart_uploads9142026/10/06 21:27:37 INFO Vacuumed table table=closures9152026/10/06 21:27:37 INFO Vacuumed table table=objects9162026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=09172026/10/06 21:27:37 WARN Force mode enabled - objects will be deleted immediately without grace period9182026/10/06 21:27:37 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=09192026/10/06 21:27:37 INFO Vacuumed table table=pending_closures9202026/10/06 21:27:37 INFO Vacuumed table table=pending_objects9212026/10/06 21:27:37 INFO Vacuumed table table=multipart_uploads9222026/10/06 21:27:37 INFO Vacuumed table table=closures9232026/10/06 21:27:37 INFO Vacuumed table table=objects924--- PASS: TestSweepSkipsRowsLockedByPush (0.73s)925=== CONT TestResolveDBConnectionString926=== RUN TestResolveDBConnectionString/flag_wins927=== PAUSE TestResolveDBConnectionString/flag_wins928=== RUN TestResolveDBConnectionString/file_when_flag_empty929=== PAUSE TestResolveDBConnectionString/file_when_flag_empty930=== RUN TestResolveDBConnectionString/missing_file_is_an_error931=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error932=== RUN TestResolveDBConnectionString/PGHOST_allows_empty9332026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures934=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty935=== RUN TestResolveDBConnectionString/nothing_configured936=== PAUSE TestResolveDBConnectionString/nothing_configured937=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9382026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=09392026/10/06 21:27:37 WARN Force mode enabled - objects will be deleted immediately without grace period9402026/10/06 21:27:37 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=09412026/10/06 21:27:37 INFO Vacuumed table table=pending_closures9422026/10/06 21:27:37 INFO Received push request method=POST path=/api/pushes9432026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures9442026/10/06 21:27:37 INFO Vacuumed table table=pending_objects9452026/10/06 21:27:37 INFO Vacuumed table table=multipart_uploads9462026/10/06 21:27:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9472026/10/06 21:27:37 INFO Vacuumed table table=closures9482026/10/06 21:27:37 INFO Uploading fpbqxmyzk6lcbc4di4asqcv79rpy5c40-file1.txt (160B)9492026/10/06 21:27:37 INFO Vacuumed table table=objects9502026/10/06 21:27:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9512026/10/06 21:27:37 WARN Failed to register uploaded object key=fpbqxmyzk6lcbc4di4asqcv79rpy5c40.ls error="server returned 404: 404 page not found\n"9522026/10/06 21:27:37 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9532026/10/06 21:27:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9542026/10/06 21:27:37 INFO Signed narinfos id=1 count=19552026/10/06 21:27:37 INFO Uploading 1 narinfos9562026/10/06 21:27:37 INFO Received complete push request method=POST path=/api/pushes/1/complete9572026/10/06 21:27:37 WARN Failed to register uploaded object key=fpbqxmyzk6lcbc4di4asqcv79rpy5c40.narinfo error="server returned 404: 404 page not found\n"9582026/10/06 21:27:37 INFO Completed push id=1959--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.99s)9602026/10/06 21:27:37 INFO Upload complete. (281ms)961=== CONT TestDeleteClosuresRacingPins962=== NAME TestNARDeduplicationMetadataUploadBug963 metadata_upload_test.go:54: Retrieved narinfo from S3:964 StorePath: /build/TestNARDeduplicationMetadataUploadBug4056051174/001/store/fpbqxmyzk6lcbc4di4asqcv79rpy5c40-file1.txt965 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst966 Compression: zstd967 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf968 NarSize: 160969 References: 970 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf971 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)972 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):973 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9742026/10/06 21:27:37 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MWE2Njc2ZjAtMDZiZC00MGZiLWJhYTctODM2NDdiNzY1MmE0LmQyMmNlNjgwLTAxNTAtNDU5Yy1hNTM4LThlODhkYjQwMmZmN3gxNzkxMzIyMDU3MDU3Nzk4Njg1 parts=109752026/10/06 21:27:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9762026/10/06 21:27:37 INFO Completed upload id=19772026/10/06 21:27:37 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009782026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures9792026/10/06 21:27:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures980--- PASS: TestService_healthCheckHandler (1.06s)981=== CONT TestClientFallsBackToClosures9822026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=09832026/10/06 21:27:37 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=09842026/10/06 21:27:37 INFO Vacuumed table table=pending_closures9852026/10/06 21:27:37 INFO Vacuumed table table=pending_objects9862026/10/06 21:27:37 INFO Vacuumed table table=multipart_uploads987=== NAME TestNARDeduplicationMetadataUploadBug988 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4056051174/001/store/5cjlz6ywhyrhxirj2fdwkpsx8wnjpklk-file2.txt9892026/10/06 21:27:37 INFO Vacuumed table table=closures9902026/10/06 21:27:37 INFO Vacuumed table table=objects9912026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures9922026/10/06 21:27:37 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000993--- PASS: TestService_createPendingClosureHandler (1.16s)994=== CONT TestCacheStatsHandler9952026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=09962026/10/06 21:27:37 WARN Force mode enabled - objects will be deleted immediately without grace period9972026/10/06 21:27:37 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9982026/10/06 21:27:37 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."999--- PASS: TestFailedS3DeleteKeepsTombstone (1.09s)1000=== CONT TestPinProtectsFromGC10012026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=010022026/10/06 21:27:37 INFO Received push request method=POST path=/api/pushes10032026/10/06 21:27:37 WARN Force mode enabled - objects will be deleted immediately without grace period10042026/10/06 21:27:37 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10052026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=010062026/10/06 21:27:37 WARN Failed to register uploaded object key=5cjlz6ywhyrhxirj2fdwkpsx8wnjpklk.ls error="server returned 404: 404 page not found\n"10072026/10/06 21:27:37 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10082026/10/06 21:27:37 INFO Signed narinfos id=2 count=110092026/10/06 21:27:37 INFO Uploading 1 narinfos10102026/10/06 21:27:37 WARN Force mode enabled - objects will be deleted immediately without grace period10112026/10/06 21:27:37 INFO Received complete push request method=POST path=/api/pushes/2/complete10122026/10/06 21:27:37 WARN Failed to register uploaded object key=5cjlz6ywhyrhxirj2fdwkpsx8wnjpklk.narinfo error="server returned 404: 404 page not found\n"10132026/10/06 21:27:37 INFO Completed push id=210142026/10/06 21:27:37 INFO Upload complete. (52ms)1015=== NAME TestNARDeduplicationMetadataUploadBug1016 metadata_upload_test.go:76: Retrieved narinfo from S3:1017 StorePath: /build/TestNARDeduplicationMetadataUploadBug4056051174/001/store/5cjlz6ywhyrhxirj2fdwkpsx8wnjpklk-file2.txt10182026/10/06 21:27:37 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=01019 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1020 Compression: zstd1021 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1022 NarSize: 1601023 References: 1024 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf10252026/10/06 21:27:37 INFO Vacuumed table table=pending_closures10262026/10/06 21:27:37 INFO Vacuumed table table=pending_objects10272026/10/06 21:27:37 INFO Vacuumed table table=multipart_uploads10282026/10/06 21:27:37 INFO Vacuumed table table=closures1029 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1030 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1031 {"version":1,"root":{"type":"regular","size":44}}10322026/10/06 21:27:37 INFO Vacuumed table table=objects10332026/10/06 21:27:37 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=01034--- PASS: TestGCSweepDeliversEachKeyOnce (1.06s)1035=== CONT TestClientSharedPathCommittedMidPush1036--- PASS: TestNARDeduplicationMetadataUploadBug (1.22s)1037=== CONT TestClientWithDependencies10382026/10/06 21:27:37 INFO Vacuumed table table=pending_closures10392026/10/06 21:27:37 INFO Vacuumed table table=pending_objects10402026/10/06 21:27:37 INFO Vacuumed table table=multipart_uploads10412026/10/06 21:27:37 INFO Vacuumed table table=closures10422026/10/06 21:27:37 INFO Vacuumed table table=objects1043--- PASS: TestSweepRechecksPendingAfterLocking (1.14s)1044=== CONT TestClientMultipleUploads1045--- PASS: TestGetExistingObjectsLocksRows (1.17s)1046=== CONT TestClientIntegration1047--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.18s)1048=== CONT TestClientErrorHandling1049=== RUN TestClientErrorHandling/InvalidStorePath1050=== PAUSE TestClientErrorHandling/InvalidStorePath1051=== RUN TestClientErrorHandling/InvalidAuthToken1052=== PAUSE TestClientErrorHandling/InvalidAuthToken1053=== RUN TestClientErrorHandling/ServerNotAvailable1054=== PAUSE TestClientErrorHandling/ServerNotAvailable1055=== CONT TestClientCADerivations10562026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures10572026/10/06 21:27:37 INFO Aborted multipart uploads count=0 kept=010582026/10/06 21:27:37 WARN Force mode enabled - objects will be deleted immediately without grace period10592026/10/06 21:27:37 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=010602026/10/06 21:27:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10612026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures10622026/10/06 21:27:37 INFO Vacuumed table table=pending_closures1063--- PASS: TestPushWaitsForSweepHoldingRow (1.25s)1064=== CONT TestReadProxyConditionalGet10652026/10/06 21:27:37 INFO Vacuumed table table=pending_objects10662026/10/06 21:27:37 INFO Vacuumed table table=multipart_uploads10672026/10/06 21:27:37 INFO Vacuumed table table=closures10682026/10/06 21:27:37 INFO Vacuumed table table=objects1069--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.86s)1070=== CONT TestParseSize1071--- PASS: TestParseSize (0.00s)1072=== CONT TestPush_RepeatedRootCommitsOnce1073--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.26s)1074=== CONT TestPush_CompleteCommitsEveryRoot1075--- PASS: TestGCSweepSkipsPendingObjects (0.89s)1076=== CONT TestPush_OverlappingRootsStoreOneRowPerKey10772026/10/06 21:27:37 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MWE2Njc2ZjAtMDZiZC00MGZiLWJhYTctODM2NDdiNzY1MmE0LmQzZTllZGVjLWE3ZDctNDJlYy04OGI1LTU5MjdlNDczZjRlZngxNzkxMzIyMDU3MzE1MzE3OTE5 parts=1010782026/10/06 21:27:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10792026/10/06 21:27:37 INFO Completed upload id=110802026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures10812026/10/06 21:27:37 INFO Received uploads request method=POST path=/api/pending_closures10822026/10/06 21:27:37 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10832026/10/06 21:27:38 WARN Found objects in DB but missing from S3, will re-upload count=11084--- PASS: TestService_verifyS3Integrity (1.39s)1085=== CONT TestReadRedirectUsesPublicS3URL10862026/10/06 21:27:38 INFO Received uploads request method=POST path=/api/pending_closures10872026/10/06 21:27:38 INFO Aborted multipart uploads count=0 kept=010882026/10/06 21:27:38 WARN Force mode enabled - objects will be deleted immediately without grace period10892026/10/06 21:27:38 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=010902026/10/06 21:27:38 INFO Vacuumed table table=pending_closures10912026/10/06 21:27:38 INFO Vacuumed table table=pending_objects10922026/10/06 21:27:38 INFO Vacuumed table table=multipart_uploads10932026/10/06 21:27:38 INFO Vacuumed table table=closures10942026/10/06 21:27:38 INFO Vacuumed table table=objects10952026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes1096--- PASS: TestGCMetrics (0.86s)1097=== CONT TestReadProxyRangeRequest10982026/10/06 21:27:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10992026/10/06 21:27:38 INFO Uploading 3hq57wlfd9grkkvc6v02hklprcr40g2g-shared-dep (136B)11002026/10/06 21:27:38 INFO Uploading sd7z0rqzs300aj4iwg7nh0w2j1idx36x-b (216B)11012026/10/06 21:27:38 WARN Failed to register uploaded object key=25sc6ybg2vwv3wx3b4iy3dxmyalisd2l.ls error="server returned 404: 404 page not found\n"11022026/10/06 21:27:38 WARN Failed to register uploaded object key=3hq57wlfd9grkkvc6v02hklprcr40g2g.ls error="server returned 404: 404 page not found\n"11032026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11042026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/0mxlvn5fxsi807s1ylh830z4jf37i79yb8cwf227vbf8r4s1j8n2.nar.zst error="server returned 404: 404 page not found\n"11052026/10/06 21:27:38 WARN Failed to register uploaded object key=sd7z0rqzs300aj4iwg7nh0w2j1idx36x.ls error="server returned 404: 404 page not found\n"11062026/10/06 21:27:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11072026/10/06 21:27:38 INFO Signed narinfos id=1 count=311082026/10/06 21:27:38 INFO Uploading 3 narinfos11092026/10/06 21:27:38 WARN Failed to register uploaded object key=3hq57wlfd9grkkvc6v02hklprcr40g2g.narinfo error="server returned 404: 404 page not found\n"11102026/10/06 21:27:38 WARN Failed to register uploaded object key=25sc6ybg2vwv3wx3b4iy3dxmyalisd2l.narinfo error="server returned 404: 404 page not found\n"11112026/10/06 21:27:38 INFO Received complete push request method=POST path=/api/pushes/1/complete11122026/10/06 21:27:38 WARN Failed to register uploaded object key=sd7z0rqzs300aj4iwg7nh0w2j1idx36x.narinfo error="server returned 404: 404 page not found\n"11132026/10/06 21:27:38 INFO Completed push id=111142026/10/06 21:27:38 INFO Upload complete. (238ms)11152026/10/06 21:27:38 INFO Aborted multipart uploads count=0 kept=01116=== NAME TestClientPushesUseOnePush1117 client_pushes_test.go:97: Retrieved narinfo from S3:1118 StorePath: /build/TestClientPushesUseOnePush2636589610/001/store/3hq57wlfd9grkkvc6v02hklprcr40g2g-shared-dep1119 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1120 Compression: zstd1121 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821122 NarSize: 1361123 References: 1124 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11252026/10/06 21:27:38 INFO lead: acquired remote=192.0.2.1:12341126 client_pushes_test.go:97: Retrieved narinfo from S3:1127 StorePath: /build/TestClientPushesUseOnePush2636589610/001/store/25sc6ybg2vwv3wx3b4iy3dxmyalisd2l-a1128 URL: nar/0mxlvn5fxsi807s1ylh830z4jf37i79yb8cwf227vbf8r4s1j8n2.nar.zst1129 Compression: zstd1130 NarHash: sha256:0mxlvn5fxsi807s1ylh830z4jf37i79yb8cwf227vbf8r4s1j8n21131 NarSize: 2161132 References: /build/TestClientPushesUseOnePush2636589610/001/store/3hq57wlfd9grkkvc6v02hklprcr40g2g-shared-dep1133 CA: text:sha256:1q13dc0xkvrzck8f2qdj3y3spmmi54478ylw4glrr19k400w9l5f1134 client_pushes_test.go:97: Retrieved narinfo from S3:1135 StorePath: /build/TestClientPushesUseOnePush2636589610/001/store/sd7z0rqzs300aj4iwg7nh0w2j1idx36x-b11362026/10/06 21:27:38 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=01137 URL: nar/0mxlvn5fxsi807s1ylh830z4jf37i79yb8cwf227vbf8r4s1j8n2.nar.zst1138 Compression: zstd1139 NarHash: sha256:0mxlvn5fxsi807s1ylh830z4jf37i79yb8cwf227vbf8r4s1j8n21140 NarSize: 2161141 References: /build/TestClientPushesUseOnePush2636589610/001/store/3hq57wlfd9grkkvc6v02hklprcr40g2g-shared-dep1142 CA: text:sha256:1q13dc0xkvrzck8f2qdj3y3spmmi54478ylw4glrr19k400w9l5f11432026/10/06 21:27:38 INFO Vacuumed table table=pending_closures11442026/10/06 21:27:38 INFO Vacuumed table table=pending_objects11452026/10/06 21:27:38 INFO Vacuumed table table=multipart_uploads1146--- PASS: TestClientPushesUseOnePush (1.44s)1147=== CONT TestReadRedirectKeepsNarinfoProxied11482026/10/06 21:27:38 INFO Vacuumed table table=closures11492026/10/06 21:27:38 INFO Vacuumed table table=objects11502026/10/06 21:27:38 INFO Aborted multipart uploads count=0 kept=011512026/10/06 21:27:38 WARN Force mode enabled - objects will be deleted immediately without grace period11522026/10/06 21:27:38 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=011532026/10/06 21:27:38 INFO Vacuumed table table=pending_closures11542026/10/06 21:27:38 INFO lead: acquired remote=192.0.2.1:123411552026/10/06 21:27:38 INFO lead: released remote=192.0.2.1:12341156--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.99s)1157=== CONT TestReadRedirectNar11582026/10/06 21:27:38 INFO Vacuumed table table=pending_objects11592026/10/06 21:27:38 INFO Vacuumed table table=multipart_uploads11602026/10/06 21:27:38 INFO Vacuumed table table=closures11612026/10/06 21:27:38 INFO Vacuumed table table=objects1162--- PASS: TestPushDedupSurvivesConcurrentGC (1.14s)1163=== CONT TestReadProxyDisabled11642026/10/06 21:27:38 INFO lead: acquired remote=192.0.2.1:12341165--- PASS: TestGCBugBareHashReferences (1.27s)1166=== CONT TestReadProxyRootRedirectsToIndexHTML1167--- PASS: TestCacheStatsHandler (0.73s)1168=== CONT TestProxyHeadersOnlyTrustedOnSocket1169=== NAME TestPinProtectsFromGC1170 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC782994136/001/store/gqc1bmsw14zw8nv7yabr28ik61727ccw-pinned-file.txt1171 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC782994136/001/store/j6046f9p2ah27fnx03hpsl3nfy53s66g-unpinned-file.txt1172=== NAME TestClientWithDependencies1173 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2322439472/001/store/6m0xj5wnaa662id9rwz5kxyzgbigr0ii-test-script1174=== NAME TestClientMultipleUploads1175 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3755206189/001/store/64id39sxasmb1vrj0gcpkqi5k7id92xp-test-file-0.txt1176=== NAME TestClientIntegration1177 client_integration_test.go:286: Created store path: /build/TestClientIntegration2719151937/002/store/8xdsxrmdza1pk9zhkkywpj4r4s0r1jq9-test-file.txt11782026/10/06 21:27:38 INFO Received uploads request method=POST path=/api/pending_closures1179--- PASS: TestReadProxyConditionalGet (0.69s)1180=== CONT TestReadProxyOutlastsServerWriteTimeout11812026/10/06 21:27:38 INFO Received uploads request method=POST path=/api/pending_closures11822026/10/06 21:27:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11832026/10/06 21:27:38 INFO Uploading sr1p0pkx7rncf3k7vn50jswq3pkgy8f6-a (216B)11842026/10/06 21:27:38 INFO Uploading nzjxifvvhkjl65gsx46pa0sabhjy7bhy-shared-dep (136B)1185=== NAME TestClientWithDependencies1186 client_integration_test.go:615: Found 1 dependencies (including self)11872026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes11882026/10/06 21:27:38 WARN Failed to register uploaded object key=pg79chj0qspap6czyv1cfj2i0rl3argr.ls error="server returned 404: 404 page not found\n"11892026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/03sys7cdkp0pkg3g13mr5c823i1rkw6mjjv9xznb9j9j2qyygacd.nar.zst error="server returned 404: 404 page not found\n"11902026/10/06 21:27:38 WARN Failed to register uploaded object key=nzjxifvvhkjl65gsx46pa0sabhjy7bhy.ls error="server returned 404: 404 page not found\n"11912026/10/06 21:27:38 WARN Failed to register uploaded object key=sr1p0pkx7rncf3k7vn50jswq3pkgy8f6.ls error="server returned 404: 404 page not found\n"11922026/10/06 21:27:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1193=== NAME TestClientMultipleUploads11942026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1195 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3755206189/001/store/3475df29rbh5clf3zn7w2pwy1m016cky-test-file-1.txt11962026/10/06 21:27:38 INFO Signed narinfos id=1 count=211972026/10/06 21:27:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11982026/10/06 21:27:38 INFO Signed narinfos id=2 count=211992026/10/06 21:27:38 INFO Uploading 4 narinfos12002026/10/06 21:27:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12012026/10/06 21:27:38 INFO Uploading gqc1bmsw14zw8nv7yabr28ik61727ccw-pinned-file.txt (128B)12022026/10/06 21:27:38 WARN Failed to register uploaded object key=nzjxifvvhkjl65gsx46pa0sabhjy7bhy.narinfo error="server returned 404: 404 page not found\n"12032026/10/06 21:27:38 WARN Failed to register uploaded object key=pg79chj0qspap6czyv1cfj2i0rl3argr.narinfo error="server returned 404: 404 page not found\n"12042026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes12052026/10/06 21:27:38 WARN Failed to register uploaded object key=sr1p0pkx7rncf3k7vn50jswq3pkgy8f6.narinfo error="server returned 404: 404 page not found\n"12062026/10/06 21:27:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12072026/10/06 21:27:38 WARN Failed to register uploaded object key=nzjxifvvhkjl65gsx46pa0sabhjy7bhy.narinfo error="server returned 404: 404 page not found\n"12082026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1209--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.26s)1210=== CONT TestReadProxyHead12112026/10/06 21:27:38 INFO Completed upload id=112122026/10/06 21:27:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12132026/10/06 21:27:38 INFO Completed upload id=212142026/10/06 21:27:38 INFO Upload complete. (102ms)1215=== NAME TestClientFallsBackToClosures1216 client_pushes_test.go:112: Retrieved narinfo from S3:1217 StorePath: /build/TestClientFallsBackToClosures1746567333/001/store/nzjxifvvhkjl65gsx46pa0sabhjy7bhy-shared-dep1218 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1219 Compression: zstd1220 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821221 NarSize: 1361222 References: 1223 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12242026/10/06 21:27:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12252026/10/06 21:27:38 WARN Failed to register uploaded object key=gqc1bmsw14zw8nv7yabr28ik61727ccw.ls error="server returned 404: 404 page not found\n"12262026/10/06 21:27:38 INFO Signed narinfos id=1 count=11227 client_pushes_test.go:112: Retrieved narinfo from S3:12282026/10/06 21:27:38 INFO Uploading 1 narinfos1229 StorePath: /build/TestClientFallsBackToClosures1746567333/001/store/sr1p0pkx7rncf3k7vn50jswq3pkgy8f6-a1230 URL: nar/03sys7cdkp0pkg3g13mr5c823i1rkw6mjjv9xznb9j9j2qyygacd.nar.zst1231 Compression: zstd1232 NarHash: sha256:03sys7cdkp0pkg3g13mr5c823i1rkw6mjjv9xznb9j9j2qyygacd1233 NarSize: 2161234 References: /build/TestClientFallsBackToClosures1746567333/001/store/nzjxifvvhkjl65gsx46pa0sabhjy7bhy-shared-dep1235 CA: text:sha256:160i7lnpvdgqv42nknr2w82z009410v74x6wfihsvmrd7ggwa60m12362026/10/06 21:27:38 INFO Received complete push request method=POST path=/api/pushes/1/complete12372026/10/06 21:27:38 INFO Received complete push request method=POST path=/api/pushes/1/complete12382026/10/06 21:27:38 WARN Failed to register uploaded object key=gqc1bmsw14zw8nv7yabr28ik61727ccw.narinfo error="server returned 404: 404 page not found\n"12392026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes12402026/10/06 21:27:38 INFO Completed push id=11241--- PASS: TestPush_CompleteCommitsEveryRoot (0.75s)1242=== CONT TestReadProxyInvalidPath12432026/10/06 21:27:38 INFO Completed push id=11244=== NAME TestClientMultipleUploads12452026/10/06 21:27:38 INFO Upload complete. (107ms)1246 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3755206189/001/store/by05rldg6z50w3bqigg5qwndz8y9497h-test-file-2.txt12472026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes1248=== NAME TestClientFallsBackToClosures1249 client_pushes_test.go:112: Retrieved narinfo from S3:1250 StorePath: /build/TestClientFallsBackToClosures1746567333/001/store/pg79chj0qspap6czyv1cfj2i0rl3argr-b1251 URL: nar/03sys7cdkp0pkg3g13mr5c823i1rkw6mjjv9xznb9j9j2qyygacd.nar.zst1252 Compression: zstd1253 NarHash: sha256:03sys7cdkp0pkg3g13mr5c823i1rkw6mjjv9xznb9j9j2qyygacd1254 NarSize: 2161255 References: /build/TestClientFallsBackToClosures1746567333/001/store/nzjxifvvhkjl65gsx46pa0sabhjy7bhy-shared-dep1256 CA: text:sha256:160i7lnpvdgqv42nknr2w82z009410v74x6wfihsvmrd7ggwa60m12572026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes12582026/10/06 21:27:38 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12592026/10/06 21:27:38 INFO Uploading vmgd6p14qi50pvww28ljlp5b843vjd7i-top (224B)12602026/10/06 21:27:38 INFO Uploading d1cdhcf2cz1afqi57z2kmrnan1is19j9-shared-dep (136B)1261--- PASS: TestClientFallsBackToClosures (1.02s)1262=== CONT TestReadProxy40412632026/10/06 21:27:38 WARN Failed to register uploaded object key=vmgd6p14qi50pvww28ljlp5b843vjd7i.ls error="server returned 404: 404 page not found\n"1264=== NAME TestClientCADerivations1265 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations513869192/001/store/0jvwbpbvanrxldp8aka7km72cqawawpy-ca-test12662026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12672026/10/06 21:27:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12682026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/162h7rf6mh5mway73v22ai45p4i837anhbdbp7qpvhgq2nda8idr.nar.zst error="server returned 404: 404 page not found\n"12692026/10/06 21:27:38 INFO Uploading 8xdsxrmdza1pk9zhkkywpj4r4s0r1jq9-test-file.txt (152B)12702026/10/06 21:27:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12712026/10/06 21:27:38 WARN Failed to register uploaded object key=d1cdhcf2cz1afqi57z2kmrnan1is19j9.ls error="server returned 404: 404 page not found\n"12722026/10/06 21:27:38 INFO Signed narinfos id=1 count=212732026/10/06 21:27:38 INFO Uploading 2 narinfos12742026/10/06 21:27:38 INFO Received complete push request method=POST path=/api/pushes/1/complete12752026/10/06 21:27:38 WARN Failed to register uploaded object key=8xdsxrmdza1pk9zhkkywpj4r4s0r1jq9.ls error="server returned 404: 404 page not found\n"12762026/10/06 21:27:38 WARN Failed to register uploaded object key=d1cdhcf2cz1afqi57z2kmrnan1is19j9.narinfo error="server returned 404: 404 page not found\n"12772026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12782026/10/06 21:27:38 INFO Received complete push request method=POST path=/api/pushes/1/complete12792026/10/06 21:27:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12802026/10/06 21:27:38 WARN Failed to register uploaded object key=vmgd6p14qi50pvww28ljlp5b843vjd7i.narinfo error="server returned 404: 404 page not found\n"12812026/10/06 21:27:38 INFO Signed narinfos id=1 count=112822026/10/06 21:27:38 INFO Uploading 1 narinfos12832026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes12842026/10/06 21:27:38 INFO Received complete push request method=POST path=/api/pushes/1/complete12852026/10/06 21:27:38 WARN Failed to register uploaded object key=8xdsxrmdza1pk9zhkkywpj4r4s0r1jq9.narinfo error="server returned 404: 404 page not found\n"12862026/10/06 21:27:38 INFO Completed push id=11287--- PASS: TestPush_RepeatedRootCommitsOnce (0.78s)1288=== CONT TestReadProxyNarStreaming12892026/10/06 21:27:38 INFO Completed push id=112902026/10/06 21:27:38 INFO Upload complete. (64ms)1291=== NAME TestClientSharedPathCommittedMidPush1292 client_integration_test.go:680: Retrieved narinfo from S3:1293 StorePath: /build/TestClientSharedPathCommittedMidPush3606895253/001/store/d1cdhcf2cz1afqi57z2kmrnan1is19j9-shared-dep1294 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1295 Compression: zstd1296 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821297 NarSize: 1361298 References: 1299 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1300 client_integration_test.go:680: Retrieved narinfo from S3:1301 StorePath: /build/TestClientSharedPathCommittedMidPush3606895253/001/store/vmgd6p14qi50pvww28ljlp5b843vjd7i-top1302 URL: nar/162h7rf6mh5mway73v22ai45p4i837anhbdbp7qpvhgq2nda8idr.nar.zst1303 Compression: zstd1304 NarHash: sha256:162h7rf6mh5mway73v22ai45p4i837anhbdbp7qpvhgq2nda8idr1305 NarSize: 2241306 References: /build/TestClientSharedPathCommittedMidPush3606895253/001/store/d1cdhcf2cz1afqi57z2kmrnan1is19j9-shared-dep1307 CA: text:sha256:19cfqcq01abp81bs51xvd3v8wzlwlw9mas5mykdp4y1hb3s1bc7813082026/10/06 21:27:38 INFO Completed push id=113092026/10/06 21:27:38 INFO Upload complete. (71ms)13102026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes1311--- PASS: TestClientSharedPathCommittedMidPush (0.93s)1312=== CONT TestReadProxyContentNegotiation13132026/10/06 21:27:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13142026/10/06 21:27:38 INFO Uploading 6m0xj5wnaa662id9rwz5kxyzgbigr0ii-test-script (136B)1315--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.79s)1316=== CONT TestReadProxyNarinfoAlreadyDecompressed13172026/10/06 21:27:38 WARN Failed to register uploaded object key=6m0xj5wnaa662id9rwz5kxyzgbigr0ii.ls error="server returned 404: 404 page not found\n"1318=== NAME TestClientCADerivations1319 client_ca_test.go:139: Found 1 dependencies (including self)13202026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13212026/10/06 21:27:38 WARN Failed to register uploaded object key=log/argp1jsacrcmi6k55w7wrdx2aiq00mpf-test-script.drv error="server returned 404: 404 page not found\n"13222026/10/06 21:27:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13232026/10/06 21:27:38 INFO Signed narinfos id=1 count=113242026/10/06 21:27:38 INFO Uploading 1 narinfos13252026/10/06 21:27:38 INFO Received complete push request method=POST path=/api/pushes/1/complete13262026/10/06 21:27:38 WARN Failed to register uploaded object key=6m0xj5wnaa662id9rwz5kxyzgbigr0ii.narinfo error="server returned 404: 404 page not found\n"13272026/10/06 21:27:38 INFO Completed push id=113282026/10/06 21:27:38 INFO Upload complete. (68ms)13292026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes13302026/10/06 21:27:38 INFO All 1 paths already cached1331=== NAME TestClientIntegration1332 client_integration_test.go:312: Retrieved narinfo from S3:1333 StorePath: /build/TestClientIntegration2719151937/002/store/8xdsxrmdza1pk9zhkkywpj4r4s0r1jq9-test-file.txt1334 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1335 Compression: zstd1336 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11337 NarSize: 1521338 References: 1339 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11340=== NAME TestClientWithDependencies1341 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2322439472/001/store) requires matching store prefix13422026/10/06 21:27:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13432026/10/06 21:27:38 INFO Uploading j6046f9p2ah27fnx03hpsl3nfy53s66g-unpinned-file.txt (128B)1344=== NAME TestClientIntegration1345 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1346 client_integration_test.go:313: Decompressed .ls content (64 bytes):1347 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1348 client_integration_test.go:316: Testing garbage collection...13492026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13502026/10/06 21:27:38 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13512026/10/06 21:27:38 WARN Failed to register uploaded object key=j6046f9p2ah27fnx03hpsl3nfy53s66g.ls error="server returned 404: 404 page not found\n"13522026/10/06 21:27:38 INFO Signed narinfos id=2 count=113532026/10/06 21:27:38 INFO Uploading 1 narinfos13542026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes1355--- PASS: TestClientWithDependencies (0.96s)1356=== CONT TestReadProxyNarinfo13572026/10/06 21:27:38 INFO Received complete push request method=POST path=/api/pushes/2/complete13582026/10/06 21:27:38 WARN Failed to register uploaded object key=j6046f9p2ah27fnx03hpsl3nfy53s66g.narinfo error="server returned 404: 404 page not found\n"13592026/10/06 21:27:38 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13602026/10/06 21:27:38 INFO Completed push id=213612026/10/06 21:27:38 INFO Uploading 64id39sxasmb1vrj0gcpkqi5k7id92xp-test-file-0.txt (160B)13622026/10/06 21:27:38 INFO Uploading by05rldg6z50w3bqigg5qwndz8y9497h-test-file-2.txt (160B)13632026/10/06 21:27:38 INFO Uploading 3475df29rbh5clf3zn7w2pwy1m016cky-test-file-1.txt (160B)1364--- PASS: TestReadRedirectUsesPublicS3URL (0.81s)13652026/10/06 21:27:38 INFO Upload complete. (50ms)1366=== CONT TestIsValidCachePath1367=== RUN TestIsValidCachePath/narinfo1368=== PAUSE TestIsValidCachePath/narinfo1369=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1370=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1371=== RUN TestIsValidCachePath/nar_zst1372=== PAUSE TestIsValidCachePath/nar_zst1373=== RUN TestIsValidCachePath/nar_xz1374=== PAUSE TestIsValidCachePath/nar_xz1375=== RUN TestIsValidCachePath/nar_bz21376=== PAUSE TestIsValidCachePath/nar_bz21377=== RUN TestIsValidCachePath/nar_uncompressed1378=== PAUSE TestIsValidCachePath/nar_uncompressed1379=== RUN TestIsValidCachePath/ls1380=== PAUSE TestIsValidCachePath/ls1381=== RUN TestIsValidCachePath/log1382=== PAUSE TestIsValidCachePath/log1383=== RUN TestIsValidCachePath/realisation1384=== PAUSE TestIsValidCachePath/realisation1385=== RUN TestIsValidCachePath/nix-cache-info1386=== PAUSE TestIsValidCachePath/nix-cache-info1387=== RUN TestIsValidCachePath/index.html1388=== PAUSE TestIsValidCachePath/index.html1389=== RUN TestIsValidCachePath/traversal_parent1390=== PAUSE TestIsValidCachePath/traversal_parent1391=== RUN TestIsValidCachePath/traversal_in_middle1392=== PAUSE TestIsValidCachePath/traversal_in_middle1393=== RUN TestIsValidCachePath/invalid_char_e1394=== PAUSE TestIsValidCachePath/invalid_char_e1395=== RUN TestIsValidCachePath/invalid_char_u1396=== PAUSE TestIsValidCachePath/invalid_char_u1397=== RUN TestIsValidCachePath/random_path1398=== PAUSE TestIsValidCachePath/random_path1399=== RUN TestIsValidCachePath/empty1400=== PAUSE TestIsValidCachePath/empty1401=== RUN TestIsValidCachePath/leading_slash1402=== PAUSE TestIsValidCachePath/leading_slash1403=== RUN TestIsValidCachePath/wrong_extension1404=== PAUSE TestIsValidCachePath/wrong_extension1405=== RUN TestIsValidCachePath/short_hash1406=== PAUSE TestIsValidCachePath/short_hash1407=== CONT TestService_AuthMiddleware_OIDC14082026/10/06 21:27:38 WARN Failed to register uploaded object key=64id39sxasmb1vrj0gcpkqi5k7id92xp.ls error="server returned 404: 404 page not found\n"14092026/10/06 21:27:38 WARN Failed to register uploaded object key=by05rldg6z50w3bqigg5qwndz8y9497h.ls error="server returned 404: 404 page not found\n"14102026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14112026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14122026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14132026/10/06 21:27:38 WARN Failed to register uploaded object key=3475df29rbh5clf3zn7w2pwy1m016cky.ls error="server returned 404: 404 page not found\n"14142026/10/06 21:27:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14152026/10/06 21:27:38 INFO Signed narinfos id=1 count=314162026/10/06 21:27:38 INFO Uploading 3 narinfos14172026/10/06 21:27:38 WARN Failed to register uploaded object key=by05rldg6z50w3bqigg5qwndz8y9497h.narinfo error="server returned 404: 404 page not found\n"14182026/10/06 21:27:38 INFO Received complete push request method=POST path=/api/pushes/1/complete14192026/10/06 21:27:38 WARN Failed to register uploaded object key=3475df29rbh5clf3zn7w2pwy1m016cky.narinfo error="server returned 404: 404 page not found\n"14202026/10/06 21:27:38 WARN Failed to register uploaded object key=64id39sxasmb1vrj0gcpkqi5k7id92xp.narinfo error="server returned 404: 404 page not found\n"1421--- PASS: TestReadRedirectKeepsNarinfoProxied (0.58s)1422=== CONT TestCacheConfigHandler1423=== RUN TestCacheConfigHandler/full_config,_no_issuer1424=== PAUSE TestCacheConfigHandler/full_config,_no_issuer14252026/10/06 21:27:38 INFO Completed push id=11426=== RUN TestCacheConfigHandler/no_cache_url_configured1427=== PAUSE TestCacheConfigHandler/no_cache_url_configured1428=== RUN TestCacheConfigHandler/no_signing_keys14292026/10/06 21:27:38 INFO Upload complete. (66ms)1430=== PAUSE TestCacheConfigHandler/no_signing_keys1431=== NAME TestClientMultipleUploads1432 client_integration_test.go:369: Uploaded 3 paths in 99.897655ms1433=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1434=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1435=== CONT TestService_ReadScope_PublicByDefault14362026/10/06 21:27:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures14372026/10/06 21:27:38 INFO Garbage collection started1438--- PASS: TestClientMultipleUploads (0.99s)1439=== CONT TestService_RequireScope_OIDC14402026/10/06 21:27:38 INFO Aborted multipart uploads count=0 kept=014412026/10/06 21:27:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures14422026/10/06 21:27:38 INFO Garbage collection started1443--- PASS: TestReadProxyRangeRequest (0.82s)1444=== CONT TestPush_CompleteWaitsForCleanupOfThePush14452026/10/06 21:27:38 WARN Force mode enabled - objects will be deleted immediately without grace period14462026/10/06 21:27:38 INFO Aborted multipart uploads count=0 kept=014472026/10/06 21:27:38 WARN Force mode enabled - objects will be deleted immediately without grace period1448--- PASS: TestReadProxyDisabled (0.60s)1449=== CONT TestCreatePin_ReservedPins14502026/10/06 21:27:38 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=014512026/10/06 21:27:38 INFO Vacuumed table table=pending_closures14522026/10/06 21:27:38 INFO Vacuumed table table=pending_objects14532026/10/06 21:27:38 INFO Vacuumed table table=multipart_uploads14542026/10/06 21:27:38 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=014552026/10/06 21:27:38 INFO Vacuumed table table=closures14562026/10/06 21:27:38 INFO Received push request method=POST path=/api/pushes14572026/10/06 21:27:38 INFO Vacuumed table table=pending_closures14582026/10/06 21:27:38 INFO Vacuumed table table=objects14592026/10/06 21:27:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14602026/10/06 21:27:38 INFO Uploading 0jvwbpbvanrxldp8aka7km72cqawawpy-ca-test (144B)14612026/10/06 21:27:38 INFO Vacuumed table table=pending_objects14622026/10/06 21:27:38 INFO Vacuumed table table=multipart_uploads14632026/10/06 21:27:38 INFO Vacuumed table table=closures14642026/10/06 21:27:38 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14652026/10/06 21:27:38 WARN Failed to register uploaded object key=log/223vy2c9y16q0i4vgws5xpnfcqkgx70x-ca-test.drv error="server returned 404: 404 page not found\n"14662026/10/06 21:27:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14672026/10/06 21:27:38 WARN Failed to register uploaded object key=0jvwbpbvanrxldp8aka7km72cqawawpy.ls error="server returned 404: 404 page not found\n"14682026/10/06 21:27:38 INFO Signed narinfos id=1 count=114692026/10/06 21:27:38 INFO Uploading 1 narinfos14702026/10/06 21:27:38 INFO Vacuumed table table=objects14712026/10/06 21:27:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33427/oidc14722026/10/06 21:27:38 INFO Received complete push request method=POST path=/api/pushes/1/complete14732026/10/06 21:27:38 WARN Failed to register uploaded object key=0jvwbpbvanrxldp8aka7km72cqawawpy.narinfo error="server returned 404: 404 page not found\n"1474--- PASS: TestReadRedirectNar (0.64s)1475=== CONT TestParseSingleRange1476=== RUN TestParseSingleRange/none1477=== PAUSE TestParseSingleRange/none1478=== RUN TestParseSingleRange/unknown_unit1479=== PAUSE TestParseSingleRange/unknown_unit1480=== RUN TestParseSingleRange/multi-range_ignored1481=== PAUSE TestParseSingleRange/multi-range_ignored1482=== RUN TestParseSingleRange/malformed_no_dash1483=== PAUSE TestParseSingleRange/malformed_no_dash1484=== RUN TestParseSingleRange/malformed_both_empty1485=== PAUSE TestParseSingleRange/malformed_both_empty1486=== RUN TestParseSingleRange/malformed_end_before_start1487=== PAUSE TestParseSingleRange/malformed_end_before_start1488=== RUN TestParseSingleRange/closed1489=== PAUSE TestParseSingleRange/closed1490=== RUN TestParseSingleRange/open-ended1491=== PAUSE TestParseSingleRange/open-ended1492=== RUN TestParseSingleRange/end_clamped_to_size1493=== PAUSE TestParseSingleRange/end_clamped_to_size1494=== RUN TestParseSingleRange/suffix1495=== PAUSE TestParseSingleRange/suffix1496=== RUN TestParseSingleRange/suffix_exceeds_size1497=== PAUSE TestParseSingleRange/suffix_exceeds_size1498=== RUN TestParseSingleRange/single_byte1499=== PAUSE TestParseSingleRange/single_byte1500=== RUN TestParseSingleRange/start_past_EOF1501=== PAUSE TestParseSingleRange/start_past_EOF1502=== RUN TestParseSingleRange/start_far_past_EOF1503=== PAUSE TestParseSingleRange/start_far_past_EOF1504=== CONT TestPresentNotReportedWhileGCDeletesClosure1505=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1506=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1507=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1508=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1509=== CONT TestService_Rustfstest15102026/10/06 21:27:38 INFO Completed push id=115112026/10/06 21:27:38 INFO Upload complete. (105ms)1512=== NAME TestClientCADerivations1513 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations513869192/001/store/0jvwbpbvanrxldp8aka7km72cqawawpy-ca-test1514 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1515 Compression: zstd1516 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1517 NarSize: 1441518 References: 1519 Deriver: /build/TestClientCADerivations513869192/001/store/223vy2c9y16q0i4vgws5xpnfcqkgx70x-ca-test.drv1520 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1521 client_ca_test.go:185: Checking for realisation files in S3...1522 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1523 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1524--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.48s)1525=== CONT TestPresentRefreshesOnlyStaleClosures15262026/10/06 21:27:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38151/oidc15272026/10/06 21:27:38 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3668194327/001/proxy.sock15282026/10/06 21:27:38 INFO Starting HTTP server address=127.0.0.1:3477915292026/10/06 21:27:38 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15302026/10/06 21:27:38 INFO Shutdown signal received, draining in-flight requests timeout=10s1531--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.45s)1532=== CONT TestPresentReportsOnlyClosureRoots15332026/10/06 21:27:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39009/oidc1534--- PASS: TestReadProxyHead (0.31s)1535=== CONT TestPresignedUploadRegisteredBeforeCommit1536--- PASS: TestReadProxyInvalidPath (0.31s)1537=== CONT TestPush_RejectsBadRequests1538=== NAME TestClientCADerivations1539 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1540 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1541 error: binary cache 's3://bucket45?endpoint=http://localhost:34373®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations513869192/001/store'1542 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11543--- PASS: TestClientCADerivations (1.17s)1544=== CONT TestPush_SignsNarinfosOfItsPendingObjects1545--- PASS: TestReadProxy404 (0.34s)1546=== CONT TestCompletedNarNotReofferedAcrossClosures1547--- PASS: TestReadProxyNarStreaming (0.34s)1548=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1549--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.35s)1550=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1551--- PASS: TestService_ReadScope_PublicByDefault (0.37s)1552=== CONT TestPush_RootsAreLockedInByteOrder1553--- PASS: TestReadProxyContentNegotiation (0.45s)1554=== CONT TestRedundantMultipartUpload15552026/10/06 21:27:39 INFO Received push request method=POST path=/api/pushes15562026/10/06 21:27:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15572026/10/06 21:27:39 WARN Refused reserved pin name=worker-x86_64-linux15582026/10/06 21:27:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15592026/10/06 21:27:39 INFO Received create pin request method=POST path=/api/pins/my-app15602026/10/06 21:27:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15612026/10/06 21:27:39 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1562--- PASS: TestCreatePin_ReservedPins (0.39s)1563=== CONT TestOrphanedObjectsGCStressTest1564--- PASS: TestReadProxyNarinfo (0.46s)1565=== CONT TestObjectStatsTrigger1566--- PASS: TestService_Rustfstest (0.37s)1567=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15682026/10/06 21:27:39 INFO lead: released remote=192.0.2.1:12341569--- PASS: TestLeadEndsOnShutdown (2.13s)1570=== CONT TestService_ReadAuthMiddleware1571--- PASS: TestPresentRefreshesOnlyStaleClosures (0.40s)1572=== CONT TestOrphanedObjectsGC1573=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1574=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1575=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1576=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1577=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1578=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1579=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1580=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1581=== CONT TestService_AuthMiddleware_MTLSProxyHeader1582--- PASS: TestPresentReportsOnlyClosureRoots (0.43s)1583=== CONT TestPendingCleanupUsesOneCutoff1584=== RUN TestService_RequireScope_OIDC/builder_may_write1585=== PAUSE TestService_RequireScope_OIDC/builder_may_write1586=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1587=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1588=== RUN TestService_RequireScope_OIDC/ops_may_admin1589=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1590=== RUN TestService_RequireScope_OIDC/ops_may_not_write1591=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1592=== RUN TestService_RequireScope_OIDC/reader_may_not_write1593=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1594=== RUN TestService_RequireScope_OIDC/static_token_may_admin1595=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1596=== RUN TestService_RequireScope_OIDC/static_token_may_write1597=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1598=== RUN TestService_RequireScope_OIDC/reader_may_read1599=== PAUSE TestService_RequireScope_OIDC/reader_may_read1600=== RUN TestService_RequireScope_OIDC/writer_implies_read1601=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1602=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1603=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1604=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1605=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1606=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1607=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1608=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1609=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1610=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1611=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1612=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded16132026/10/06 21:27:39 INFO Received uploads request method=POST path=/api/pending_closures16142026/10/06 21:27:39 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst16152026/10/06 21:27:39 INFO Received uploads request method=POST path=/api/pending_closures1616--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.43s)1617=== CONT TestPendingClosureWriteTimeout/empty1618=== CONT TestPendingClosureWriteTimeout/670k_objects1619=== CONT TestPendingClosureWriteTimeout/400_objects1620=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1621=== RUN TestPush_RejectsBadRequests/no_roots1622=== PAUSE TestPush_RejectsBadRequests/no_roots1623=== RUN TestPush_RejectsBadRequests/no_objects1624=== PAUSE TestPush_RejectsBadRequests/no_objects1625=== RUN TestPush_RejectsBadRequests/bad_root1626=== PAUSE TestPush_RejectsBadRequests/bad_root1627=== RUN TestPush_RejectsBadRequests/root_not_in_objects1628=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1629=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16302026/10/06 21:27:39 INFO Received uploads request method=POST path=/1631=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16322026/10/06 21:27:39 INFO Received complete multipart upload request method=POST path=/1633=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16342026/10/06 21:27:39 INFO Received request for more parts method=POST path=/1635=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16362026/10/06 21:27:39 INFO Received uploads request method=POST path=/1637--- PASS: TestUploadHandlersRejectInvalidKeys (0.09s)1638 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1639 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1640 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1641 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1642=== CONT TestGCEndsOnShutdown/before_the_run16432026/10/06 21:27:39 INFO Received push request method=POST path=/api/pushes16442026/10/06 21:27:39 INFO lead: released remote=192.0.2.1:123416452026/10/06 21:27:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16462026/10/06 21:27:39 INFO Signed narinfos id=1 count=116472026/10/06 21:27:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16482026/10/06 21:27:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16492026/10/06 21:27:39 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"16502026/10/06 21:27:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16512026/10/06 21:27:39 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"16522026/10/06 21:27:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16532026/10/06 21:27:39 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=116542026/10/06 21:27:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1655--- PASS: TestDeleteClosuresRacingPins (1.80s)1656=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16572026/10/06 21:27:39 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1658--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.44s)1659=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16602026/10/06 21:27:39 INFO Received uploads request method=POST path=/api/pending_closures16612026/10/06 21:27:39 INFO lead: acquired remote=192.0.2.1:123416622026-10-06 21:27:39.550 UTC [1952] ERROR: Push does not exist: id=116632026-10-06 21:27:39.550 UTC [1952] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE16642026-10-06 21:27:39.550 UTC [1952] STATEMENT: SELECT commit_push($1)1665--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.70s)1666=== CONT TestServerTLSConfig/no_client_CA1667=== CONT TestServerTLSConfig/not_a_PEM_file1668=== CONT TestServerTLSConfig/missing_CA_file1669--- PASS: TestServerTLSConfig (0.09s)1670 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1671 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1672 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1673=== CONT TestProxyWriteTimeout/narinfo1674=== CONT TestProxyWriteTimeout/unknown_size1675=== CONT TestProxyWriteTimeout/10_GiB_nar1676=== CONT TestProxyWriteTimeout/1_GiB_nar1677--- PASS: TestProxyWriteTimeout (0.09s)1678 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1679 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1680 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1681 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1682=== CONT TestIsValidUploadKey/narinfo1683=== CONT TestIsValidUploadKey/realisation_plus_in_output1684=== CONT TestIsValidUploadKey/unknown_type1685=== CONT TestIsValidUploadKey/empty_key1686=== CONT TestIsValidUploadKey/absolute1687=== CONT TestIsValidUploadKey/traversal_nar1688=== CONT TestIsValidUploadKey/traversal1689=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1690=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1691=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1692=== CONT TestIsValidUploadKey/index.html1693=== CONT TestIsValidUploadKey/nix-cache-info1694=== CONT TestIsValidUploadKey/build_log_home-manager_file1695=== CONT TestIsValidUploadKey/realisation1696=== CONT TestIsValidUploadKey/build_log_equals1697=== CONT TestIsValidUploadKey/build_log_question_mark1698=== CONT TestIsValidUploadKey/build_log_plus_in_name1699=== CONT TestIsValidUploadKey/nar_plain1700=== CONT TestIsValidUploadKey/build_log1701=== CONT TestIsValidUploadKey/listing1702=== CONT TestIsValidUploadKey/nar_xz1703=== CONT TestIsValidUploadKey/nar_zst1704--- PASS: TestIsValidUploadKey (0.10s)1705 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1706 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1707 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1708 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1709 --- PASS: TestIsValidUploadKey/absolute (0.00s)1710 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1711 --- PASS: TestIsValidUploadKey/traversal (0.00s)1712 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1713 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1714 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1715 --- PASS: TestIsValidUploadKey/index.html (0.00s)1716 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1717 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1718 --- PASS: TestIsValidUploadKey/realisation (0.00s)1719 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1720 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1721 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1722 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1723 --- PASS: TestIsValidUploadKey/build_log (0.00s)1724 --- PASS: TestIsValidUploadKey/listing (0.00s)1725 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1726 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1727=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17282026/10/06 21:27:39 INFO Received push request method=POST path=/api/pushes17292026/10/06 21:27:39 INFO Received uploads request method=POST path=/api/pending_closures17302026/10/06 21:27:39 INFO Received complete push request method=POST path=/api/pushes/1/complete17312026/10/06 21:27:39 INFO Completed push id=117322026/10/06 21:27:39 INFO Received push request method=POST path=/api/pushes17332026/10/06 21:27:39 INFO Received push request method=POST path=/api/pushes17342026/10/06 21:27:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17352026/10/06 21:27:39 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWE2Njc2ZjAtMDZiZC00MGZiLWJhYTctODM2NDdiNzY1MmE0LmQxNGMyZWZhLTUwOWUtNDc1OC1iYTU2LWNkMDI5ZmEzZjBmZXgxNzkxMzIyMDU5NTkzMzg2Mjkz17362026/10/06 21:27:39 INFO Received uploads request method=POST path=/api/pending_closures17372026/10/06 21:27:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWE2Njc2ZjAtMDZiZC00MGZiLWJhYTctODM2NDdiNzY1MmE0LmQxNGMyZWZhLTUwOWUtNDc1OC1iYTU2LWNkMDI5ZmEzZjBmZXgxNzkxMzIyMDU5NTkzMzg2Mjkz parts=11738--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.53s)1739=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17402026/10/06 21:27:39 INFO Received uploads request method=POST path=/api/pending_closures17412026-10-06 21:27:39.659 UTC [1998] ERROR: could not obtain lock on row in relation "closures"17422026-10-06 21:27:39.659 UTC [1998] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17432026-10-06 21:27:39.660 UTC [1998] ERROR: could not obtain lock on row in relation "closures"17442026-10-06 21:27:39.660 UTC [1998] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17452026-10-06 21:27:39.660 UTC [1998] ERROR: could not obtain lock on row in relation "closures"17462026-10-06 21:27:39.660 UTC [1998] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17472026-10-06 21:27:39.661 UTC [1998] ERROR: could not obtain lock on row in relation "closures"17482026-10-06 21:27:39.661 UTC [1998] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT17492026/10/06 21:27:39 INFO Aborted multipart uploads count=0 kept=017502026-10-06 21:27:39.661 UTC [1998] ERROR: could not obtain lock on row in relation "closures"17512026-10-06 21:27:39.661 UTC [1998] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1752--- PASS: TestPush_RootsAreLockedInByteOrder (0.47s)1753=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17542026/10/06 21:27:39 INFO Received uploads request method=POST path=/17552026/10/06 21:27:39 WARN Force mode enabled - objects will be deleted immediately without grace period17562026/10/06 21:27:39 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=017572026/10/06 21:27:39 INFO Vacuumed table table=pending_closures17582026/10/06 21:27:39 INFO Vacuumed table table=pending_objects17592026/10/06 21:27:39 INFO Vacuumed table table=multipart_uploads17602026/10/06 21:27:39 INFO Vacuumed table table=closures17612026/10/06 21:27:39 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17622026/10/06 21:27:39 WARN mTLS auth: bound subjects configured but subject DN unavailable17632026/10/06 21:27:39 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1764--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.42s)1765=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17662026/10/06 21:27:39 INFO Received request for more parts method=POST path=/17672026/10/06 21:27:39 INFO Vacuumed table table=objects17682026/10/06 21:27:39 INFO Received complete push request method=POST path=/api/pushes/2/complete17692026/10/06 21:27:39 INFO Completed push id=21770--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.61s)1771=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17722026/10/06 21:27:39 INFO Received complete multipart upload request method=POST path=/1773--- PASS: TestObjectStatsTrigger (0.47s)1774=== CONT TestResolveDBConnectionString/flag_wins1775=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1776=== CONT TestResolveDBConnectionString/nothing_configured1777=== CONT TestResolveDBConnectionString/missing_file_is_an_error1778=== CONT TestResolveDBConnectionString/file_when_flag_empty1779=== CONT TestClientErrorHandling/InvalidStorePath1780--- PASS: TestResolveDBConnectionString (0.00s)1781 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1782 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1783 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1784 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1785 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1786=== CONT TestClientErrorHandling/ServerNotAvailable1787--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.45s)1788=== CONT TestClientErrorHandling/InvalidAuthToken1789=== CONT TestIsValidCachePath/narinfo1790=== CONT TestIsValidCachePath/index.html1791=== CONT TestIsValidCachePath/short_hash1792=== CONT TestIsValidCachePath/wrong_extension1793=== CONT TestIsValidCachePath/leading_slash1794=== CONT TestIsValidCachePath/empty1795=== CONT TestIsValidCachePath/random_path1796=== CONT TestIsValidCachePath/invalid_char_u1797=== CONT TestIsValidCachePath/invalid_char_e1798=== CONT TestIsValidCachePath/traversal_in_middle1799=== CONT TestIsValidCachePath/traversal_parent1800=== CONT TestIsValidCachePath/realisation1801=== CONT TestIsValidCachePath/nix-cache-info1802=== CONT TestIsValidCachePath/nar_uncompressed1803=== CONT TestIsValidCachePath/nar_xz1804=== CONT TestIsValidCachePath/nar_bz21805=== CONT TestIsValidCachePath/log1806=== CONT TestIsValidCachePath/ls1807=== CONT TestIsValidCachePath/nar_zst1808=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1809--- PASS: TestIsValidCachePath (0.00s)1810 --- PASS: TestIsValidCachePath/narinfo (0.00s)1811 --- PASS: TestIsValidCachePath/index.html (0.00s)1812 --- PASS: TestIsValidCachePath/short_hash (0.00s)1813 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1814 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1815 --- PASS: TestIsValidCachePath/empty (0.00s)1816 --- PASS: TestIsValidCachePath/random_path (0.00s)1817 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1818 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1819 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1820 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1821 --- PASS: TestIsValidCachePath/realisation (0.00s)1822 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1823 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1824 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1825 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1826 --- PASS: TestIsValidCachePath/log (0.00s)1827 --- PASS: TestIsValidCachePath/ls (0.00s)1828 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1829 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1830=== CONT TestCacheConfigHandler/full_config,_no_issuer1831=== CONT TestCacheConfigHandler/no_signing_keys1832=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1833=== CONT TestCacheConfigHandler/no_cache_url_configured1834--- PASS: TestCacheConfigHandler (0.00s)1835 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1836 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1837 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1838 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1839=== CONT TestParseSingleRange/none1840=== CONT TestParseSingleRange/open-ended1841=== CONT TestParseSingleRange/start_far_past_EOF1842=== CONT TestParseSingleRange/start_past_EOF1843=== CONT TestParseSingleRange/single_byte1844=== CONT TestParseSingleRange/suffix_exceeds_size1845=== CONT TestParseSingleRange/end_clamped_to_size1846=== CONT TestParseSingleRange/malformed_both_empty1847=== CONT TestParseSingleRange/closed1848=== CONT TestParseSingleRange/malformed_end_before_start1849=== CONT TestParseSingleRange/suffix1850=== CONT TestParseSingleRange/multi-range_ignored1851=== CONT TestParseSingleRange/unknown_unit1852=== CONT TestParseSingleRange/malformed_no_dash1853--- PASS: TestParseSingleRange (0.00s)1854 --- PASS: TestParseSingleRange/none (0.00s)1855 --- PASS: TestParseSingleRange/open-ended (0.00s)1856 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1857 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1858 --- PASS: TestParseSingleRange/single_byte (0.00s)1859 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1860 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1861 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1862 --- PASS: TestParseSingleRange/closed (0.00s)1863 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1864 --- PASS: TestParseSingleRange/suffix (0.00s)1865 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1866 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1867 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1868=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1869--- PASS: TestService_ReadAuthMiddleware (0.49s)1870=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18712026/10/06 21:27:39 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/present18722026/10/06 21:27:39 INFO Received uploads request method=POST path=/api/pending_closures18732026/10/06 21:27:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.39931ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18742026/10/06 21:27:39 INFO Received uploads request method=POST path=/api/pending_closures18752026/10/06 21:27:39 INFO Received cleanup request method=DELETE path=/api/pending_closures18762026/10/06 21:27:39 INFO Received uploads request method=POST path=/api/pending_closures1877--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.59s)1878=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1879=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18802026/10/06 21:27:40 WARN Authentication failed token_preview=eyJhbGciOi...Q_6Kek1-sw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1881=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18822026/10/06 21:27:40 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]1883=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1884=== CONT TestService_RequireScope_OIDC/builder_may_write1885--- PASS: TestService_AuthMiddleware_OIDC (0.52s)1886 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1887 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1888 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1889 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1890=== CONT TestService_RequireScope_OIDC/reader_may_read1891=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1892=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18932026/10/06 21:27:40 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]1894=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1895=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1896=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1897=== CONT TestService_RequireScope_OIDC/writer_implies_read1898=== CONT TestService_RequireScope_OIDC/reader_may_not_write1899=== CONT TestService_RequireScope_OIDC/static_token_may_write1900=== CONT TestService_RequireScope_OIDC/static_token_may_admin1901=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1902=== CONT TestService_RequireScope_OIDC/ops_may_admin1903=== CONT TestService_RequireScope_OIDC/ops_may_not_write1904=== CONT TestPush_RejectsBadRequests/no_roots19052026/10/06 21:27:40 INFO Received uploads request method=POST path=/api/pending_closures19062026/10/06 21:27:40 INFO Received push request method=POST path=/api/pushes1907=== CONT TestPush_RejectsBadRequests/bad_root19082026/10/06 21:27:40 INFO Received push request method=POST path=/api/pushes1909=== CONT TestPush_RejectsBadRequests/root_not_in_objects19102026/10/06 21:27:40 INFO Received push request method=POST path=/api/pushes1911=== CONT TestPush_RejectsBadRequests/no_objects19122026/10/06 21:27:40 INFO Received push request method=POST path=/api/pushes1913--- PASS: TestService_RequireScope_OIDC (0.58s)1914 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1915 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1916 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1917 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1918 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1919 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1920 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1921 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1922 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1923 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1924 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1925 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1926 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1927 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1928--- PASS: TestPush_RejectsBadRequests (0.41s)1929 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1930 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1931 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1932 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1933=== NAME TestOrphanedObjectsGC1934 orphaned_objects_gc_test.go:287: GC Test Summary:1935 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1936 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1937 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1938 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1939 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1940--- PASS: TestOrphanedObjectsGC (0.75s)19412026/10/06 21:27:40 INFO Aborted multipart uploads count=0 kept=019422026/10/06 21:27:40 WARN Force mode enabled - objects will be deleted immediately without grace period19432026/10/06 21:27:40 INFO Aborted multipart uploads count=0 kept=019442026/10/06 21:27:40 WARN Force mode enabled - objects will be deleted immediately without grace period19452026/10/06 21:27:40 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:34373/bucket92/?delete=\": context canceled"1946--- PASS: TestGCEndsOnShutdown (0.00s)1947 --- PASS: TestGCEndsOnShutdown/before_the_run (0.59s)1948 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.60s)1949 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.61s)19502026/10/06 21:27:40 INFO Received uploads request method=POST path=/api/pending_closures19512026/10/06 21:27:40 INFO Aborted multipart uploads count=0 kept=019522026/10/06 21:27:40 WARN Force mode enabled - objects will be deleted immediately without grace period19532026/10/06 21:27:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=374.306446ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19542026/10/06 21:27:40 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=019552026/10/06 21:27:40 INFO Vacuumed table table=pending_closures19562026/10/06 21:27:40 INFO Vacuumed table table=pending_objects19572026/10/06 21:27:40 INFO Vacuumed table table=multipart_uploads19582026/10/06 21:27:40 INFO Vacuumed table table=closures19592026/10/06 21:27:40 INFO Vacuumed table table=objects19602026/10/06 21:27:40 INFO Received uploads request method=POST path=/api/pending_closures19612026/10/06 21:27:40 INFO Aborted multipart uploads count=0 kept=019622026/10/06 21:27:40 WARN Force mode enabled - objects will be deleted immediately without grace period19632026/10/06 21:27:40 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=019642026/10/06 21:27:40 INFO Vacuumed table table=pending_closures19652026/10/06 21:27:40 INFO Vacuumed table table=pending_objects19662026/10/06 21:27:40 INFO Vacuumed table table=multipart_uploads19672026/10/06 21:27:40 INFO Vacuumed table table=closures19682026/10/06 21:27:40 INFO Vacuumed table table=objects1969--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1970 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.61s)1971 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.53s)19722026/10/06 21:27:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19732026/10/06 21:27:40 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MWE2Njc2ZjAtMDZiZC00MGZiLWJhYTctODM2NDdiNzY1MmE0LjA3Y2Q2ZWFlLTUwYzQtNGQxNy05MWFjLTljMTZiNDAxYTg0MngxNzkxMzIyMDU5NTE5MzU0MzM0 parts=1219742026/10/06 21:27:40 INFO Received uploads request method=POST path=/api/pending_closures1975--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.12s)1976--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)1977 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1978 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.08s)1979 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.60s)19802026/10/06 21:27:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19812026/10/06 21:27:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MWE2Njc2ZjAtMDZiZC00MGZiLWJhYTctODM2NDdiNzY1MmE0LjllODllOGM0LWUxYzgtNGM0MC1iMDI2LWM2NDgyZTY0NWQ1NXgxNzkxMzIyMDU5NjQ4MTMzNzU1 parts=1219822026/10/06 21:27:40 INFO Received uploads request method=POST path=/api/pending_closures19832026/10/06 21:27:40 INFO Received uploads request method=POST path=/api/pending_closures19842026/10/06 21:27:40 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19852026/10/06 21:27:40 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19862026/10/06 21:27:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=738.710305ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19872026/10/06 21:27:40 INFO lead: released remote=192.0.2.1:12341988--- PASS: TestLeadElectsOneAndHandsOver (3.37s)1989--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)1990 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.90s)1991 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.93s)1992--- PASS: TestPendingClosureWriteTimeout (0.09s)1993 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1994 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1995 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1996 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.38s)19972026/10/06 21:27:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01998=== NAME TestClientIntegration1999 client_integration_test.go:323: Objects in database after GC:2000 client_integration_test.go:323: Successfully deleted all objects with GC --force2001--- PASS: TestClientIntegration (2.96s)20022026/10/06 21:27:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020032026/10/06 21:27:40 INFO Received create pin request method=POST path=/api/pins/myapp20042026/10/06 21:27:40 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC782994136/001/store/gqc1bmsw14zw8nv7yabr28ik61727ccw-pinned-file.txt narinfo_key=gqc1bmsw14zw8nv7yabr28ik61727ccw.narinfo20052026/10/06 21:27:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures20062026/10/06 21:27:40 INFO Garbage collection started20072026/10/06 21:27:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20082026/10/06 21:27:40 INFO Aborted multipart uploads count=0 kept=020092026/10/06 21:27:40 WARN Force mode enabled - objects will be deleted immediately without grace period20102026/10/06 21:27:40 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=020112026/10/06 21:27:40 INFO Vacuumed table table=pending_closures20122026/10/06 21:27:40 INFO Vacuumed table table=pending_objects20132026/10/06 21:27:40 INFO Vacuumed table table=multipart_uploads20142026/10/06 21:27:40 INFO Vacuumed table table=closures20152026/10/06 21:27:40 INFO Vacuumed table table=objects20162026/10/06 21:27:40 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWE2Njc2ZjAtMDZiZC00MGZiLWJhYTctODM2NDdiNzY1MmE0LmQyZTcxNTQ5LWM3ZDAtNGMxYS1iNGU3LTMyNWVkNGYwZThlNXgxNzkxMzIyMDYwMzAxMTE3NTcx error="Get \"http://127.0.0.1:1/bucket80/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"20172026/10/06 21:27:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWE2Njc2ZjAtMDZiZC00MGZiLWJhYTctODM2NDdiNzY1MmE0LmEyNjcyYWFlLTYyZmUtNDY4Ni05ZjY0LTAwZWQ1MzJlNTJmOHgxNzkxMzIyMDYwMjk1MDk4MTYx parts=1220182026/10/06 21:27:40 INFO Received cleanup request method=DELETE path=/api/pending_closures20192026/10/06 21:27:40 INFO Aborted multipart uploads count=1 kept=02020--- PASS: TestRedundantMultipartUpload (1.68s)2021=== NAME TestOrphanedObjectsGCStressTest2022 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2023 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20242026/10/06 21:27:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.503479326s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2025 orphaned_objects_gc_test.go:503: Stress test completed successfully:2026 orphaned_objects_gc_test.go:504: - Active objects preserved: 202027 orphaned_objects_gc_test.go:505: - Objects deleted: 2102028 orphaned_objects_gc_test.go:506: - Total GC'd: 2102029--- PASS: TestOrphanedObjectsGCStressTest (2.19s)2030--- PASS: TestConnectWaitsForAPeerMigration (5.36s)20312026/10/06 21:27:42 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-config20322026/10/06 21:27:42 WARN Rate limiter enabled after throttle name=s3-test rate=520332026/10/06 21:27:42 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2034=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2035 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102036 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002037--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.21s)2038=== NAME TestPinProtectsFromGC2039 client_integration_test.go:840: Pin successfully protected closure from garbage collection2040--- PASS: TestPinProtectsFromGC (5.07s)20412026/10/06 21:27:42 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.437085ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20422026/10/06 21:27:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=418.977834ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2043--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.54s)20442026/10/06 21:27:43 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=780.231499ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20452026/10/06 21:27:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.475844256s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20462026/10/06 21:27:45 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"20472026/10/06 21:27:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20482026/10/06 21:27:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.472041ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20492026/10/06 21:27:45 INFO Aborted multipart uploads count=1 kept=020502026/10/06 21:27:45 INFO Received cleanup request method=DELETE path=/api/pending_closures20512026/10/06 21:27:45 INFO Aborted multipart uploads count=1 kept=02052--- PASS: TestPendingCleanupUsesOneCutoff (6.61s)20532026/10/06 21:27:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=392.58275ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20542026/10/06 21:27:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=844.885557ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20552026/10/06 21:27:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.678728598s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20562026/10/06 21:27:49 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_closures20572026/10/06 21:27:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.268917ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20582026/10/06 21:27:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=419.909584ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20592026/10/06 21:27:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=750.008682ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20602026/10/06 21:27:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.643937838s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2061--- PASS: TestClientErrorHandling (0.00s)2062 --- PASS: TestClientErrorHandling/InvalidStorePath (0.46s)2063 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.55s)2064 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.35s)2065PASS20662026-10-06 21:27:52.506 UTC [129] LOG: received smart shutdown request20672026-10-06 21:27:52.511 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120682026-10-06 21:27:52.524 UTC [134] LOG: shutting down20692026-10-06 21:27:52.525 UTC [134] LOG: checkpoint starting: shutdown immediate20702026-10-06 21:27:54.369 UTC [134] LOG: checkpoint complete: wrote 11173 buffers (68.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.301 s, sync=1.477 s, total=1.845 s; sync files=33373, longest=0.002 s, average=0.001 s; distance=484076 kB, estimate=484076 kB; lsn=0/1F020EB8, redo lsn=0/1F020EB820712026-10-06 21:27:54.433 UTC [129] LOG: database system is shut down2072Running OIDC tests...2073=== RUN TestAudienceForIssuer2074=== PAUSE TestAudienceForIssuer2075=== RUN TestGlobMatch2076=== PAUSE TestGlobMatch2077=== RUN TestValidateToken_ValidToken2078=== PAUSE TestValidateToken_ValidToken2079=== RUN TestValidateToken_WrongAudience2080=== PAUSE TestValidateToken_WrongAudience2081=== RUN TestValidateToken_Expired2082=== PAUSE TestValidateToken_Expired2083=== RUN TestValidateToken_BoundClaimsMismatch2084=== PAUSE TestValidateToken_BoundClaimsMismatch2085=== RUN TestValidateToken_BoundSubjectMismatch2086=== PAUSE TestValidateToken_BoundSubjectMismatch2087=== RUN TestValidateToken_MultipleProviders2088=== PAUSE TestValidateToken_MultipleProviders2089=== RUN TestValidateToken_NoMatchingProvider2090=== PAUSE TestValidateToken_NoMatchingProvider2091=== RUN TestValidateToken_KubernetesServiceAccount2092=== PAUSE TestValidateToken_KubernetesServiceAccount2093=== RUN TestNewValidator_KubernetesRequiresCA2094=== PAUSE TestNewValidator_KubernetesRequiresCA2095=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2096=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2097=== RUN TestPins_ReservedForMatchingRule2098=== PAUSE TestPins_ReservedForMatchingRule2099=== RUN TestPins_TopLevelShorthand2100=== PAUSE TestPins_TopLevelShorthand2101=== RUN TestPins_ConfigValidation2102=== PAUSE TestPins_ConfigValidation2103=== RUN TestScopes_LegacyProviderDefaultsToWrite2104=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2105=== RUN TestScopes_Rules2106=== PAUSE TestScopes_Rules2107=== RUN TestScopes_ConfigValidation2108=== PAUSE TestScopes_ConfigValidation2109=== CONT TestAudienceForIssuer2110=== CONT TestValidateToken_KubernetesServiceAccount2111=== CONT TestValidateToken_BoundClaimsMismatch2112=== CONT TestValidateToken_NoMatchingProvider2113=== CONT TestValidateToken_MultipleProviders2114=== CONT TestValidateToken_BoundSubjectMismatch2115=== CONT TestPins_ConfigValidation2116--- PASS: TestAudienceForIssuer (0.00s)2117=== CONT TestScopes_ConfigValidation2118=== CONT TestValidateToken_ValidToken2119=== CONT TestScopes_Rules2120=== CONT TestGlobMatch2121=== RUN TestGlobMatch/foo_foo2122=== PAUSE TestGlobMatch/foo_foo2123=== CONT TestScopes_LegacyProviderDefaultsToWrite2124--- PASS: TestPins_ConfigValidation (0.00s)2125--- PASS: TestScopes_ConfigValidation (0.00s)2126=== CONT TestValidateToken_Expired2127=== CONT TestPins_TopLevelShorthand2128=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2129=== CONT TestNewValidator_KubernetesRequiresCA2130=== CONT TestValidateToken_WrongAudience2131=== RUN TestGlobMatch/foo_bar2132=== PAUSE TestGlobMatch/foo_bar2133=== CONT TestPins_ReservedForMatchingRule2134=== RUN TestGlobMatch/*_2135=== PAUSE TestGlobMatch/*_2136=== RUN TestGlobMatch/*_anything2137=== PAUSE TestGlobMatch/*_anything2138=== RUN TestGlobMatch/foo*_foo2139=== PAUSE TestGlobMatch/foo*_foo2140=== RUN TestGlobMatch/foo*_foobar2141=== PAUSE TestGlobMatch/foo*_foobar2142=== RUN TestGlobMatch/foo*_bar2143=== PAUSE TestGlobMatch/foo*_bar2144=== RUN TestGlobMatch/*bar_bar2145=== PAUSE TestGlobMatch/*bar_bar2146=== RUN TestGlobMatch/*bar_foobar2147=== PAUSE TestGlobMatch/*bar_foobar2148=== RUN TestGlobMatch/*bar_foo2149=== PAUSE TestGlobMatch/*bar_foo2150=== RUN TestGlobMatch/foo*bar_foobar2151=== PAUSE TestGlobMatch/foo*bar_foobar2152=== RUN TestGlobMatch/foo*bar_foo123bar2153=== PAUSE TestGlobMatch/foo*bar_foo123bar2154=== RUN TestGlobMatch/foo*bar_foobarbaz2155=== PAUSE TestGlobMatch/foo*bar_foobarbaz2156=== RUN TestGlobMatch/*/*_foo/bar2157=== PAUSE TestGlobMatch/*/*_foo/bar2158=== RUN TestGlobMatch/*/*_foo2159=== PAUSE TestGlobMatch/*/*_foo2160=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2161=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2162=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02163=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02164=== RUN TestGlobMatch/refs/*/main_refs/heads/main2165=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2166=== RUN TestGlobMatch/fo?_foo2167=== PAUSE TestGlobMatch/fo?_foo2168=== RUN TestGlobMatch/fo?_fo2169=== PAUSE TestGlobMatch/fo?_fo2170=== RUN TestGlobMatch/fo?_fooo2171=== PAUSE TestGlobMatch/fo?_fooo2172=== RUN TestGlobMatch/?oo_foo2173=== PAUSE TestGlobMatch/?oo_foo2174=== RUN TestGlobMatch/?oo_boo2175=== PAUSE TestGlobMatch/?oo_boo2176=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2177=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2178=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2179=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2180=== CONT TestGlobMatch/foo_foo2181=== CONT TestGlobMatch/fo?_fooo2182=== CONT TestGlobMatch/fo?_fo2183=== CONT TestGlobMatch/fo?_foo2184=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2185=== CONT TestGlobMatch/?oo_foo2186=== CONT TestGlobMatch/*bar_foo2187=== CONT TestGlobMatch/*bar_foobar2188=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2189=== CONT TestGlobMatch/refs/*/main_refs/heads/main2190=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02191=== CONT TestGlobMatch/foo*_foo2192=== CONT TestGlobMatch/*_anything2193=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2194=== CONT TestGlobMatch/*/*_foo2195=== CONT TestGlobMatch/?oo_boo2196=== CONT TestGlobMatch/*/*_foo/bar2197=== CONT TestGlobMatch/foo*bar_foobarbaz2198=== CONT TestGlobMatch/foo*bar_foo123bar2199=== CONT TestGlobMatch/foo*bar_foobar2200=== CONT TestGlobMatch/*bar_bar2201=== CONT TestGlobMatch/foo*_bar2202=== CONT TestGlobMatch/foo*_foobar2203=== CONT TestGlobMatch/*_2204=== CONT TestGlobMatch/foo_bar2205--- PASS: TestGlobMatch (0.00s)2206 --- PASS: TestGlobMatch/foo_foo (0.00s)2207 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2208 --- PASS: TestGlobMatch/fo?_fo (0.00s)2209 --- PASS: TestGlobMatch/fo?_foo (0.00s)2210 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2211 --- PASS: TestGlobMatch/*bar_foo (0.00s)2212 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2213 --- PASS: TestGlobMatch/?oo_foo (0.00s)2214 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2215 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2216 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2217 --- PASS: TestGlobMatch/foo*_foo (0.00s)2218 --- PASS: TestGlobMatch/*_anything (0.00s)2219 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2220 --- PASS: TestGlobMatch/*/*_foo (0.00s)2221 --- PASS: TestGlobMatch/?oo_boo (0.00s)2222 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2223 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2224 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2225 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2226 --- PASS: TestGlobMatch/*bar_bar (0.00s)2227 --- PASS: TestGlobMatch/foo*_bar (0.00s)2228 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2229 --- PASS: TestGlobMatch/*_ (0.00s)2230 --- PASS: TestGlobMatch/foo_bar (0.00s)22312026/10/06 21:27:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37621/oidc22322026/10/06 21:27:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40191/oidc2233--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)22342026/10/06 21:27:56 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:405552235--- PASS: TestPins_ReservedForMatchingRule (0.03s)2236--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)22372026/10/06 21:27:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33469/oidc22382026/10/06 21:27:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41597/oidc22392026/10/06 21:27:56 http: TLS handshake error from 127.0.0.1:40764: remote error: tls: bad certificate2240--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)2241--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)2242--- PASS: TestValidateToken_BoundSubjectMismatch (0.04s)22432026/10/06 21:27:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35539/oidc2244--- PASS: TestPins_TopLevelShorthand (0.05s)22452026/10/06 21:27:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34081/oidc2246--- PASS: TestValidateToken_WrongAudience (0.06s)22472026/10/06 21:27:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42715/oidc2248--- PASS: TestValidateToken_ValidToken (0.06s)22492026/10/06 21:27:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34071/oidc22502026/10/06 21:27:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44265/oidc2251--- PASS: TestValidateToken_Expired (0.07s)2252--- PASS: TestScopes_Rules (0.07s)22532026/10/06 21:27:57 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34323/oidc2254--- PASS: TestValidateToken_NoMatchingProvider (0.11s)22552026/10/06 21:27:57 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232256--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.13s)22572026/10/06 21:27:57 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37485/oidc22582026/10/06 21:27:57 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34785/oidc2259--- PASS: TestValidateToken_MultipleProviders (0.29s)2260PASS2261Running hook tests...2262=== RUN TestSendPathsEmpty2263=== PAUSE TestSendPathsEmpty2264=== RUN TestQueueEnqueueAndFetch2265=== PAUSE TestQueueEnqueueAndFetch2266=== RUN TestQueueDeduplication2267=== PAUSE TestQueueDeduplication2268=== RUN TestQueueRemove2269=== PAUSE TestQueueRemove2270=== RUN TestQueueFetchBatchLimit2271=== PAUSE TestQueueFetchBatchLimit2272=== RUN TestQueueRetryMovesToBack2273=== PAUSE TestQueueRetryMovesToBack2274=== RUN TestQueueFetchRemoveLifecycle2275=== PAUSE TestQueueFetchRemoveLifecycle2276=== RUN TestQueueConcurrentWriters2277=== PAUSE TestQueueConcurrentWriters2278=== RUN TestQueueRemoveLargeClosure2279=== PAUSE TestQueueRemoveLargeClosure2280=== RUN TestServerClientIntegration2281=== PAUSE TestServerClientIntegration2282=== RUN TestServerQueueError2283=== PAUSE TestServerQueueError2284=== RUN TestGetListenerSocketActivation2285 server_test.go:210: === RUN TestGetListenerSocketActivation2286 --- PASS: TestGetListenerSocketActivation (0.00s)2287 PASS2288 2289--- PASS: TestGetListenerSocketActivation (0.01s)2290=== RUN TestDrainIsolatesPoisonPath2291=== PAUSE TestDrainIsolatesPoisonPath2292=== RUN TestRunNotBlockedByPoisonHead2293=== PAUSE TestRunNotBlockedByPoisonHead2294=== RUN TestDrainGivesUpWhenServerDown2295=== PAUSE TestDrainGivesUpWhenServerDown2296=== RUN TestFailedPathPrunedByLaterClosure2297=== PAUSE TestFailedPathPrunedByLaterClosure2298=== RUN TestWorkerUploadsAndRemoves2299=== PAUSE TestWorkerUploadsAndRemoves2300=== RUN TestWorkerSkipsGCdPaths2301=== PAUSE TestWorkerSkipsGCdPaths2302=== RUN TestWorkerPrunesClosureDeps2303=== PAUSE TestWorkerPrunesClosureDeps2304=== RUN TestDrainTimeout2305=== PAUSE TestDrainTimeout2306=== CONT TestSendPathsEmpty2307=== CONT TestServerQueueError2308--- PASS: TestSendPathsEmpty (0.00s)2309=== CONT TestServerClientIntegration2310=== CONT TestQueueRemoveLargeClosure2311=== CONT TestQueueConcurrentWriters23122026/10/06 21:27:57 ERROR Failed to queue paths error="permission denied" count=12313=== CONT TestQueueFetchRemoveLifecycle2314=== CONT TestQueueRetryMovesToBack2315=== CONT TestQueueFetchBatchLimit2316=== CONT TestQueueRemove2317=== CONT TestQueueDeduplication2318--- PASS: TestServerQueueError (0.00s)2319=== CONT TestQueueEnqueueAndFetch2320=== CONT TestDrainGivesUpWhenServerDown2321=== CONT TestFailedPathPrunedByLaterClosure2322=== CONT TestRunNotBlockedByPoisonHead2323=== CONT TestDrainIsolatesPoisonPath2324=== CONT TestWorkerPrunesClosureDeps2325=== CONT TestDrainTimeout2326=== CONT TestWorkerUploadsAndRemoves2327=== CONT TestWorkerSkipsGCdPaths2328--- PASS: TestServerClientIntegration (0.00s)23292026/10/06 21:27:57 INFO Upload queue status pending=223302026/10/06 21:27:57 INFO Upload queue status pending=22331--- PASS: TestQueueDeduplication (0.02s)23322026/10/06 21:27:57 INFO Uploading batch count=223332026/10/06 21:27:57 INFO Upload queue status pending=323342026/10/06 21:27:57 INFO Uploading batch count=123352026/10/06 21:27:57 INFO Uploading batch count=423362026/10/06 21:27:57 ERROR Upload failed error="upload failed" count=423372026/10/06 21:27:57 INFO Uploading batch count=12338--- PASS: TestQueueEnqueueAndFetch (0.02s)23392026/10/06 21:27:57 INFO Uploading batch count=223402026/10/06 21:27:57 INFO Upload queue status pending=223412026/10/06 21:27:57 INFO Uploading batch count=12342--- PASS: TestQueueFetchBatchLimit (0.02s)23432026/10/06 21:27:57 ERROR Upload failed error="upload failed" count=12344--- PASS: TestQueueRetryMovesToBack (0.02s)23452026/10/06 21:27:57 ERROR Upload failed error="upload failed" count=123462026/10/06 21:27:57 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2454092680/002/nonexistent23472026/10/06 21:27:57 INFO Uploading batch count=223482026/10/06 21:27:57 ERROR Upload failed error="upload failed" count=223492026/10/06 21:27:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2910403489/002/a23502026/10/06 21:27:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3604231284/002/bbb23512026/10/06 21:27:57 INFO Uploading batch count=12352--- PASS: TestQueueRemove (0.02s)23532026/10/06 21:27:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2910403489/002/b23542026/10/06 21:27:57 INFO Uploading batch count=12355--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23562026/10/06 21:27:57 INFO Uploading batch count=123572026/10/06 21:27:57 INFO Uploading batch count=223582026/10/06 21:27:57 ERROR Upload failed error="upload failed" count=223592026/10/06 21:27:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2910403489/002/c23602026/10/06 21:27:57 INFO Uploading batch count=123612026/10/06 21:27:57 ERROR Upload failed error="upload failed" count=123622026/10/06 21:27:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2910403489/002/d23632026/10/06 21:27:57 INFO Uploading batch count=123642026/10/06 21:27:57 ERROR Upload failed error="upload failed" count=123652026/10/06 21:27:57 INFO Uploading batch count=223662026/10/06 21:27:57 ERROR Upload failed error="upload failed" count=223672026/10/06 21:27:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2910403489/002/e23682026/10/06 21:27:57 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2910403489/002/f2369--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23702026/10/06 21:27:57 INFO Uploading batch count=123712026/10/06 21:27:57 ERROR Upload failed error="upload failed" count=123722026/10/06 21:27:57 ERROR Drain finished with paths left in queue remaining=1023732026/10/06 21:27:57 ERROR Drain finished with paths left in queue remaining=12374--- PASS: TestDrainIsolatesPoisonPath (0.03s)2375--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2376--- PASS: TestWorkerPrunesClosureDeps (0.04s)2377--- PASS: TestWorkerSkipsGCdPaths (0.04s)2378--- PASS: TestWorkerUploadsAndRemoves (0.04s)2379--- PASS: TestQueueRemoveLargeClosure (0.06s)23802026/10/06 21:27:57 ERROR Upload failed error="context deadline exceeded" count=223812026/10/06 21:27:57 ERROR Drain finished with paths left in queue remaining=42382--- PASS: TestDrainTimeout (0.22s)2383--- PASS: TestQueueConcurrentWriters (0.28s)23842026/10/06 21:27:58 INFO Uploading batch count=123852026/10/06 21:27:58 INFO Uploading batch count=123862026/10/06 21:27:58 INFO Uploading batch count=123872026/10/06 21:27:58 ERROR Upload failed error="upload failed" count=123882026/10/06 21:27:58 INFO Uploading batch count=123892026/10/06 21:27:58 ERROR Upload failed error="upload failed" count=123902026/10/06 21:27:58 INFO Uploading batch count=123912026/10/06 21:27:58 ERROR Upload failed error="upload failed" count=123922026/10/06 21:27:58 INFO Uploading batch count=123932026/10/06 21:27:58 ERROR Upload failed error="upload failed" count=123942026/10/06 21:27:58 ERROR Drain finished with paths left in queue remaining=12395--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2396PASS2397Running signing tests...2398=== RUN TestExternalSigner2399=== PAUSE TestExternalSigner2400=== RUN TestExternalSignerWrongPublicKey2401=== PAUSE TestExternalSignerWrongPublicKey2402=== RUN TestExternalSignerErrors2403=== PAUSE TestExternalSignerErrors2404=== RUN TestExternalSignerRestartsAfterCrash2405=== PAUSE TestExternalSignerRestartsAfterCrash2406=== RUN TestExternalSignerProgramErrorKeepsProcess2407=== PAUSE TestExternalSignerProgramErrorKeepsProcess2408=== RUN TestExternalSignerClose2409=== PAUSE TestExternalSignerClose2410=== RUN TestExternalSignerRejectsInvalidPublicKey2411=== PAUSE TestExternalSignerRejectsInvalidPublicKey2412=== RUN TestExternalSignerCancellation2413=== PAUSE TestExternalSignerCancellation2414=== RUN TestGenerateFingerprint2415=== PAUSE TestGenerateFingerprint2416=== RUN TestParseSigningKey2417=== PAUSE TestParseSigningKey2418=== RUN TestSign2419=== PAUSE TestSign2420=== RUN TestSignBatch2421=== PAUSE TestSignBatch2422=== RUN TestNilKeyPublicKey2423=== PAUSE TestNilKeyPublicKey2424=== RUN TestSignErrors2425=== PAUSE TestSignErrors2426=== CONT TestExternalSigner2427=== CONT TestSignBatch2428=== CONT TestExternalSignerCancellation2429=== CONT TestParseSigningKey2430=== CONT TestGenerateFingerprint2431=== RUN TestParseSigningKey/valid_32-byte_key2432=== CONT TestSign2433=== CONT TestExternalSignerProgramErrorKeepsProcess2434=== CONT TestExternalSignerErrors2435=== CONT TestExternalSignerRejectsInvalidPublicKey2436=== RUN TestExternalSignerRejectsInvalidPublicKey/#002437=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002438=== CONT TestExternalSignerRestartsAfterCrash2439=== CONT TestExternalSignerClose2440=== CONT TestExternalSignerWrongPublicKey2441=== CONT TestNilKeyPublicKey2442=== PAUSE TestParseSigningKey/valid_32-byte_key2443=== CONT TestSignErrors2444=== RUN TestGenerateFingerprint/basic_with_references2445--- PASS: TestSignBatch (0.00s)2446--- PASS: TestSign (0.00s)2447--- PASS: TestNilKeyPublicKey (0.00s)2448=== PAUSE TestGenerateFingerprint/basic_with_references2449=== RUN TestGenerateFingerprint/no_references2450=== PAUSE TestGenerateFingerprint/no_references2451=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2452=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2453=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2454=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2455=== RUN TestGenerateFingerprint/invalid_nar_hash_length2456=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2457=== RUN TestGenerateFingerprint/invalid_store_path_prefix2458=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2459=== RUN TestGenerateFingerprint/invalid_reference_prefix2460=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2461=== CONT TestGenerateFingerprint/basic_with_references2462=== RUN TestExternalSignerErrors/exit_at_startup2463=== PAUSE TestExternalSignerErrors/exit_at_startup2464=== RUN TestExternalSignerErrors/exit_on_request2465=== PAUSE TestExternalSignerErrors/exit_on_request2466=== CONT TestGenerateFingerprint/invalid_reference_prefix2467=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2468=== CONT TestGenerateFingerprint/invalid_store_path_prefix2469=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2470=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2471=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2472=== CONT TestGenerateFingerprint/no_references2473=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2474=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2475=== RUN TestSignErrors/nil_key2476=== PAUSE TestSignErrors/nil_key2477=== RUN TestSignErrors/nil_narinfo2478=== PAUSE TestSignErrors/nil_narinfo2479=== RUN TestSignErrors/invalid_narinfo2480=== PAUSE TestSignErrors/invalid_narinfo2481=== RUN TestSignErrors/canceled2482=== PAUSE TestSignErrors/canceled2483=== CONT TestSignErrors/nil_key2484=== RUN TestExternalSignerErrors/invalid_JSON2485=== CONT TestSignErrors/nil_narinfo2486=== CONT TestGenerateFingerprint/invalid_nar_hash_length2487--- PASS: TestGenerateFingerprint (0.00s)2488 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2489 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2490 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2491 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2492 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2493 --- PASS: TestGenerateFingerprint/no_references (0.00s)2494 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2495=== RUN TestParseSigningKey/no_colon2496=== PAUSE TestParseSigningKey/no_colon2497=== RUN TestParseSigningKey/empty_name2498=== PAUSE TestParseSigningKey/empty_name2499=== RUN TestParseSigningKey/invalid_base642500=== PAUSE TestParseSigningKey/invalid_base642501=== RUN TestParseSigningKey/wrong_length2502=== PAUSE TestParseSigningKey/wrong_length2503=== CONT TestParseSigningKey/valid_32-byte_key2504=== CONT TestParseSigningKey/empty_name2505=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2506=== CONT TestParseSigningKey/invalid_base642507=== CONT TestSignErrors/invalid_narinfo2508=== CONT TestSignErrors/canceled2509--- PASS: TestSignErrors (0.00s)2510 --- PASS: TestSignErrors/nil_key (0.00s)2511 --- PASS: TestSignErrors/nil_narinfo (0.00s)2512 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2513 --- PASS: TestSignErrors/canceled (0.00s)2514=== PAUSE TestExternalSignerErrors/invalid_JSON2515=== RUN TestExternalSignerErrors/missing_signatures2516=== PAUSE TestExternalSignerErrors/missing_signatures2517=== RUN TestExternalSignerErrors/null_signatures2518=== PAUSE TestExternalSignerErrors/null_signatures2519=== RUN TestExternalSignerErrors/wrong_signature_name2520=== PAUSE TestExternalSignerErrors/wrong_signature_name2521=== RUN TestExternalSignerErrors/wrong_shape2522=== PAUSE TestExternalSignerErrors/wrong_shape2523=== RUN TestExternalSignerErrors/null2524=== PAUSE TestExternalSignerErrors/null2525=== CONT TestParseSigningKey/wrong_length2526=== CONT TestParseSigningKey/no_colon2527=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2528=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2529=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2530=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2531=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2532=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2533=== CONT TestExternalSignerRejectsInvalidPublicKey/#002534=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2535=== RUN TestExternalSignerErrors/wrong_id2536=== PAUSE TestExternalSignerErrors/wrong_id2537=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2538--- PASS: TestParseSigningKey (0.00s)2539 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2540 --- PASS: TestParseSigningKey/empty_name (0.00s)2541 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2542 --- PASS: TestParseSigningKey/wrong_length (0.00s)2543 --- PASS: TestParseSigningKey/no_colon (0.00s)2544 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2545=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2546=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2547=== RUN TestExternalSignerErrors/too_few_signatures2548=== PAUSE TestExternalSignerErrors/too_few_signatures2549--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2550 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2551 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2552 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2553 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2554 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2555=== RUN TestExternalSignerErrors/unrequested_key2556=== PAUSE TestExternalSignerErrors/unrequested_key2557=== RUN TestExternalSignerErrors/missing_signature_name2558=== PAUSE TestExternalSignerErrors/missing_signature_name2559=== RUN TestExternalSignerErrors/program_error2560=== PAUSE TestExternalSignerErrors/program_error2561=== RUN TestExternalSignerErrors/wrong_signatures_shape2562=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2563=== RUN TestExternalSignerErrors/invalid_signature_base642564=== PAUSE TestExternalSignerErrors/invalid_signature_base642565=== RUN TestExternalSignerErrors/wrong_signature_length2566=== PAUSE TestExternalSignerErrors/wrong_signature_length2567=== CONT TestExternalSignerErrors/exit_at_startup2568=== CONT TestExternalSignerErrors/null2569=== CONT TestExternalSignerErrors/wrong_signature_name2570=== CONT TestExternalSignerErrors/too_few_signatures2571=== CONT TestExternalSignerErrors/wrong_signature_length2572=== CONT TestExternalSignerErrors/wrong_signatures_shape2573=== CONT TestExternalSignerErrors/program_error2574=== CONT TestExternalSignerErrors/missing_signature_name2575=== CONT TestExternalSignerErrors/unrequested_key2576=== CONT TestExternalSignerErrors/wrong_shape2577=== CONT TestExternalSignerErrors/wrong_id2578=== CONT TestExternalSignerErrors/missing_signatures2579=== CONT TestExternalSignerErrors/null_signatures2580=== CONT TestExternalSignerErrors/invalid_JSON2581=== CONT TestExternalSignerErrors/exit_on_request2582=== CONT TestExternalSignerErrors/invalid_signature_base642583--- PASS: TestExternalSignerClose (0.00s)2584--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2585--- PASS: TestExternalSignerWrongPublicKey (0.01s)2586--- PASS: TestExternalSigner (0.01s)2587--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2588--- PASS: TestExternalSignerErrors (0.00s)2589 --- PASS: TestExternalSignerErrors/null (0.00s)2590 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2591 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2592 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2593 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2594 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2595 --- PASS: TestExternalSignerErrors/program_error (0.01s)2596 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2597 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2598 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2599 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2600 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2601 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2602 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2603 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2604 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2605--- PASS: TestExternalSignerCancellation (0.02s)2606PASS2607Running OpenBao signer tests...2608=== RUN TestSign2609=== PAUSE TestSign2610=== RUN TestSignErrors2611=== PAUSE TestSignErrors2612=== RUN TestServe2613=== PAUSE TestServe2614=== RUN TestServeRejectsGarbage2615=== PAUSE TestServeRejectsGarbage2616=== CONT TestSign2617=== CONT TestSignErrors2618=== CONT TestServe2619=== CONT TestServeRejectsGarbage2620=== RUN TestSignErrors/no_prefix2621=== PAUSE TestSignErrors/no_prefix2622--- PASS: TestServeRejectsGarbage (0.00s)2623--- PASS: TestServe (0.00s)2624=== RUN TestSignErrors/invalid_base642625=== PAUSE TestSignErrors/invalid_base642626=== RUN TestSignErrors/http_error2627=== PAUSE TestSignErrors/http_error2628=== RUN TestSignErrors/invalid_json2629=== PAUSE TestSignErrors/invalid_json2630=== CONT TestSignErrors/no_prefix2631=== CONT TestSignErrors/invalid_base642632=== CONT TestSignErrors/http_error2633=== CONT TestSignErrors/invalid_json2634--- PASS: TestSign (0.00s)2635--- PASS: TestSignErrors (0.00s)2636 --- PASS: TestSignErrors/no_prefix (0.00s)2637 --- PASS: TestSignErrors/invalid_json (0.00s)2638 --- PASS: TestSignErrors/invalid_base64 (0.00s)2639 --- PASS: TestSignErrors/http_error (0.00s)2640PASS