niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #387
· 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 TestEncodeNixBase32101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102=== CONT TestScriptTokenEmptyCommand103--- PASS: TestScriptTokenEmptyCommand (0.00s)104=== CONT TestScriptTokenScriptFails105=== CONT TestScriptTokenBadJSON106=== CONT TestScriptTokenEmptyToken107=== CONT TestScriptTokenCachesUntilRefresh108=== CONT TestScriptTokenNoExpiryRerunsEveryCall109=== CONT TestFileTokenEmpty110=== CONT TestFileTokenMissing111=== CONT TestFileTokenReadsAndCaches112--- PASS: TestScriptTokenScriptFails (0.00s)113=== CONT TestPathInfoCACompatibility114=== RUN TestPathInfoCACompatibility/null_ca_field115=== CONT TestStaticToken116--- PASS: TestStaticToken (0.00s)117=== CONT TestSetClientTLSErrors118=== CONT TestSetClientTLSDoesNotMutateDefaultTransport119--- PASS: TestFileTokenMissing (0.00s)120=== CONT TestSetClientTLS121=== CONT TestClientSignaturesByStorePath122=== CONT TestParsePathInfoJSONMultiplePaths123=== CONT TestStreamPushReportsSignatures124=== CONT TestResolveStorePath125=== CONT TestStreamPushRequestLine126=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess127=== CONT TestStreamPushGivesUpOnDeadServer128=== CONT TestRateLimiterFeedback129=== RUN TestEncodeNixBase32/test_string_hash130=== CONT TestStreamPushIsolatesFailures131=== PAUSE TestPathInfoCACompatibility/null_ca_field132=== CONT TestStreamPushBatchesUnderLoad133=== CONT TestGetStorePathHash134--- PASS: TestClientSignaturesByStorePath (0.00s)135=== CONT TestStreamPushReportsEveryPath136=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths137=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths138=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths139=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths140=== RUN TestPathInfoCACompatibility/old_string_format_-_text141--- PASS: TestFileTokenReadsAndCaches (0.00s)142=== CONT TestParsePathInfoJSON143=== RUN TestParsePathInfoJSON/Nix_format144=== PAUSE TestParsePathInfoJSON/Nix_format145=== RUN TestParsePathInfoJSON/Lix_format146=== PAUSE TestParsePathInfoJSON/Lix_format147--- PASS: TestScriptTokenBadJSON (0.01s)148=== RUN TestParsePathInfoJSON/empty_input149=== CONT TestShellSplitErrors150--- PASS: TestShellSplitErrors (0.00s)1512026/10/06 21:24:02 WARN Rate limiter enabled after throttle name=server-test rate=5152=== RUN TestGetStorePathHash/valid_store_path153--- PASS: TestFileTokenEmpty (0.01s)1542026/10/06 21:24:02 ERROR Upload failed error="bad path" count=3155=== RUN TestRateLimiterFeedback/429_enables_limiter156=== PAUSE TestGetStorePathHash/valid_store_path157=== PAUSE TestEncodeNixBase32/test_string_hash158=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text159=== RUN TestEncodeNixBase32/empty_input160=== PAUSE TestEncodeNixBase32/empty_input161=== PAUSE TestRateLimiterFeedback/429_enables_limiter1622026/10/06 21:24:02 ERROR Upload failed error="connection refused" count=20163=== CONT TestDumpPathMatchesNix1642026/10/06 21:24:02 ERROR Server seems unavailable, giving up on batch untried=17165=== RUN TestRateLimiterFeedback/503_enables_limiter166=== PAUSE TestRateLimiterFeedback/503_enables_limiter1672026/10/06 21:24:02 WARN Rate limiter enabled after throttle name=server-test rate=5168=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter169=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter170=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter171=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter172--- PASS: TestResolveStorePath (0.00s)1732026/10/06 21:24:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:36561174=== CONT TestPathInfoHashCompatibility175=== CONT TestDumpPathWriterError1762026/10/06 21:24:02 ERROR Upload failed error=boom count=1177--- PASS: TestStreamPushIsolatesFailures (0.00s)178=== CONT TestUploadMultipart_SupersededByPeer179=== RUN TestUploadMultipart_SupersededByPeer/exists1802026/10/06 21:24:02 WARN Rate limiter backed off name=server-test rate=5181=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive182=== CONT TestPartSizeForNAR1832026/10/06 21:24:02 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:36561184=== RUN TestPartSizeForNAR/zero_stays_at_minimum1852026/10/06 21:24:02 ERROR Upload failed error=boom count=1186=== PAUSE TestParsePathInfoJSON/empty_input187=== CONT TestShellSplit188=== CONT TestConvertHashToNix32189=== RUN TestGetStorePathHash/basename_without_hyphen_should_error190=== CONT TestDumpPathSingleFile191=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)192=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun193=== RUN TestConvertHashToNix32/SRI_format_to_Nix32194=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error195=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica196=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error197=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error198--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)199=== CONT TestFilterOversizedClosures200=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive201=== PAUSE TestUploadMultipart_SupersededByPeer/exists202=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum203=== CONT TestRegisterUploadedObjectReusesConnections204=== RUN TestParsePathInfoJSON/whitespace_only205=== CONT TestCaseHackSuffix206=== RUN TestPartSizeForNAR/small_stays_at_minimum207=== PAUSE TestPartSizeForNAR/small_stays_at_minimum208=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)209=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32210=== CONT TestUploadMultipart_PartsInParallel211=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error212--- PASS: TestStreamPushReportsEveryPath (0.00s)213=== RUN TestFilterOversizedClosures/no_limit_keeps_everything214=== RUN TestSetClientTLSErrors/missing_cert_file215=== RUN TestPathInfoCACompatibility/new_structured_format_-_text216=== PAUSE TestParsePathInfoJSON/whitespace_only217=== RUN TestParsePathInfoJSON/invalid_JSON218=== CONT TestEncodeNixBase32WithRealHash219=== RUN TestUploadMultipart_SupersededByPeer/missing220--- PASS: TestDoServerRequestAttachesToken (0.01s)221=== PAUSE TestUploadMultipart_SupersededByPeer/missing222=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths223=== PAUSE TestParsePathInfoJSON/invalid_JSON224=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths225=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text226=== PAUSE TestSetClientTLSErrors/missing_cert_file227=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything228=== CONT TestRateLimiterFeedback/429_enables_limiter229=== RUN TestConvertHashToNix32/already_Nix32_format230=== PAUSE TestConvertHashToNix32/already_Nix32_format231--- PASS: TestScriptTokenEmptyToken (0.01s)232=== RUN TestConvertHashToNix32/invalid_format233=== PAUSE TestConvertHashToNix32/invalid_format234--- PASS: TestStreamPushReportsSignatures (0.00s)235--- PASS: TestShellSplit (0.00s)236--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)237--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)238--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)239--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)240=== CONT TestEncodeNixBase32/test_string_hash241=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon242=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum243=== RUN TestSetClientTLSErrors/missing_key_file244=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error245=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped246=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter247=== CONT TestEncodeNixBase32/empty_input248=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum249=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts250=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon251--- PASS: TestEncodeNixBase32WithRealHash (0.00s)252=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter253=== CONT TestRateLimiterFeedback/503_enables_limiter2542026/10/06 21:24:02 WARN Rate limiter enabled after throttle name=server-test rate=52552026/10/06 21:24:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:374432562026/10/06 21:24:02 WARN Rate limiter enabled after throttle name=server-test rate=52572026/10/06 21:24:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:363392582026/10/06 21:24:02 WARN Rate limiter backed off name=server-test rate=52592026/10/06 21:24:02 WARN Rate limiter backed off name=server-test rate=5260=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped261=== RUN TestFilterOversizedClosures/all_closures_skipped262=== PAUSE TestFilterOversizedClosures/all_closures_skipped263=== CONT TestUploadMultipart_SupersededByPeer/missing264=== CONT TestParsePathInfoJSON/empty_input2652026/10/06 21:24:02 INFO Garbage collection started266=== CONT TestParsePathInfoJSON/Lix_format267=== CONT TestConvertHashToNix32/SRI_format_to_Nix32268=== CONT TestConvertHashToNix32/invalid_format269=== CONT TestParsePathInfoJSON/invalid_JSON270=== CONT TestConvertHashToNix32/already_Nix32_format271=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error272=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error273=== CONT TestGetStorePathHash/basename_without_hyphen_should_error274=== CONT TestFilterOversizedClosures/no_limit_keeps_everything275=== CONT TestFilterOversizedClosures/all_closures_skipped2762026/10/06 21:24:02 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=50277=== CONT TestGetStorePathHash/valid_store_path278=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2792026/10/06 21:24:02 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=2000280=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method281=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method282=== CONT TestPathInfoCACompatibility/null_ca_field283=== CONT TestPathInfoCACompatibility/new_structured_format_-_text284=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI285=== RUN TestSetClientTLS/rejects_connection_without_client_cert286--- PASS: TestEncodeNixBase32 (0.05s)287 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)288 --- PASS: TestEncodeNixBase32/empty_input (0.00s)289=== CONT TestParsePathInfoJSON/Nix_format290=== CONT TestParsePathInfoJSON/whitespace_only291=== PAUSE TestSetClientTLSErrors/missing_key_file292=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts293=== CONT TestUploadMultipart_SupersededByPeer/exists294=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive295=== RUN TestSetClientTLSErrors/missing_ca_file296=== PAUSE TestSetClientTLSErrors/missing_ca_file297=== RUN TestSetClientTLSErrors/invalid_ca_file298=== PAUSE TestSetClientTLSErrors/invalid_ca_file299=== CONT TestSetClientTLSErrors/missing_cert_file300=== CONT TestSetClientTLSErrors/invalid_ca_file301=== CONT TestSetClientTLSErrors/missing_ca_file302=== CONT TestSetClientTLSErrors/missing_key_file3032026/10/06 21:24:02 INFO Garbage collection started3042026/10/06 21:24:02 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=0305=== CONT TestPathInfoCACompatibility/old_string_format_-_text306=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method307=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI308=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert309=== RUN TestPartSizeForNAR/1_TiB310--- PASS: TestConvertHashToNix32 (0.01s)311 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)312 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)313 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)314=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512315=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512316=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)317=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512318=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI319=== PAUSE TestPartSizeForNAR/1_TiB320=== RUN TestPartSizeForNAR/5_TiB_S3_max_object321=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object322=== RUN TestPartSizeForNAR/capped_at_5_GiB323=== PAUSE TestPartSizeForNAR/capped_at_5_GiB324=== CONT TestPartSizeForNAR/zero_stays_at_minimum325=== CONT TestPartSizeForNAR/1_TiB326=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA327=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA328=== RUN TestSetClientTLS/preserves_debug_logging_transport329=== PAUSE TestSetClientTLS/preserves_debug_logging_transport330=== CONT TestSetClientTLS/rejects_connection_without_client_cert331=== CONT TestSetClientTLS/preserves_debug_logging_transport3322026/10/06 21:24:02 WARN Garbage collection finished on another replica. Its statistics are not available here333=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA334=== CONT TestPartSizeForNAR/capped_at_5_GiB335=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts336=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum337=== CONT TestPartSizeForNAR/small_stays_at_minimum338--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)339 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)340 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.04s)341=== CONT TestPartSizeForNAR/5_TiB_S3_max_object342=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon343--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.05s)344--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.05s)345--- PASS: TestFilterOversizedClosures (0.05s)346 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)347 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)348 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)349--- PASS: TestParsePathInfoJSON (0.01s)350 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)351 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)352 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)353 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)354 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)355--- PASS: TestRateLimiterFeedback (0.00s)356 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.04s)357 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)358 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.04s)359 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.04s)360--- PASS: TestPathInfoCACompatibility (0.06s)361 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)362 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)363 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)364 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)365 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)366--- PASS: TestPathInfoHashCompatibility (0.05s)367 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)368 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)369 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)370 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)371--- PASS: TestGetStorePathHash (0.02s)372 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)373 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)374 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)375 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)376--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)377 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)378 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)379--- PASS: TestPartSizeForNAR (0.05s)380 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)381 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)382 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)383 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)384 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)385 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)386 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)387--- PASS: TestSetClientTLSErrors (0.06s)388 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)391 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)392--- PASS: TestStreamPushRequestLine (0.08s)3932026/10/06 21:24:02 http: TLS handshake error from 127.0.0.1:40112: remote error: tls: bad certificate394--- PASS: TestRegisterUploadedObjectReusesConnections (0.07s)395--- PASS: TestSetClientTLS (0.06s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)399--- PASS: TestDumpPathSingleFile (0.09s)400--- PASS: TestCaseHackSuffix (0.08s)401--- PASS: TestDumpPathWriterError (0.10s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.13s)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/postgres2768105772/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/postgres2768105772/data -l logfile start434435/build/postgres2768105772:5432 - no response4362026-10-06 21:24:04.397 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:24:04.398 UTC [129] LOG: listening on Unix socket "/build/postgres2768105772/.s.PGSQL.5432"4382026-10-06 21:24:04.408 UTC [136] LOG: database system was shut down at 2026-10-06 21:24:04 UTC4392026-10-06 21:24:04.411 UTC [129] LOG: database system is ready to accept connections440/build/postgres2768105772:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestDeleteClosuresRacingPins478=== PAUSE TestDeleteClosuresRacingPins479=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== RUN TestResolveDBConnectionString482=== PAUSE TestResolveDBConnectionString483=== RUN TestConnectWaitsForAPeerMigration484=== PAUSE TestConnectWaitsForAPeerMigration485=== RUN TestLeadElectsOneAndHandsOver486=== PAUSE TestLeadElectsOneAndHandsOver487=== RUN TestLeadIncumbentWinsAfterRestart4882026/10/06 21:24:04 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 21:24:05 INFO lead: released remote=192.0.2.1:12344902026/10/06 21:24:05 INFO lead: acquired remote=192.0.2.1:12344912026/10/06 21:24:06 INFO lead: released remote=192.0.2.1:1234492--- PASS: TestLeadIncumbentWinsAfterRestart (1.84s)493=== RUN TestLeadIncumbentAnnouncesAtOnce494=== PAUSE TestLeadIncumbentAnnouncesAtOnce495=== RUN TestLeadEndsOnShutdown496=== PAUSE TestLeadEndsOnShutdown497=== RUN TestLeadEndsWhenItsConnectionHangs4982026/10/06 21:24:06 INFO lead: acquired remote=192.0.2.1:12344992026-10-06 21:24:08.061 UTC [574] FATAL: terminating connection due to administrator command5002026/10/06 21:24:08 INFO lead: acquired remote=192.0.2.1:12345012026/10/06 21:24:09 WARN lead: lock connection lost error="timeout: context deadline exceeded"5022026/10/06 21:24:09 INFO lead: released remote=192.0.2.1:12345032026/10/06 21:24:09 INFO lead: released remote=192.0.2.1:1234504--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)505=== RUN TestGCAdvisoryLockBlocksConcurrentRun506=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestForceGCDuringPushOffersSweptObject524=== PAUSE TestForceGCDuringPushOffersSweptObject525=== RUN TestFailedS3DeleteKeepsTombstone526=== PAUSE TestFailedS3DeleteKeepsTombstone527=== RUN TestSweepSkipsRowsLockedByPush528=== PAUSE TestSweepSkipsRowsLockedByPush529=== RUN TestRegisterCompletedObjectNeedsPendingRow530=== PAUSE TestRegisterCompletedObjectNeedsPendingRow531=== RUN TestGetExistingObjectsLocksRows532=== PAUSE TestGetExistingObjectsLocksRows533=== RUN TestSweepRechecksPendingAfterLocking534=== PAUSE TestSweepRechecksPendingAfterLocking535=== RUN TestPushWaitsForSweepHoldingRow536=== PAUSE TestPushWaitsForSweepHoldingRow537=== RUN TestCommitRacingPendingCleanupKeepsObjects538=== PAUSE TestCommitRacingPendingCleanupKeepsObjects539=== RUN TestGCEndsOnShutdown540=== PAUSE TestGCEndsOnShutdown541=== RUN TestGCTaskStore_StartNew542=== PAUSE TestGCTaskStore_StartNew543=== RUN TestGCTaskStore_DeduplicateSameParams544=== PAUSE TestGCTaskStore_DeduplicateSameParams545=== RUN TestGCTaskStore_ConflictDifferentParams546=== PAUSE TestGCTaskStore_ConflictDifferentParams547=== RUN TestGCTaskStore_GetEmpty548=== PAUSE TestGCTaskStore_GetEmpty549=== RUN TestGCTaskStore_GetReturnsLatest550=== PAUSE TestGCTaskStore_GetReturnsLatest551=== RUN TestGCTaskStore_CompletedAllowsNewTask552=== PAUSE TestGCTaskStore_CompletedAllowsNewTask553=== RUN TestGCTaskStore_PhaseUpdates554=== PAUSE TestGCTaskStore_PhaseUpdates555=== RUN TestGCTaskStore_Fail556=== PAUSE TestGCTaskStore_Fail557=== RUN TestGracefulShutdownDrainsInflight558=== PAUSE TestGracefulShutdownDrainsInflight559=== RUN TestService_healthCheckHandler560=== PAUSE TestService_healthCheckHandler561=== RUN TestService_readinessHandler562=== PAUSE TestService_readinessHandler563=== RUN TestGenerateLandingPage564=== PAUSE TestGenerateLandingPage565=== RUN TestCacheConfigHandlerMaxNarSize566=== PAUSE TestCacheConfigHandlerMaxNarSize567=== RUN TestCreatePendingClosureRejectsOversizedNAR568=== PAUSE TestCreatePendingClosureRejectsOversizedNAR569=== RUN TestNARDeduplicationMetadataUploadBug570=== PAUSE TestNARDeduplicationMetadataUploadBug571=== RUN TestMetricsInventory572=== PAUSE TestMetricsInventory573=== RUN TestService_NativeMTLS574=== PAUSE TestService_NativeMTLS575=== RUN TestServerTLSConfig576=== PAUSE TestServerTLSConfig577=== RUN TestMultipartCleanup578=== PAUSE TestMultipartCleanup579=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== RUN TestPendingCleanupUsesOneCutoff582=== PAUSE TestPendingCleanupUsesOneCutoff583=== RUN TestObjectStatsTrigger584=== PAUSE TestObjectStatsTrigger585=== RUN TestOrphanedObjectsGC586=== PAUSE TestOrphanedObjectsGC587=== RUN TestOrphanedObjectsGCStressTest588=== PAUSE TestOrphanedObjectsGCStressTest589=== RUN TestCreatePin_ReservedPins590=== PAUSE TestCreatePin_ReservedPins591=== RUN TestPresentReportsOnlyClosureRoots592=== PAUSE TestPresentReportsOnlyClosureRoots593=== RUN TestPresentRefreshesOnlyStaleClosures594=== PAUSE TestPresentRefreshesOnlyStaleClosures595=== RUN TestPresentNotReportedWhileGCDeletesClosure596=== PAUSE TestPresentNotReportedWhileGCDeletesClosure597=== RUN TestParseSingleRange598=== PAUSE TestParseSingleRange599=== RUN TestProxyHeadersOnlyTrustedOnSocket600=== PAUSE TestProxyHeadersOnlyTrustedOnSocket601=== RUN TestIsValidCachePath602=== PAUSE TestIsValidCachePath603=== RUN TestReadProxyNarinfo604=== PAUSE TestReadProxyNarinfo605=== RUN TestReadProxyNarinfoAlreadyDecompressed606=== PAUSE TestReadProxyNarinfoAlreadyDecompressed607=== RUN TestReadProxyContentNegotiation608=== PAUSE TestReadProxyContentNegotiation609=== RUN TestReadProxyNarStreaming610=== PAUSE TestReadProxyNarStreaming611=== RUN TestReadProxy404612=== PAUSE TestReadProxy404613=== RUN TestReadProxyInvalidPath614=== PAUSE TestReadProxyInvalidPath615=== RUN TestReadProxyHead616=== PAUSE TestReadProxyHead617=== RUN TestReadProxyOutlastsServerWriteTimeout618=== PAUSE TestReadProxyOutlastsServerWriteTimeout619=== RUN TestReadProxyConditionalGet620=== PAUSE TestReadProxyConditionalGet621=== RUN TestReadProxyRootRedirectsToIndexHTML622=== PAUSE TestReadProxyRootRedirectsToIndexHTML623=== RUN TestReadProxyDisabled624=== PAUSE TestReadProxyDisabled625=== RUN TestReadRedirectNar626=== PAUSE TestReadRedirectNar627=== RUN TestReadRedirectKeepsNarinfoProxied628=== PAUSE TestReadRedirectKeepsNarinfoProxied629=== RUN TestReadProxyRangeRequest630=== PAUSE TestReadProxyRangeRequest631=== RUN TestReadRedirectUsesPublicS3URL632=== PAUSE TestReadRedirectUsesPublicS3URL633=== RUN TestPush_OverlappingRootsStoreOneRowPerKey634=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey635=== RUN TestPush_CompleteCommitsEveryRoot636=== PAUSE TestPush_CompleteCommitsEveryRoot637=== RUN TestPush_RepeatedRootCommitsOnce638=== PAUSE TestPush_RepeatedRootCommitsOnce639=== RUN TestPush_CompleteWaitsForCleanupOfThePush640=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush641=== RUN TestPush_RootsAreLockedInByteOrder642=== PAUSE TestPush_RootsAreLockedInByteOrder643=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit644=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit645=== RUN TestPush_RejectsBadRequests646=== PAUSE TestPush_RejectsBadRequests647=== RUN TestPush_SignsNarinfosOfItsPendingObjects648=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects649=== RUN TestRedundantMultipartUpload650=== PAUSE TestRedundantMultipartUpload651=== RUN TestCompleteMultipartUpload_ErrorButObjectExists652=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists653=== RUN TestCompletedNarNotReofferedAcrossClosures654=== PAUSE TestCompletedNarNotReofferedAcrossClosures655=== RUN TestPresignedUploadRegisteredBeforeCommit656=== PAUSE TestPresignedUploadRegisteredBeforeCommit657=== RUN TestService_Rustfstest658=== PAUSE TestService_Rustfstest659=== RUN TestParseSize660=== PAUSE TestParseSize661=== RUN TestSkippedUploadsHandler662=== PAUSE TestSkippedUploadsHandler663=== RUN TestSystemdListenerNotActivated664--- PASS: TestSystemdListenerNotActivated (0.00s)665=== RUN TestWatchdogBeatsWhenHealthy666--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)667=== RUN TestWatchdogSkipsWhenUnhealthy6682026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6762026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"678--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)679=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle680=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle681=== RUN TestProxyWriteTimeout682=== PAUSE TestProxyWriteTimeout683=== RUN TestPendingClosureWriteTimeout684=== PAUSE TestPendingClosureWriteTimeout685=== RUN TestIsValidUploadKey686=== PAUSE TestIsValidUploadKey687=== RUN TestUploadHandlersRejectInvalidKeys688=== PAUSE TestUploadHandlersRejectInvalidKeys689=== RUN TestUploadHandlersRejectOversizedBody690=== PAUSE TestUploadHandlersRejectOversizedBody691=== RUN TestService_cleanupPendingClosuresHandler692=== PAUSE TestService_cleanupPendingClosuresHandler693=== RUN TestService_createPendingClosureHandler694=== PAUSE TestService_createPendingClosureHandler695=== RUN TestService_verifyS3Integrity696=== PAUSE TestService_verifyS3Integrity697=== RUN TestCompleteMultipartUnregistered698=== PAUSE TestCompleteMultipartUnregistered699=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT700=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT701=== CONT TestService_AuthMiddleware702=== CONT TestMetricsInventory703=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT704=== CONT TestCompleteMultipartUnregistered705=== CONT TestService_verifyS3Integrity706=== CONT TestService_createPendingClosureHandler707=== CONT TestService_cleanupPendingClosuresHandler708=== CONT TestUploadHandlersRejectOversizedBody709=== CONT TestUploadHandlersRejectInvalidKeys710=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info711=== CONT TestIsValidUploadKey712=== RUN TestIsValidUploadKey/narinfo713=== CONT TestPendingClosureWriteTimeout714=== CONT TestProxyWriteTimeout715=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle716=== CONT TestSkippedUploadsHandler717=== CONT TestParseSize718=== CONT TestService_Rustfstest719=== CONT TestPresignedUploadRegisteredBeforeCommit720=== CONT TestCompletedNarNotReofferedAcrossClosures721=== CONT TestCompleteMultipartUpload_ErrorButObjectExists722=== CONT TestRedundantMultipartUpload723--- PASS: TestParseSize (0.00s)724=== CONT TestPush_RejectsBadRequests725=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit7262026/10/06 21:24:09 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000727=== CONT TestPush_RootsAreLockedInByteOrder728=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info729=== PAUSE TestIsValidUploadKey/narinfo730=== RUN TestIsValidUploadKey/nar_zst731=== RUN TestProxyWriteTimeout/narinfo732=== RUN TestPendingClosureWriteTimeout/empty733=== CONT TestPush_SignsNarinfosOfItsPendingObjects734=== CONT TestPush_CompleteWaitsForCleanupOfThePush735=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal736=== PAUSE TestIsValidUploadKey/nar_zst737=== RUN TestIsValidUploadKey/nar_xz738=== PAUSE TestIsValidUploadKey/nar_xz739=== RUN TestIsValidUploadKey/nar_plain740=== PAUSE TestIsValidUploadKey/nar_plain741=== PAUSE TestProxyWriteTimeout/narinfo742=== PAUSE TestPendingClosureWriteTimeout/empty743=== RUN TestPendingClosureWriteTimeout/400_objects744=== PAUSE TestPendingClosureWriteTimeout/400_objects745=== RUN TestPendingClosureWriteTimeout/670k_objects746=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal747=== RUN TestIsValidUploadKey/listing748=== PAUSE TestIsValidUploadKey/listing749=== RUN TestIsValidUploadKey/build_log750=== PAUSE TestIsValidUploadKey/build_log751=== RUN TestProxyWriteTimeout/1_GiB_nar752=== PAUSE TestProxyWriteTimeout/1_GiB_nar753=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key754=== PAUSE TestPendingClosureWriteTimeout/670k_objects755=== RUN TestIsValidUploadKey/build_log_home-manager_file756=== PAUSE TestIsValidUploadKey/build_log_home-manager_file757=== 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=== RUN TestIsValidUploadKey/build_log_equals762=== PAUSE TestIsValidUploadKey/build_log_equals763=== RUN TestIsValidUploadKey/realisation764=== PAUSE TestIsValidUploadKey/realisation765--- PASS: TestSkippedUploadsHandler (0.08s)766=== RUN TestIsValidUploadKey/realisation_plus_in_output767=== PAUSE TestIsValidUploadKey/realisation_plus_in_output768=== RUN TestProxyWriteTimeout/10_GiB_nar769=== PAUSE TestProxyWriteTimeout/10_GiB_nar770=== RUN TestProxyWriteTimeout/unknown_size771=== PAUSE TestProxyWriteTimeout/unknown_size772=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key773=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline774=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline775=== CONT TestPush_OverlappingRootsStoreOneRowPerKey776=== CONT TestPush_RepeatedRootCommitsOnce777=== RUN TestIsValidUploadKey/nix-cache-info778=== PAUSE TestIsValidUploadKey/nix-cache-info779=== RUN TestIsValidUploadKey/index.html780=== PAUSE TestIsValidUploadKey/index.html781=== RUN TestIsValidUploadKey/narinfo_key,_nar_type782=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type783=== RUN TestIsValidUploadKey/nar_key,_narinfo_type784=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type785=== RUN TestIsValidUploadKey/listing_key,_narinfo_type786=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type787=== RUN TestIsValidUploadKey/traversal788=== PAUSE TestIsValidUploadKey/traversal789=== RUN TestIsValidUploadKey/traversal_nar790=== CONT TestPush_CompleteCommitsEveryRoot791=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key792=== PAUSE TestIsValidUploadKey/traversal_nar793=== RUN TestIsValidUploadKey/absolute794=== PAUSE TestIsValidUploadKey/absolute795=== RUN TestIsValidUploadKey/empty_key796=== PAUSE TestIsValidUploadKey/empty_key797=== RUN TestIsValidUploadKey/unknown_type798=== PAUSE TestIsValidUploadKey/unknown_type799=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key800=== CONT TestReadRedirectUsesPublicS3URL801=== CONT TestReadProxyRangeRequest802=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure803=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure804=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart805=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart806=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts807=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts808=== CONT TestReadRedirectKeepsNarinfoProxied8092026/10/06 21:24:10 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"810--- PASS: TestService_AuthMiddleware (0.50s)811=== CONT TestReadRedirectNar812--- PASS: TestMetricsInventory (0.50s)813=== CONT TestReadProxyDisabled8142026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8152026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8162026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8172026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8182026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8192026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8202026/10/06 21:24:10 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8212026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures822--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.60s)823=== CONT TestReadProxyRootRedirectsToIndexHTML8242026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures825--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.64s)826=== CONT TestReadProxyConditionalGet8272026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8282026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8292026/10/06 21:24:10 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst830--- PASS: TestCompleteMultipartUnregistered (0.67s)831=== CONT TestReadProxyOutlastsServerWriteTimeout8322026/10/06 21:24:10 INFO Received cleanup request method=DELETE path=/api/pending_closures8332026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=08342026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8352026/10/06 21:24:10 INFO Received cleanup request method=DELETE path=/api/pending_closures8362026/10/06 21:24:10 INFO Aborted multipart uploads count=1 kept=08372026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8382026/10/06 21:24:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8392026-10-06 21:24:10.620 UTC [651] ERROR: Closure does not exist: id=18402026-10-06 21:24:10.620 UTC [651] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8412026-10-06 21:24:10.620 UTC [651] STATEMENT: -- name: CommitPendingClosure :exec842 SELECT commit_pending_closure($1::bigint)843 844--- PASS: TestService_cleanupPendingClosuresHandler (0.72s)845=== CONT TestReadProxyHead8462026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8472026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete848=== RUN TestPush_RejectsBadRequests/no_roots849=== PAUSE TestPush_RejectsBadRequests/no_roots850=== RUN TestPush_RejectsBadRequests/no_objects851=== PAUSE TestPush_RejectsBadRequests/no_objects852=== RUN TestPush_RejectsBadRequests/bad_root853=== PAUSE TestPush_RejectsBadRequests/bad_root854=== RUN TestPush_RejectsBadRequests/root_not_in_objects855=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects856=== CONT TestReadProxyInvalidPath8572026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes8582026/10/06 21:24:10 INFO Received complete push request method=POST path=/api/pushes/1/complete8592026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8602026/10/06 21:24:10 INFO Completed push id=1861--- PASS: TestPush_RepeatedRootCommitsOnce (0.71s)862=== CONT TestReadProxy4048632026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes8642026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8652026/10/06 21:24:10 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjYwOTgyM2MtZWY2NC00ZmMxLThlMjQtN2UwMWVlYjhhZmZjLjRiY2M4OGJkLWRkZjYtNDA4Zi1iZTZlLWYwOTk0NGE0MzA2ZHgxNzkxMzIxODUwNjkxMDQ1NDg2866--- PASS: TestService_Rustfstest (0.81s)867=== CONT TestReadProxyNarStreaming8682026/10/06 21:24:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjYwOTgyM2MtZWY2NC00ZmMxLThlMjQtN2UwMWVlYjhhZmZjLjRiY2M4OGJkLWRkZjYtNDA4Zi1iZTZlLWYwOTk0NGE0MzA2ZHgxNzkxMzIxODUwNjkxMDQ1NDg2 parts=1869--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.81s)870=== CONT TestReadProxyContentNegotiation8712026-10-06 21:24:10.744 UTC [698] ERROR: could not obtain lock on row in relation "closures"8722026-10-06 21:24:10.744 UTC [698] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8732026-10-06 21:24:10.745 UTC [698] ERROR: could not obtain lock on row in relation "closures"8742026-10-06 21:24:10.745 UTC [698] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8752026-10-06 21:24:10.745 UTC [698] ERROR: could not obtain lock on row in relation "closures"8762026-10-06 21:24:10.745 UTC [698] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8772026-10-06 21:24:10.745 UTC [698] ERROR: could not obtain lock on row in relation "closures"8782026-10-06 21:24:10.745 UTC [698] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8792026-10-06 21:24:10.746 UTC [698] ERROR: could not obtain lock on row in relation "closures"8802026-10-06 21:24:10.746 UTC [698] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT881--- PASS: TestPush_RootsAreLockedInByteOrder (0.84s)882=== CONT TestReadProxyNarinfoAlreadyDecompressed883--- PASS: TestReadProxyRangeRequest (0.77s)884=== CONT TestReadProxyNarinfo8852026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes8862026/10/06 21:24:10 INFO Received complete push request method=POST path=/api/pushes/1/complete8872026/10/06 21:24:10 INFO Completed push id=18882026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes8892026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete890--- PASS: TestReadRedirectUsesPublicS3URL (0.84s)891=== CONT TestIsValidCachePath892=== RUN TestIsValidCachePath/narinfo893=== PAUSE TestIsValidCachePath/narinfo894=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars895=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars896=== RUN TestIsValidCachePath/nar_zst897=== PAUSE TestIsValidCachePath/nar_zst898=== RUN TestIsValidCachePath/nar_xz899=== PAUSE TestIsValidCachePath/nar_xz900=== RUN TestIsValidCachePath/nar_bz2901=== PAUSE TestIsValidCachePath/nar_bz2902=== RUN TestIsValidCachePath/nar_uncompressed903=== PAUSE TestIsValidCachePath/nar_uncompressed904=== RUN TestIsValidCachePath/ls905=== PAUSE TestIsValidCachePath/ls906=== RUN TestIsValidCachePath/log907=== PAUSE TestIsValidCachePath/log908=== RUN TestIsValidCachePath/realisation909=== PAUSE TestIsValidCachePath/realisation910=== RUN TestIsValidCachePath/nix-cache-info911=== PAUSE TestIsValidCachePath/nix-cache-info912=== RUN TestIsValidCachePath/index.html913=== PAUSE TestIsValidCachePath/index.html914=== RUN TestIsValidCachePath/traversal_parent915=== PAUSE TestIsValidCachePath/traversal_parent916=== RUN TestIsValidCachePath/traversal_in_middle917=== PAUSE TestIsValidCachePath/traversal_in_middle918=== RUN TestIsValidCachePath/invalid_char_e919=== PAUSE TestIsValidCachePath/invalid_char_e920=== RUN TestIsValidCachePath/invalid_char_u921=== PAUSE TestIsValidCachePath/invalid_char_u922=== RUN TestIsValidCachePath/random_path923=== PAUSE TestIsValidCachePath/random_path924=== RUN TestIsValidCachePath/empty925=== PAUSE TestIsValidCachePath/empty926=== RUN TestIsValidCachePath/leading_slash927=== PAUSE TestIsValidCachePath/leading_slash928=== RUN TestIsValidCachePath/wrong_extension929=== PAUSE TestIsValidCachePath/wrong_extension930=== RUN TestIsValidCachePath/short_hash931=== PAUSE TestIsValidCachePath/short_hash932=== CONT TestProxyHeadersOnlyTrustedOnSocket9332026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes9342026/10/06 21:24:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjYwOTgyM2MtZWY2NC00ZmMxLThlMjQtN2UwMWVlYjhhZmZjLjNiNGEyMWQwLWI3ZWQtNGU2MC1hZTQ5LTQ1NjVmZTdmNGIyNngxNzkxMzIxODUwNDI5MzEyMDY1 parts=109352026/10/06 21:24:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9362026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9372026/10/06 21:24:10 INFO Signed narinfos id=1 count=19382026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9392026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9402026/10/06 21:24:10 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9412026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9422026/10/06 21:24:10 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9432026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9442026/10/06 21:24:10 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19452026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9462026/10/06 21:24:10 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo947--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.87s)948=== CONT TestParseSingleRange949=== RUN TestParseSingleRange/none950=== PAUSE TestParseSingleRange/none951=== RUN TestParseSingleRange/unknown_unit952=== PAUSE TestParseSingleRange/unknown_unit953=== RUN TestParseSingleRange/multi-range_ignored954=== PAUSE TestParseSingleRange/multi-range_ignored955=== RUN TestParseSingleRange/malformed_no_dash956=== PAUSE TestParseSingleRange/malformed_no_dash957=== RUN TestParseSingleRange/malformed_both_empty958=== PAUSE TestParseSingleRange/malformed_both_empty959=== RUN TestParseSingleRange/malformed_end_before_start960=== PAUSE TestParseSingleRange/malformed_end_before_start961=== RUN TestParseSingleRange/closed962=== PAUSE TestParseSingleRange/closed963=== RUN TestParseSingleRange/open-ended964=== PAUSE TestParseSingleRange/open-ended965=== RUN TestParseSingleRange/end_clamped_to_size966=== PAUSE TestParseSingleRange/end_clamped_to_size967=== RUN TestParseSingleRange/suffix968=== PAUSE TestParseSingleRange/suffix969=== RUN TestParseSingleRange/suffix_exceeds_size970=== PAUSE TestParseSingleRange/suffix_exceeds_size971=== RUN TestParseSingleRange/single_byte972=== PAUSE TestParseSingleRange/single_byte973=== RUN TestParseSingleRange/start_past_EOF974=== PAUSE TestParseSingleRange/start_past_EOF975=== RUN TestParseSingleRange/start_far_past_EOF976=== PAUSE TestParseSingleRange/start_far_past_EOF977=== CONT TestPresentNotReportedWhileGCDeletesClosure978=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh979=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh980=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale981=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale982=== CONT TestPresentRefreshesOnlyStaleClosures9832026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes9842026/10/06 21:24:10 INFO Completed upload id=19852026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures9862026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures9872026/10/06 21:24:10 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9882026/10/06 21:24:10 WARN Found objects in DB but missing from S3, will re-upload count=1989--- PASS: TestService_verifyS3Integrity (0.97s)990=== CONT TestPresentReportsOnlyClosureRoots9912026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9922026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=09932026/10/06 21:24:10 WARN Force mode enabled - objects will be deleted immediately without grace period994--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.90s)995=== CONT TestCreatePin_ReservedPins9962026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes9972026/10/06 21:24:10 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=09982026/10/06 21:24:10 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjYwOTgyM2MtZWY2NC00ZmMxLThlMjQtN2UwMWVlYjhhZmZjLmZhY2FhZWQyLTJiMGUtNGJjYy05MDBlLTEzOTMxODg2NzI4NHgxNzkxMzIxODUwNDU1ODExNzUx parts=109992026/10/06 21:24:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10002026/10/06 21:24:10 INFO Vacuumed table table=pending_closures10012026/10/06 21:24:10 INFO Vacuumed table table=pending_objects10022026/10/06 21:24:10 INFO Completed upload id=110032026/10/06 21:24:10 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010042026/10/06 21:24:10 INFO Vacuumed table table=multipart_uploads10052026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures10062026/10/06 21:24:10 INFO Vacuumed table table=closures10072026/10/06 21:24:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures10082026/10/06 21:24:10 INFO Vacuumed table table=objects10092026/10/06 21:24:10 INFO Received complete push request method=POST path=/api/pushes/1/complete10102026/10/06 21:24:10 INFO Received complete push request method=POST path=/api/pushes/2/complete10112026/10/06 21:24:10 INFO Completed push id=21012--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.01s)1013=== CONT TestOrphanedObjectsGCStressTest10142026/10/06 21:24:10 INFO Completed push id=110152026/10/06 21:24:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41937/oidc1016--- PASS: TestPush_CompleteCommitsEveryRoot (0.94s)1017=== CONT TestOrphanedObjectsGC10182026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=01019--- PASS: TestReadRedirectKeepsNarinfoProxied (0.85s)1020=== CONT TestObjectStatsTrigger10212026/10/06 21:24:10 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=010222026/10/06 21:24:10 INFO Vacuumed table table=pending_closures10232026/10/06 21:24:10 INFO Vacuumed table table=pending_objects10242026/10/06 21:24:10 INFO Vacuumed table table=multipart_uploads10252026/10/06 21:24:10 INFO Vacuumed table table=closures10262026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes10272026/10/06 21:24:10 INFO Vacuumed table table=objects10282026/10/06 21:24:10 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001029--- PASS: TestService_createPendingClosureHandler (1.06s)1030=== CONT TestPendingCleanupUsesOneCutoff10312026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1032--- PASS: TestReadRedirectNar (0.59s)1033=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1034--- PASS: TestReadProxyDisabled (0.60s)1035=== CONT TestService_NativeMTLS10362026/10/06 21:24:11 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjYwOTgyM2MtZWY2NC00ZmMxLThlMjQtN2UwMWVlYjhhZmZjLjY3MzY1ZmMyLTUwYmMtNGRiZC05YzE4LWYyYWQzNjFhYmJjM3gxNzkxMzIxODUwNTAxMTExMzkw parts=1210372026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1038--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.13s)1039=== CONT TestDeduplicatedObjectsRecordedAsPending1040--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.54s)1041=== CONT TestNARDeduplicationMetadataUploadBug1042--- PASS: TestReadProxyConditionalGet (0.57s)1043=== CONT TestCreatePendingClosureRejectsOversizedNAR10442026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1045--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1046=== CONT TestCacheConfigHandlerMaxNarSize1047--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1048=== CONT TestGenerateLandingPage1049--- PASS: TestGenerateLandingPage (0.00s)1050=== CONT TestService_readinessHandler1051--- PASS: TestReadProxyHead (0.52s)1052=== CONT TestService_healthCheckHandler1053--- PASS: TestReadProxyInvalidPath (0.52s)1054=== CONT TestGracefulShutdownDrainsInflight10552026/10/06 21:24:11 INFO Starting HTTP server address=127.0.0.1:4079910562026/10/06 21:24:11 INFO Shutdown signal received, draining in-flight requests timeout=10s10572026/10/06 21:24:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10582026/10/06 21:24:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjYwOTgyM2MtZWY2NC00ZmMxLThlMjQtN2UwMWVlYjhhZmZjLjhhZGZmNmEzLThmM2QtNDUzOS04NGQwLTY2ZWM5MDc1MWRiNXgxNzkxMzIxODUwNjI1NDM1Njc2 parts=1210592026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures10602026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1061--- PASS: TestReadProxy404 (0.53s)1062=== CONT TestGCTaskStore_Fail1063--- PASS: TestGCTaskStore_Fail (0.00s)1064=== CONT TestGCTaskStore_PhaseUpdates1065--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1066=== CONT TestGCTaskStore_CompletedAllowsNewTask1067--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1068=== CONT TestGCTaskStore_GetReturnsLatest1069--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1070=== CONT TestGCTaskStore_GetEmpty1071--- PASS: TestGCTaskStore_GetEmpty (0.00s)1072=== CONT TestGCTaskStore_ConflictDifferentParams1073--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1074=== CONT TestGCTaskStore_DeduplicateSameParams1075--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1076=== CONT TestGCTaskStore_StartNew1077--- PASS: TestGCTaskStore_StartNew (0.00s)1078=== CONT TestGCEndsOnShutdown1079=== RUN TestGCEndsOnShutdown/before_the_run1080=== PAUSE TestGCEndsOnShutdown/before_the_run1081=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1082=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1083=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1084=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1085=== CONT TestCommitRacingPendingCleanupKeepsObjects1086--- PASS: TestReadProxyNarStreaming (0.51s)1087=== CONT TestPushWaitsForSweepHoldingRow1088--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1089=== CONT TestSweepRechecksPendingAfterLocking10902026-10-06 21:24:11.279 UTC [753] ERROR: Push does not exist: id=110912026-10-06 21:24:11.279 UTC [753] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE10922026-10-06 21:24:11.279 UTC [753] STATEMENT: SELECT commit_push($1)1093--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.30s)1094=== CONT TestServerTLSConfig1095=== RUN TestServerTLSConfig/no_client_CA1096=== PAUSE TestServerTLSConfig/no_client_CA1097=== RUN TestServerTLSConfig/missing_CA_file1098=== PAUSE TestServerTLSConfig/missing_CA_file1099=== RUN TestServerTLSConfig/not_a_PEM_file1100=== PAUSE TestServerTLSConfig/not_a_PEM_file1101=== CONT TestGetExistingObjectsLocksRows1102--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.53s)1103=== CONT TestMultipartCleanup1104--- PASS: TestReadProxyContentNegotiation (0.57s)1105=== CONT TestRegisterCompletedObjectNeedsPendingRow11062026/10/06 21:24:11 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2048381447/001/proxy.sock11072026/10/06 21:24:11 INFO Starting HTTP server address=127.0.0.1:4209311082026/10/06 21:24:11 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11092026/10/06 21:24:11 INFO Shutdown signal received, draining in-flight requests timeout=10s1110--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.52s)1111=== CONT TestSweepSkipsRowsLockedByPush1112--- PASS: TestPresentRefreshesOnlyStaleClosures (0.55s)1113=== CONT TestFailedS3DeleteKeepsTombstone11142026/10/06 21:24:11 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1115--- PASS: TestReadProxyNarinfo (0.66s)1116=== CONT TestPinProtectsFromGC1117--- PASS: TestPresentReportsOnlyClosureRoots (0.56s)1118=== CONT TestForceGCDuringPushOffersSweptObject1119=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1120=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1121=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1122=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1123=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11242026/10/06 21:24:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11252026/10/06 21:24:11 WARN Refused reserved pin name=worker-x86_64-linux11262026/10/06 21:24:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11272026/10/06 21:24:11 INFO Received create pin request method=POST path=/api/pins/my-app11282026/10/06 21:24:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1129--- PASS: TestCreatePin_ReservedPins (0.62s)1130=== CONT TestGCSweepDeliversEachKeyOnce11312026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1132--- PASS: TestObjectStatsTrigger (0.66s)1133=== CONT TestPushDedupSurvivesConcurrentGC11342026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures11352026/10/06 21:24:11 INFO Received cleanup request method=DELETE path=/api/pending_closures11362026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1137--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.64s)1138=== CONT TestTombstonedObjectOfferedWithoutWaiting11392026/10/06 21:24:11 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11402026/10/06 21:24:11 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1141--- PASS: TestService_NativeMTLS (0.63s)1142=== CONT TestGCMetrics11432026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1144--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.65s)1145=== CONT TestGCBugBareHashReferences11462026/10/06 21:24:11 WARN readiness check failed error="closed pool"1147--- PASS: TestService_readinessHandler (0.61s)1148=== CONT TestGCSweepSkipsPendingObjects1149=== NAME TestNARDeduplicationMetadataUploadBug1150 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug57707482/001/store/bllqdzw73qz79brj2kgvqwq05ggdnyi7-file1.txt1151--- PASS: TestService_healthCheckHandler (0.61s)1152=== CONT TestGCAdvisoryLockBlocksConcurrentRun11532026/10/06 21:24:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11542026/10/06 21:24:11 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjYwOTgyM2MtZWY2NC00ZmMxLThlMjQtN2UwMWVlYjhhZmZjLmExNDliMzVhLTIyYWMtNDgwNy05ZTMzLWIzMWEzNzQ0Y2U4ZHgxNzkxMzIxODUxMjE0ODYxNDM3 error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11552026/10/06 21:24:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjYwOTgyM2MtZWY2NC00ZmMxLThlMjQtN2UwMWVlYjhhZmZjLjAwNmI5MTRlLWJiNmUtNGZjNy1iODkxLTI3MTE2MzAzZWNiN3gxNzkxMzIxODUxMjA3MTE2NTY0 parts=1211562026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures11572026/10/06 21:24:11 INFO Received cleanup request method=DELETE path=/api/pending_closures11582026/10/06 21:24:11 INFO Aborted multipart uploads count=1 kept=011592026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=01160--- PASS: TestRedundantMultipartUpload (1.93s)1161=== CONT TestResolveDBConnectionString1162=== RUN TestResolveDBConnectionString/flag_wins1163=== PAUSE TestResolveDBConnectionString/flag_wins1164=== RUN TestResolveDBConnectionString/file_when_flag_empty1165=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1166=== RUN TestResolveDBConnectionString/missing_file_is_an_error1167=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1168=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1169=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1170=== RUN TestResolveDBConnectionString/nothing_configured1171=== PAUSE TestResolveDBConnectionString/nothing_configured1172=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11732026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period11742026/10/06 21:24:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011752026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes11762026/10/06 21:24:11 INFO Vacuumed table table=pending_closures11772026/10/06 21:24:11 INFO Vacuumed table table=pending_objects11782026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads11792026/10/06 21:24:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11802026/10/06 21:24:11 INFO Uploading bllqdzw73qz79brj2kgvqwq05ggdnyi7-file1.txt (160B)11812026/10/06 21:24:11 INFO Vacuumed table table=closures11822026/10/06 21:24:11 INFO Vacuumed table table=objects1183--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.63s)1184=== CONT TestLeadEndsOnShutdown11852026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11862026/10/06 21:24:11 WARN Failed to register uploaded object key=bllqdzw73qz79brj2kgvqwq05ggdnyi7.ls error="server returned 404: 404 page not found\n"11872026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11882026/10/06 21:24:11 INFO Signed narinfos id=1 count=111892026/10/06 21:24:11 INFO Uploading 1 narinfos11902026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=011912026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/1/complete11922026/10/06 21:24:11 WARN Failed to register uploaded object key=bllqdzw73qz79brj2kgvqwq05ggdnyi7.narinfo error="server returned 404: 404 page not found\n"1193=== NAME TestOrphanedObjectsGC1194 orphaned_objects_gc_test.go:287: GC Test Summary:1195 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1196 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1197 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1198 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1199 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1200--- PASS: TestOrphanedObjectsGC (0.95s)1201=== CONT TestDeleteClosuresRacingPins12022026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period12032026/10/06 21:24:11 INFO Completed push id=112042026/10/06 21:24:11 INFO Upload complete. (84ms)1205=== NAME TestNARDeduplicationMetadataUploadBug1206 metadata_upload_test.go:54: Retrieved narinfo from S3:1207 StorePath: /build/TestNARDeduplicationMetadataUploadBug57707482/001/store/bllqdzw73qz79brj2kgvqwq05ggdnyi7-file1.txt1208 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1209 Compression: zstd1210 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1211 NarSize: 1601212 References: 1213 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1214 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1215 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1216 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12172026/10/06 21:24:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01218--- PASS: TestGetExistingObjectsLocksRows (0.60s)1219=== CONT TestLeadIncumbentAnnouncesAtOnce12202026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures12212026/10/06 21:24:11 INFO Vacuumed table table=pending_closures12222026/10/06 21:24:11 INFO Vacuumed table table=pending_objects12232026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads12242026/10/06 21:24:11 INFO Vacuumed table table=closures12252026/10/06 21:24:11 INFO Vacuumed table table=objects1226--- PASS: TestSweepRechecksPendingAfterLocking (0.67s)1227=== CONT TestClientFallsBackToClosures1228=== NAME TestNARDeduplicationMetadataUploadBug1229 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug57707482/001/store/shmyb6alm0vr8fvpbgf0w1dnwz7ibgwz-file2.txt1230--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.62s)1231=== CONT TestClientPushesUseOnePush12322026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures12332026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=012342026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period12352026/10/06 21:24:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012362026/10/06 21:24:11 INFO Vacuumed table table=pending_closures12372026/10/06 21:24:11 INFO Vacuumed table table=pending_objects12382026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads12392026/10/06 21:24:11 INFO Vacuumed table table=closures12402026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes12412026/10/06 21:24:11 INFO Vacuumed table table=objects12422026/10/06 21:24:11 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12432026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=012442026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12452026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period12462026/10/06 21:24:11 INFO Signed narinfos id=2 count=112472026/10/06 21:24:11 WARN Failed to register uploaded object key=shmyb6alm0vr8fvpbgf0w1dnwz7ibgwz.ls error="server returned 404: 404 page not found\n"12482026/10/06 21:24:11 INFO Uploading 1 narinfos12492026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures12502026/10/06 21:24:12 INFO Received complete push request method=POST path=/api/pushes/2/complete12512026/10/06 21:24:12 WARN Failed to register uploaded object key=shmyb6alm0vr8fvpbgf0w1dnwz7ibgwz.narinfo error="server returned 404: 404 page not found\n"12522026/10/06 21:24:12 INFO Completed push id=212532026/10/06 21:24:12 INFO Upload complete. (59ms)1254=== NAME TestNARDeduplicationMetadataUploadBug1255 metadata_upload_test.go:76: Retrieved narinfo from S3:1256 StorePath: /build/TestNARDeduplicationMetadataUploadBug57707482/001/store/shmyb6alm0vr8fvpbgf0w1dnwz7ibgwz-file2.txt1257 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1258 Compression: zstd1259 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1260 NarSize: 1601261 References: 1262 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12632026/10/06 21:24:12 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=012642026/10/06 21:24:12 INFO Vacuumed table table=pending_closures12652026/10/06 21:24:12 INFO Vacuumed table table=pending_objects12662026/10/06 21:24:12 INFO Vacuumed table table=multipart_uploads1267 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1268 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1269 {"version":1,"root":{"type":"regular","size":44}}12702026/10/06 21:24:12 INFO Vacuumed table table=closures12712026/10/06 21:24:12 INFO Vacuumed table table=objects1272--- PASS: TestSweepSkipsRowsLockedByPush (0.68s)1273=== CONT TestLeadElectsOneAndHandsOver12742026/10/06 21:24:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12752026/10/06 21:24:12 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket57/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12762026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=11277--- PASS: TestNARDeduplicationMetadataUploadBug (0.97s)1278=== CONT TestConnectWaitsForAPeerMigration12792026/10/06 21:24:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12802026/10/06 21:24:12 INFO Aborted multipart uploads count=1 kept=01281--- PASS: TestMultipartCleanup (0.74s)1282=== CONT TestCacheStatsHandler12832026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=012842026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period12852026/10/06 21:24:12 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12862026/10/06 21:24:12 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12872026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=01288--- PASS: TestFailedS3DeleteKeepsTombstone (0.68s)1289=== CONT TestClientMultipleUploads12902026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period1291=== NAME TestPinProtectsFromGC1292 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4178443907/001/store/309l2rhka4fncrafg9vwbrglldwisqc3-pinned-file.txt1293 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4178443907/001/store/dsyrk6g1dbvswviz77g89zcmflw1z39c-unpinned-file.txt12942026/10/06 21:24:12 INFO Received uploads request method=POST path=/api/pending_closures12952026/10/06 21:24:12 INFO Received uploads request method=POST path=/api/pending_closures12962026/10/06 21:24:12 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=012972026/10/06 21:24:12 INFO Vacuumed table table=pending_closures12982026/10/06 21:24:12 INFO Vacuumed table table=pending_objects12992026/10/06 21:24:12 INFO Vacuumed table table=multipart_uploads13002026/10/06 21:24:12 INFO Vacuumed table table=closures13012026/10/06 21:24:12 INFO Vacuumed table table=objects1302--- PASS: TestGCSweepDeliversEachKeyOnce (0.62s)1303=== CONT TestClientIntegration1304--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.49s)1305=== CONT TestClientSharedPathCommittedMidPush13062026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=013072026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period13082026/10/06 21:24:12 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=013092026/10/06 21:24:12 INFO Vacuumed table table=pending_closures13102026/10/06 21:24:12 INFO Vacuumed table table=pending_objects13112026/10/06 21:24:12 INFO Vacuumed table table=multipart_uploads13122026/10/06 21:24:12 INFO Vacuumed table table=closures13132026/10/06 21:24:12 INFO Vacuumed table table=objects1314--- PASS: TestGCMetrics (0.51s)1315=== CONT TestClientErrorHandling1316=== RUN TestClientErrorHandling/InvalidStorePath1317=== PAUSE TestClientErrorHandling/InvalidStorePath1318=== RUN TestClientErrorHandling/InvalidAuthToken1319=== PAUSE TestClientErrorHandling/InvalidAuthToken1320=== RUN TestClientErrorHandling/ServerNotAvailable1321=== PAUSE TestClientErrorHandling/ServerNotAvailable1322=== CONT TestClientCADerivations13232026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes13242026/10/06 21:24:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13252026/10/06 21:24:12 INFO Uploading 309l2rhka4fncrafg9vwbrglldwisqc3-pinned-file.txt (128B)13262026/10/06 21:24:12 INFO Received uploads request method=POST path=/api/pending_closures13272026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=013282026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13292026/10/06 21:24:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13302026/10/06 21:24:12 WARN Failed to register uploaded object key=309l2rhka4fncrafg9vwbrglldwisqc3.ls error="server returned 404: 404 page not found\n"13312026/10/06 21:24:12 INFO Signed narinfos id=1 count=113322026/10/06 21:24:12 INFO Uploading 1 narinfos13332026/10/06 21:24:12 INFO Received complete push request method=POST path=/api/pushes/1/complete13342026/10/06 21:24:12 WARN Failed to register uploaded object key=309l2rhka4fncrafg9vwbrglldwisqc3.narinfo error="server returned 404: 404 page not found\n"13352026/10/06 21:24:12 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=013362026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=013372026/10/06 21:24:12 INFO Vacuumed table table=pending_closures13382026/10/06 21:24:12 INFO Completed push id=113392026/10/06 21:24:12 INFO Upload complete. (74ms)13402026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period13412026/10/06 21:24:12 INFO Vacuumed table table=pending_objects13422026/10/06 21:24:12 INFO Vacuumed table table=multipart_uploads13432026/10/06 21:24:12 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=013442026/10/06 21:24:12 INFO Vacuumed table table=closures1345--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.78s)13462026/10/06 21:24:12 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"1347=== CONT TestClientWithDependencies1348--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.46s)1349=== CONT TestService_AuthMiddleware_OIDC13502026/10/06 21:24:12 INFO Vacuumed table table=objects13512026/10/06 21:24:12 INFO Vacuumed table table=pending_closures13522026/10/06 21:24:12 INFO Vacuumed table table=pending_objects13532026/10/06 21:24:12 INFO Vacuumed table table=multipart_uploads13542026/10/06 21:24:12 INFO Vacuumed table table=closures13552026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=013562026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period13572026/10/06 21:24:12 INFO Vacuumed table table=objects13582026/10/06 21:24:12 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=013592026/10/06 21:24:12 INFO Vacuumed table table=pending_closures13602026/10/06 21:24:12 INFO Vacuumed table table=pending_objects13612026/10/06 21:24:12 INFO Vacuumed table table=multipart_uploads13622026/10/06 21:24:12 INFO Vacuumed table table=closures13632026/10/06 21:24:12 INFO Vacuumed table table=objects1364--- PASS: TestPushDedupSurvivesConcurrentGC (0.64s)1365=== CONT TestCacheConfigHandler1366=== RUN TestCacheConfigHandler/full_config,_no_issuer1367=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1368=== RUN TestCacheConfigHandler/no_cache_url_configured1369=== PAUSE TestCacheConfigHandler/no_cache_url_configured1370=== RUN TestCacheConfigHandler/no_signing_keys1371=== PAUSE TestCacheConfigHandler/no_signing_keys1372=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1373=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1374=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1375--- PASS: TestGCSweepSkipsPendingObjects (0.51s)1376=== CONT TestService_ReadScope_PublicByDefault13772026/10/06 21:24:12 INFO lead: acquired remote=192.0.2.1:123413782026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes13792026/10/06 21:24:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42063/oidc13802026/10/06 21:24:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13812026/10/06 21:24:12 INFO Uploading dsyrk6g1dbvswviz77g89zcmflw1z39c-unpinned-file.txt (128B)13822026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13832026/10/06 21:24:12 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13842026/10/06 21:24:12 INFO Signed narinfos id=2 count=113852026/10/06 21:24:12 WARN Failed to register uploaded object key=dsyrk6g1dbvswviz77g89zcmflw1z39c.ls error="server returned 404: 404 page not found\n"13862026/10/06 21:24:12 INFO Uploading 1 narinfos13872026/10/06 21:24:12 INFO Received complete push request method=POST path=/api/pushes/2/complete13882026/10/06 21:24:12 WARN Failed to register uploaded object key=dsyrk6g1dbvswviz77g89zcmflw1z39c.narinfo error="server returned 404: 404 page not found\n"13892026/10/06 21:24:12 INFO Completed push id=213902026/10/06 21:24:12 INFO Upload complete. (55ms)13912026/10/06 21:24:12 INFO lead: acquired remote=192.0.2.1:123413922026/10/06 21:24:12 INFO lead: released remote=192.0.2.1:12341393--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.43s)1394=== CONT TestService_ReadAuthMiddleware1395--- PASS: TestPushWaitsForSweepHoldingRow (1.09s)1396=== CONT TestService_RequireScope_OIDC13972026/10/06 21:24:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures13982026/10/06 21:24:12 INFO Garbage collection started13992026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=014002026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period14012026/10/06 21:24:12 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=014022026/10/06 21:24:12 INFO Vacuumed table table=pending_closures14032026/10/06 21:24:12 INFO Vacuumed table table=pending_objects14042026/10/06 21:24:12 INFO Vacuumed table table=multipart_uploads14052026/10/06 21:24:12 INFO Vacuumed table table=closures14062026/10/06 21:24:12 INFO Vacuumed table table=objects1407--- PASS: TestGCBugBareHashReferences (0.71s)1408=== CONT TestService_AuthMiddleware_MTLSProxyHeader14092026/10/06 21:24:12 INFO lead: acquired remote=192.0.2.1:123414102026/10/06 21:24:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42117/oidc1411--- PASS: TestCacheStatsHandler (0.42s)1412=== CONT TestProxyWriteTimeout/narinfo1413=== CONT TestProxyWriteTimeout/10_GiB_nar1414=== CONT TestProxyWriteTimeout/1_GiB_nar1415=== CONT TestProxyWriteTimeout/unknown_size1416--- PASS: TestProxyWriteTimeout (0.08s)1417 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1418 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1419 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1420 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1421=== CONT TestPendingClosureWriteTimeout/empty1422=== CONT TestPendingClosureWriteTimeout/400_objects1423=== CONT TestPendingClosureWriteTimeout/670k_objects1424=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1425=== NAME TestClientMultipleUploads1426 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1271423405/001/store/9jv6j704hiha4i418ff8xqvrir47a0yy-test-file-0.txt1427=== NAME TestClientIntegration1428 client_integration_test.go:286: Created store path: /build/TestClientIntegration3813182325/002/store/0rv0rd0qcs1rlwgdz3xh8s5ihvg4aapb-test-file.txt14292026/10/06 21:24:12 INFO Received uploads request method=POST path=/api/pending_closures1430=== NAME TestClientMultipleUploads1431 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1271423405/001/store/zqnm3y7g6d82lk92f6sj3vmz8yjm2n77-test-file-1.txt14322026/10/06 21:24:12 INFO Received uploads request method=POST path=/api/pending_closures14332026/10/06 21:24:12 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14342026/10/06 21:24:12 INFO Uploading 4srlxvx1xs0aaxcpkfarglhnvgvrhvsn-shared-dep (136B)14352026/10/06 21:24:12 INFO Uploading 30sgzck0irw0gd4jvyyvqdacxfp8n2in-a (216B)14362026/10/06 21:24:12 WARN Failed to register uploaded object key=fzgkw7hz0b1dj602kwbfv8lb1cx8905p.ls error="server returned 404: 404 page not found\n"1437--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.73s)1438=== CONT TestIsValidUploadKey/narinfo1439=== CONT TestIsValidUploadKey/realisation1440=== CONT TestIsValidUploadKey/build_log_equals1441=== CONT TestIsValidUploadKey/build_log_question_mark1442=== CONT TestIsValidUploadKey/build_log_plus_in_name1443=== CONT TestIsValidUploadKey/build_log_home-manager_file1444=== CONT TestIsValidUploadKey/build_log1445=== CONT TestIsValidUploadKey/listing1446=== CONT TestIsValidUploadKey/nar_plain1447=== CONT TestIsValidUploadKey/nar_xz1448=== CONT TestIsValidUploadKey/nar_zst1449=== CONT TestIsValidUploadKey/traversal1450=== CONT TestIsValidUploadKey/unknown_type1451=== CONT TestIsValidUploadKey/empty_key1452=== CONT TestIsValidUploadKey/absolute1453=== CONT TestIsValidUploadKey/traversal_nar1454=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1455=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1456=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1457=== CONT TestIsValidUploadKey/index.html1458=== CONT TestIsValidUploadKey/nix-cache-info1459=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14602026/10/06 21:24:12 INFO Received uploads request method=POST path=/1461=== CONT TestIsValidUploadKey/realisation_plus_in_output1462--- PASS: TestIsValidUploadKey (0.08s)1463 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1464 --- PASS: TestIsValidUploadKey/realisation (0.00s)1465 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1466 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1467 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1468 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1469 --- PASS: TestIsValidUploadKey/build_log (0.00s)1470 --- PASS: TestIsValidUploadKey/listing (0.00s)1471 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1472 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1473 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1474 --- PASS: TestIsValidUploadKey/traversal (0.00s)1475 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1476 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1477 --- PASS: TestIsValidUploadKey/absolute (0.00s)1478 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1479 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1480 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1481 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1482 --- PASS: TestIsValidUploadKey/index.html (0.00s)1483 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1484 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1485=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14862026/10/06 21:24:12 INFO Received request for more parts method=POST path=/1487=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14882026/10/06 21:24:12 INFO Received complete multipart upload request method=POST path=/1489=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14902026/10/06 21:24:12 INFO Received uploads request method=POST path=/1491--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1492 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1493 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1494 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1495 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1496=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14972026/10/06 21:24:12 INFO Received uploads request method=POST path=/14982026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14992026/10/06 21:24:12 WARN Failed to register uploaded object key=4srlxvx1xs0aaxcpkfarglhnvgvrhvsn.ls error="server returned 404: 404 page not found\n"15002026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/1krrwj3dgzwaj74h45ibs4fphl16jnzm034wfpp7c4jnnmx0c5x0.nar.zst error="server returned 404: 404 page not found\n"15012026/10/06 21:24:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15022026/10/06 21:24:12 WARN Failed to register uploaded object key=30sgzck0irw0gd4jvyyvqdacxfp8n2in.ls error="server returned 404: 404 page not found\n"15032026/10/06 21:24:12 INFO Signed narinfos id=1 count=215042026/10/06 21:24:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15052026/10/06 21:24:12 INFO Signed narinfos id=2 count=215062026/10/06 21:24:12 INFO Uploading 4 narinfos15072026/10/06 21:24:12 WARN Failed to register uploaded object key=fzgkw7hz0b1dj602kwbfv8lb1cx8905p.narinfo error="server returned 404: 404 page not found\n"15082026/10/06 21:24:12 WARN Failed to register uploaded object key=4srlxvx1xs0aaxcpkfarglhnvgvrhvsn.narinfo error="server returned 404: 404 page not found\n"15092026/10/06 21:24:12 WARN Failed to register uploaded object key=30sgzck0irw0gd4jvyyvqdacxfp8n2in.narinfo error="server returned 404: 404 page not found\n"15102026/10/06 21:24:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15112026/10/06 21:24:12 WARN Failed to register uploaded object key=4srlxvx1xs0aaxcpkfarglhnvgvrhvsn.narinfo error="server returned 404: 404 page not found\n"15122026/10/06 21:24:12 INFO Completed upload id=115132026/10/06 21:24:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15142026/10/06 21:24:12 INFO Completed upload id=215152026/10/06 21:24:12 INFO Upload complete. (78ms)15162026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes1517=== NAME TestClientMultipleUploads1518 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1271423405/001/store/i549cicyvbd6li8zp5lqwa6ynbyyp30m-test-file-2.txt1519=== NAME TestClientFallsBackToClosures1520 client_pushes_test.go:112: Retrieved narinfo from S3:1521 StorePath: /build/TestClientFallsBackToClosures1377102673/001/store/4srlxvx1xs0aaxcpkfarglhnvgvrhvsn-shared-dep1522 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1523 Compression: zstd1524 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821525 NarSize: 1361526 References: 1527 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1528 client_pushes_test.go:112: Retrieved narinfo from S3:1529 StorePath: /build/TestClientFallsBackToClosures1377102673/001/store/30sgzck0irw0gd4jvyyvqdacxfp8n2in-a1530 URL: nar/1krrwj3dgzwaj74h45ibs4fphl16jnzm034wfpp7c4jnnmx0c5x0.nar.zst1531 Compression: zstd1532 NarHash: sha256:1krrwj3dgzwaj74h45ibs4fphl16jnzm034wfpp7c4jnnmx0c5x01533 NarSize: 2161534 References: /build/TestClientFallsBackToClosures1377102673/001/store/4srlxvx1xs0aaxcpkfarglhnvgvrhvsn-shared-dep1535 CA: text:sha256:1z2lcwhfrwndl7qsxd6whdxj0443p8hafvdnk6vg7f7d5ya8q3sr15362026/10/06 21:24:12 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15372026/10/06 21:24:12 INFO Uploading rw2zqbrkfb6pwnn6rc6s59p03wnlx2d2-shared-dep (136B)15382026/10/06 21:24:12 INFO Uploading phrwmv9c9yzxycqnjsd22zl4nd6zzg27-b (208B)1539 client_pushes_test.go:112: Retrieved narinfo from S3:1540 StorePath: /build/TestClientFallsBackToClosures1377102673/001/store/fzgkw7hz0b1dj602kwbfv8lb1cx8905p-b1541 URL: nar/1krrwj3dgzwaj74h45ibs4fphl16jnzm034wfpp7c4jnnmx0c5x0.nar.zst1542 Compression: zstd1543 NarHash: sha256:1krrwj3dgzwaj74h45ibs4fphl16jnzm034wfpp7c4jnnmx0c5x01544 NarSize: 2161545 References: /build/TestClientFallsBackToClosures1377102673/001/store/4srlxvx1xs0aaxcpkfarglhnvgvrhvsn-shared-dep1546 CA: text:sha256:1z2lcwhfrwndl7qsxd6whdxj0443p8hafvdnk6vg7f7d5ya8q3sr15472026/10/06 21:24:12 WARN Failed to register uploaded object key=dqc5i0fggfp851is3fhsfvk8jpy4zc5x.ls error="server returned 404: 404 page not found\n"15482026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15492026/10/06 21:24:12 WARN Failed to register uploaded object key=rw2zqbrkfb6pwnn6rc6s59p03wnlx2d2.ls error="server returned 404: 404 page not found\n"15502026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/0waf9iz4s5sq5dg7lwhpdwwk8l4hcqgwgjnis675439qd2k7r884.nar.zst error="server returned 404: 404 page not found\n"15512026/10/06 21:24:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15522026/10/06 21:24:12 WARN Failed to register uploaded object key=phrwmv9c9yzxycqnjsd22zl4nd6zzg27.ls error="server returned 404: 404 page not found\n"15532026/10/06 21:24:12 INFO Signed narinfos id=1 count=315542026/10/06 21:24:12 INFO Uploading 3 narinfos15552026/10/06 21:24:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15562026/10/06 21:24:12 WARN mTLS auth: bound subjects configured but subject DN unavailable15572026/10/06 21:24:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1558--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.38s)1559=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15602026/10/06 21:24:12 INFO Received complete multipart upload request method=POST path=/1561--- PASS: TestClientFallsBackToClosures (0.70s)1562=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15632026/10/06 21:24:12 INFO Received request for more parts method=POST path=/15642026/10/06 21:24:12 WARN Failed to register uploaded object key=rw2zqbrkfb6pwnn6rc6s59p03wnlx2d2.narinfo error="server returned 404: 404 page not found\n"15652026/10/06 21:24:12 WARN Failed to register uploaded object key=dqc5i0fggfp851is3fhsfvk8jpy4zc5x.narinfo error="server returned 404: 404 page not found\n"15662026/10/06 21:24:12 INFO Received complete push request method=POST path=/api/pushes/1/complete15672026/10/06 21:24:12 WARN Failed to register uploaded object key=phrwmv9c9yzxycqnjsd22zl4nd6zzg27.narinfo error="server returned 404: 404 page not found\n"15682026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes15692026/10/06 21:24:12 INFO Completed push id=115702026/10/06 21:24:12 INFO Upload complete. (74ms)1571=== NAME TestClientPushesUseOnePush1572 client_pushes_test.go:97: Retrieved narinfo from S3:1573 StorePath: /build/TestClientPushesUseOnePush85452116/001/store/rw2zqbrkfb6pwnn6rc6s59p03wnlx2d2-shared-dep1574 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1575 Compression: zstd1576 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821577 NarSize: 1361578 References: 1579 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15802026/10/06 21:24:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15812026/10/06 21:24:12 INFO Uploading 0rv0rd0qcs1rlwgdz3xh8s5ihvg4aapb-test-file.txt (152B)1582 client_pushes_test.go:97: Retrieved narinfo from S3:1583 StorePath: /build/TestClientPushesUseOnePush85452116/001/store/dqc5i0fggfp851is3fhsfvk8jpy4zc5x-a1584 URL: nar/0waf9iz4s5sq5dg7lwhpdwwk8l4hcqgwgjnis675439qd2k7r884.nar.zst1585 Compression: zstd1586 NarHash: sha256:0waf9iz4s5sq5dg7lwhpdwwk8l4hcqgwgjnis675439qd2k7r8841587 NarSize: 2081588 References: /build/TestClientPushesUseOnePush85452116/001/store/rw2zqbrkfb6pwnn6rc6s59p03wnlx2d2-shared-dep1589 CA: text:sha256:13m769mklw8s8sm238n0jn1b1dm3mm7r2qayg06s1fbbx6g6ks431590 client_pushes_test.go:97: Retrieved narinfo from S3:1591 StorePath: /build/TestClientPushesUseOnePush85452116/001/store/phrwmv9c9yzxycqnjsd22zl4nd6zzg27-b1592 URL: nar/0waf9iz4s5sq5dg7lwhpdwwk8l4hcqgwgjnis675439qd2k7r884.nar.zst1593 Compression: zstd1594 NarHash: sha256:0waf9iz4s5sq5dg7lwhpdwwk8l4hcqgwgjnis675439qd2k7r8841595 NarSize: 2081596 References: /build/TestClientPushesUseOnePush85452116/001/store/rw2zqbrkfb6pwnn6rc6s59p03wnlx2d2-shared-dep1597 CA: text:sha256:13m769mklw8s8sm238n0jn1b1dm3mm7r2qayg06s1fbbx6g6ks4315982026/10/06 21:24:12 WARN Failed to register uploaded object key=0rv0rd0qcs1rlwgdz3xh8s5ihvg4aapb.ls error="server returned 404: 404 page not found\n"15992026/10/06 21:24:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16002026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1601--- PASS: TestService_ReadScope_PublicByDefault (0.40s)16022026/10/06 21:24:12 INFO Signed narinfos id=1 count=11603=== CONT TestPush_RejectsBadRequests/no_roots16042026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes1605=== CONT TestPush_RejectsBadRequests/bad_root16062026/10/06 21:24:12 INFO Uploading 1 narinfos16072026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes1608=== CONT TestPush_RejectsBadRequests/no_objects16092026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes1610=== CONT TestPush_RejectsBadRequests/root_not_in_objects16112026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes1612=== CONT TestIsValidCachePath/narinfo1613=== CONT TestIsValidCachePath/index.html1614--- PASS: TestPush_RejectsBadRequests (0.74s)1615 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1616 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1617 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1618 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1619=== CONT TestIsValidCachePath/short_hash1620=== CONT TestIsValidCachePath/wrong_extension1621=== CONT TestIsValidCachePath/leading_slash1622=== CONT TestIsValidCachePath/empty1623=== CONT TestIsValidCachePath/random_path1624=== CONT TestIsValidCachePath/invalid_char_u1625=== CONT TestIsValidCachePath/invalid_char_e1626=== CONT TestIsValidCachePath/traversal_in_middle1627=== CONT TestIsValidCachePath/traversal_parent1628=== CONT TestIsValidCachePath/nar_xz1629=== CONT TestIsValidCachePath/nar_uncompressed1630=== CONT TestIsValidCachePath/nar_bz21631=== CONT TestIsValidCachePath/nix-cache-info1632=== CONT TestIsValidCachePath/nar_zst1633=== CONT TestIsValidCachePath/realisation1634=== CONT TestIsValidCachePath/log1635=== CONT TestIsValidCachePath/ls1636=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1637--- PASS: TestIsValidCachePath (0.00s)1638 --- PASS: TestIsValidCachePath/narinfo (0.00s)1639 --- PASS: TestIsValidCachePath/index.html (0.00s)1640 --- PASS: TestIsValidCachePath/short_hash (0.00s)1641 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1642 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1643 --- PASS: TestIsValidCachePath/empty (0.00s)1644 --- PASS: TestIsValidCachePath/random_path (0.00s)1645 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1646 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1647 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1648 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1649 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1650 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1651 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1652 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1653 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1654 --- PASS: TestIsValidCachePath/realisation (0.00s)1655 --- PASS: TestIsValidCachePath/log (0.00s)1656 --- PASS: TestIsValidCachePath/ls (0.00s)1657 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1658=== CONT TestParseSingleRange/none1659=== CONT TestParseSingleRange/open-ended1660=== CONT TestParseSingleRange/start_far_past_EOF1661=== CONT TestParseSingleRange/start_past_EOF1662=== CONT TestParseSingleRange/single_byte1663=== CONT TestParseSingleRange/suffix_exceeds_size1664=== CONT TestParseSingleRange/suffix1665=== CONT TestParseSingleRange/end_clamped_to_size1666=== CONT TestParseSingleRange/malformed_both_empty1667=== CONT TestParseSingleRange/closed1668=== CONT TestParseSingleRange/malformed_end_before_start1669=== CONT TestParseSingleRange/malformed_no_dash1670=== CONT TestParseSingleRange/unknown_unit1671=== CONT TestParseSingleRange/multi-range_ignored1672--- PASS: TestParseSingleRange (0.00s)1673 --- PASS: TestParseSingleRange/none (0.00s)1674 --- PASS: TestParseSingleRange/open-ended (0.00s)1675 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1676 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1677 --- PASS: TestParseSingleRange/single_byte (0.00s)1678 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1679 --- PASS: TestParseSingleRange/suffix (0.00s)1680 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1681 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1682 --- PASS: TestParseSingleRange/closed (0.00s)1683 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1684 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1685 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1686 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1687=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1688--- PASS: TestClientPushesUseOnePush (0.71s)1689=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale16902026/10/06 21:24:12 INFO Received complete push request method=POST path=/api/pushes/1/complete16912026/10/06 21:24:12 WARN Failed to register uploaded object key=0rv0rd0qcs1rlwgdz3xh8s5ihvg4aapb.narinfo error="server returned 404: 404 page not found\n"16922026/10/06 21:24:12 INFO Completed push id=116932026/10/06 21:24:12 INFO Upload complete. (61ms)1694=== NAME TestClientCADerivations1695 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1104974025/001/store/wdnlz7m8n6291imjlsbdkv8l9qkas95g-ca-test1696=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1697=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1698=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1699=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1700=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1701=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1702=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1703=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1704=== CONT TestGCEndsOnShutdown/before_the_run1705=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17062026/10/06 21:24:12 INFO All 1 paths already cached1707=== NAME TestClientIntegration1708 client_integration_test.go:312: Retrieved narinfo from S3:1709 StorePath: /build/TestClientIntegration3813182325/002/store/0rv0rd0qcs1rlwgdz3xh8s5ihvg4aapb-test-file.txt1710 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1711 Compression: zstd1712 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11713 NarSize: 1521714 References: 1715 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11716=== NAME TestClientCADerivations1717 client_ca_test.go:139: Found 1 dependencies (including self)1718--- PASS: TestService_ReadAuthMiddleware (0.36s)1719=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17202026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes1721=== NAME TestClientIntegration1722 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1723 client_integration_test.go:313: Decompressed .ls content (64 bytes):1724 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1725 client_integration_test.go:316: Testing garbage collection...17262026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes17272026/10/06 21:24:12 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17282026/10/06 21:24:12 INFO Uploading zqnm3y7g6d82lk92f6sj3vmz8yjm2n77-test-file-1.txt (160B)17292026/10/06 21:24:12 INFO Uploading 9jv6j704hiha4i418ff8xqvrir47a0yy-test-file-0.txt (160B)17302026/10/06 21:24:12 INFO Uploading i549cicyvbd6li8zp5lqwa6ynbyyp30m-test-file-2.txt (160B)17312026/10/06 21:24:12 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17322026/10/06 21:24:12 INFO Uploading c8j6f5l3cl3xn6zzcxvgvd47a4x774ff-shared-dep (136B)17332026/10/06 21:24:12 INFO Uploading 370f4imiwsf1577k7xnjjyxpmipa60pj-top (224B)1734=== NAME TestClientWithDependencies1735 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2651545555/001/store/jvl9ly40b56hbffh8nwh7vg5m4pg5ds7-test-script17362026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17372026/10/06 21:24:12 WARN Failed to register uploaded object key=i549cicyvbd6li8zp5lqwa6ynbyyp30m.ls error="server returned 404: 404 page not found\n"17382026/10/06 21:24:12 WARN Failed to register uploaded object key=zqnm3y7g6d82lk92f6sj3vmz8yjm2n77.ls error="server returned 404: 404 page not found\n"1739=== CONT TestServerTLSConfig/no_client_CA17402026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1741=== CONT TestServerTLSConfig/not_a_PEM_file17422026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17432026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1744=== CONT TestServerTLSConfig/missing_CA_file1745--- PASS: TestServerTLSConfig (0.00s)1746 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1747 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1748 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1749=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17502026/10/06 21:24:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17512026/10/06 21:24:12 WARN Failed to register uploaded object key=9jv6j704hiha4i418ff8xqvrir47a0yy.ls error="server returned 404: 404 page not found\n"17522026/10/06 21:24:12 WARN Failed to register uploaded object key=c8j6f5l3cl3xn6zzcxvgvd47a4x774ff.ls error="server returned 404: 404 page not found\n"17532026/10/06 21:24:12 INFO Signed narinfos id=1 count=317542026/10/06 21:24:12 INFO Uploading 3 narinfos17552026/10/06 21:24:12 WARN Failed to register uploaded object key=370f4imiwsf1577k7xnjjyxpmipa60pj.ls error="server returned 404: 404 page not found\n"17562026/10/06 21:24:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17572026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/1kfh84fkn9gysab3d2l0hyamapzhz78xzj4wsiymc17kc1ji4jql.nar.zst error="server returned 404: 404 page not found\n"17582026/10/06 21:24:12 INFO Signed narinfos id=1 count=217592026/10/06 21:24:12 INFO Uploading 2 narinfos17602026/10/06 21:24:12 WARN Failed to register uploaded object key=9jv6j704hiha4i418ff8xqvrir47a0yy.narinfo error="server returned 404: 404 page not found\n"17612026/10/06 21:24:12 WARN Failed to register uploaded object key=zqnm3y7g6d82lk92f6sj3vmz8yjm2n77.narinfo error="server returned 404: 404 page not found\n"17622026/10/06 21:24:12 INFO Received complete push request method=POST path=/api/pushes/1/complete17632026/10/06 21:24:12 WARN Failed to register uploaded object key=i549cicyvbd6li8zp5lqwa6ynbyyp30m.narinfo error="server returned 404: 404 page not found\n"17642026/10/06 21:24:12 WARN Failed to register uploaded object key=c8j6f5l3cl3xn6zzcxvgvd47a4x774ff.narinfo error="server returned 404: 404 page not found\n"17652026/10/06 21:24:12 INFO Received complete push request method=POST path=/api/pushes/1/complete17662026/10/06 21:24:12 WARN Failed to register uploaded object key=370f4imiwsf1577k7xnjjyxpmipa60pj.narinfo error="server returned 404: 404 page not found\n"17672026/10/06 21:24:12 INFO Completed push id=117682026/10/06 21:24:12 INFO Upload complete. (66ms)1769=== NAME TestClientMultipleUploads1770 client_integration_test.go:369: Uploaded 3 paths in 118.934271ms1771--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.32s)1772=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17732026/10/06 21:24:12 INFO Completed push id=117742026/10/06 21:24:12 INFO Upload complete. (65ms)1775=== NAME TestClientSharedPathCommittedMidPush1776 client_integration_test.go:680: Retrieved narinfo from S3:1777 StorePath: /build/TestClientSharedPathCommittedMidPush4066653156/001/store/c8j6f5l3cl3xn6zzcxvgvd47a4x774ff-shared-dep1778 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1779 Compression: zstd1780 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821781 NarSize: 1361782 References: 1783 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1784 client_integration_test.go:680: Retrieved narinfo from S3:1785 StorePath: /build/TestClientSharedPathCommittedMidPush4066653156/001/store/370f4imiwsf1577k7xnjjyxpmipa60pj-top1786 URL: nar/1kfh84fkn9gysab3d2l0hyamapzhz78xzj4wsiymc17kc1ji4jql.nar.zst1787 Compression: zstd1788 NarHash: sha256:1kfh84fkn9gysab3d2l0hyamapzhz78xzj4wsiymc17kc1ji4jql1789 NarSize: 2241790 References: /build/TestClientSharedPathCommittedMidPush4066653156/001/store/c8j6f5l3cl3xn6zzcxvgvd47a4x774ff-shared-dep1791 CA: text:sha256:1p2z4n5fnfb28gqk2jlhx3ymlbgg7whzpngnzggc50bdms5zlwdp17922026/10/06 21:24:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures17932026/10/06 21:24:12 INFO Garbage collection started1794--- PASS: TestClientMultipleUploads (0.64s)1795=== CONT TestResolveDBConnectionString/flag_wins1796=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1797=== CONT TestResolveDBConnectionString/nothing_configured1798=== CONT TestResolveDBConnectionString/missing_file_is_an_error1799=== CONT TestResolveDBConnectionString/file_when_flag_empty1800=== CONT TestClientErrorHandling/InvalidStorePath1801--- PASS: TestResolveDBConnectionString (0.00s)1802 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1803 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1804 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1805 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1806 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1807=== NAME TestClientWithDependencies1808 client_integration_test.go:615: Found 1 dependencies (including self)1809--- PASS: TestClientSharedPathCommittedMidPush (0.60s)1810=== CONT TestClientErrorHandling/ServerNotAvailable18112026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=018122026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period1813=== RUN TestService_RequireScope_OIDC/builder_may_write1814=== PAUSE TestService_RequireScope_OIDC/builder_may_write1815=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1816=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1817=== RUN TestService_RequireScope_OIDC/ops_may_admin1818=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1819=== RUN TestService_RequireScope_OIDC/ops_may_not_write1820=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1821=== RUN TestService_RequireScope_OIDC/reader_may_not_write1822=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1823=== RUN TestService_RequireScope_OIDC/static_token_may_admin1824=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1825=== RUN TestService_RequireScope_OIDC/static_token_may_write1826=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1827=== RUN TestService_RequireScope_OIDC/reader_may_read1828=== PAUSE TestService_RequireScope_OIDC/reader_may_read1829=== RUN TestService_RequireScope_OIDC/writer_implies_read1830=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1831=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1832=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1833=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1834=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1835=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1836=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1837=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1838=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1839=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1840=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1841=== CONT TestClientErrorHandling/InvalidAuthToken18422026/10/06 21:24:12 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=018432026/10/06 21:24:12 INFO Received uploads request method=POST path=/api/pending_closures18442026/10/06 21:24:12 INFO Vacuumed table table=pending_closures18452026/10/06 21:24:12 INFO Vacuumed table table=pending_objects18462026/10/06 21:24:12 INFO Vacuumed table table=multipart_uploads18472026/10/06 21:24:12 INFO Vacuumed table table=closures18482026/10/06 21:24:12 INFO Vacuumed table table=objects18492026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes18502026/10/06 21:24:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18512026/10/06 21:24:12 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/present18522026/10/06 21:24:12 INFO Uploading wdnlz7m8n6291imjlsbdkv8l9qkas95g-ca-test (144B)18532026/10/06 21:24:12 INFO Received push request method=POST path=/api/pushes18542026/10/06 21:24:12 WARN Failed to register uploaded object key=wdnlz7m8n6291imjlsbdkv8l9qkas95g.ls error="server returned 404: 404 page not found\n"18552026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18562026/10/06 21:24:12 WARN Failed to register uploaded object key=log/4m2frnp09l6557l9c3kbdqvzc8a4ndrn-ca-test.drv error="server returned 404: 404 page not found\n"18572026/10/06 21:24:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18582026/10/06 21:24:12 INFO Signed narinfos id=1 count=118592026/10/06 21:24:12 INFO Uploading 1 narinfos18602026/10/06 21:24:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18612026/10/06 21:24:12 INFO Uploading jvl9ly40b56hbffh8nwh7vg5m4pg5ds7-test-script (136B)18622026/10/06 21:24:12 INFO Received complete push request method=POST path=/api/pushes/1/complete18632026/10/06 21:24:12 WARN Failed to register uploaded object key=wdnlz7m8n6291imjlsbdkv8l9qkas95g.narinfo error="server returned 404: 404 page not found\n"18642026/10/06 21:24:12 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18652026/10/06 21:24:12 WARN Failed to register uploaded object key=jvl9ly40b56hbffh8nwh7vg5m4pg5ds7.ls error="server returned 404: 404 page not found\n"18662026/10/06 21:24:12 WARN Failed to register uploaded object key=log/nsxw9a1gh9n9vkl5hwhywa85z53gs7r7-test-script.drv error="server returned 404: 404 page not found\n"18672026/10/06 21:24:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18682026/10/06 21:24:12 INFO Signed narinfos id=1 count=118692026/10/06 21:24:12 INFO Uploading 1 narinfos18702026/10/06 21:24:12 INFO Received complete push request method=POST path=/api/pushes/1/complete18712026/10/06 21:24:12 WARN Failed to register uploaded object key=jvl9ly40b56hbffh8nwh7vg5m4pg5ds7.narinfo error="server returned 404: 404 page not found\n"18722026/10/06 21:24:12 INFO Completed push id=118732026/10/06 21:24:12 INFO Completed push id=118742026/10/06 21:24:12 INFO Upload complete. (116ms)18752026/10/06 21:24:12 INFO Upload complete. (70ms)1876=== NAME TestClientWithDependencies1877 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2651545555/001/store) requires matching store prefix1878=== NAME TestClientCADerivations1879 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1104974025/001/store/wdnlz7m8n6291imjlsbdkv8l9qkas95g-ca-test1880 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1881 Compression: zstd1882 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1883 NarSize: 1441884 References: 1885 Deriver: /build/TestClientCADerivations1104974025/001/store/4m2frnp09l6557l9c3kbdqvzc8a4ndrn-ca-test.drv1886 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1887 client_ca_test.go:185: Checking for realisation files in S3...1888 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1889 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1890--- PASS: TestClientWithDependencies (0.63s)1891=== CONT TestCacheConfigHandler/full_config,_no_issuer1892=== CONT TestCacheConfigHandler/no_signing_keys1893=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1894=== CONT TestCacheConfigHandler/no_cache_url_configured1895--- PASS: TestCacheConfigHandler (0.00s)1896 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1897 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1898 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1899 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1900=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1901=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19022026/10/06 21:24:12 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]1903=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19042026/10/06 21:24:12 WARN Authentication failed token_preview=eyJhbGciOi...JzEoDObulw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1905=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1906=== CONT TestService_RequireScope_OIDC/builder_may_write1907=== CONT TestService_RequireScope_OIDC/reader_may_read1908--- PASS: TestService_AuthMiddleware_OIDC (0.44s)1909 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1910 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1911 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1912 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1913=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1914=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19152026/10/06 21:24:12 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]1916=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1917=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1918=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1919=== CONT TestService_RequireScope_OIDC/writer_implies_read1920=== CONT TestService_RequireScope_OIDC/reader_may_not_write1921=== CONT TestService_RequireScope_OIDC/static_token_may_write1922=== CONT TestService_RequireScope_OIDC/static_token_may_admin1923=== CONT TestService_RequireScope_OIDC/ops_may_admin1924=== CONT TestService_RequireScope_OIDC/ops_may_not_write1925=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1926--- PASS: TestService_RequireScope_OIDC (0.43s)1927 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1928 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1929 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1930 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1931 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1932 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1933 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1934 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1935 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1936 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1937 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1938 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1939 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1940 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19412026/10/06 21:24:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.082697ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19422026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=019432026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period19442026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=019452026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period19462026/10/06 21:24:12 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:38301/bucket94/?delete=\": context canceled"1947--- PASS: TestGCEndsOnShutdown (0.00s)1948 --- PASS: TestGCEndsOnShutdown/before_the_run (0.22s)1949 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.25s)1950 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.25s)19512026/10/06 21:24:12 INFO Received uploads request method=POST path=/api/pending_closures19522026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=019532026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period1954=== NAME TestClientCADerivations1955 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1956 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1957 error: binary cache 's3://bucket81?endpoint=http://localhost:38301®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1104974025/001/store'1958 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 119592026/10/06 21:24:12 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=019602026/10/06 21:24:12 INFO Vacuumed table table=pending_closures19612026/10/06 21:24:12 INFO Vacuumed table table=pending_objects19622026/10/06 21:24:12 INFO Vacuumed table table=multipart_uploads19632026/10/06 21:24:12 INFO Vacuumed table table=closures1964--- PASS: TestClientCADerivations (0.80s)19652026/10/06 21:24:12 INFO Vacuumed table table=objects19662026/10/06 21:24:12 INFO Received uploads request method=POST path=/api/pending_closures19672026/10/06 21:24:12 INFO Aborted multipart uploads count=0 kept=019682026/10/06 21:24:12 WARN Force mode enabled - objects will be deleted immediately without grace period19692026/10/06 21:24:12 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=019702026/10/06 21:24:12 INFO Vacuumed table table=pending_closures19712026/10/06 21:24:12 INFO Vacuumed table table=pending_objects19722026/10/06 21:24:12 INFO Vacuumed table table=multipart_uploads19732026/10/06 21:24:12 INFO Vacuumed table table=closures19742026/10/06 21:24:12 INFO Vacuumed table table=objects1975--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1976 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.28s)1977 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.30s)1978=== NAME TestOrphanedObjectsGCStressTest1979 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1980 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion19812026/10/06 21:24:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19822026/10/06 21:24:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.545586ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19832026/10/06 21:24:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1984--- PASS: TestDeleteClosuresRacingPins (1.39s)19852026/10/06 21:24:13 INFO lead: released remote=192.0.2.1:12341986--- PASS: TestLeadEndsOnShutdown (1.46s)1987--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)1988 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1989 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.09s)1990 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.77s)1991--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)1992 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.70s)1993 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.72s)1994=== NAME TestOrphanedObjectsGCStressTest1995 orphaned_objects_gc_test.go:503: Stress test completed successfully:1996 orphaned_objects_gc_test.go:504: - Active objects preserved: 201997 orphaned_objects_gc_test.go:505: - Objects deleted: 2101998 orphaned_objects_gc_test.go:506: - Total GC'd: 2101999--- PASS: TestOrphanedObjectsGCStressTest (2.51s)20002026/10/06 21:24:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=879.200147ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2001--- PASS: TestPendingClosureWriteTimeout (0.08s)2002 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2003 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2004 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2005 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.12s)20062026/10/06 21:24:13 INFO lead: released remote=192.0.2.1:123420072026/10/06 21:24:13 INFO lead: acquired remote=192.0.2.1:123420082026/10/06 21:24:13 WARN Rate limiter enabled after throttle name=s3-test rate=520092026/10/06 21:24:13 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2010=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2011 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102012 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002013--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.85s)20142026/10/06 21:24:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020152026/10/06 21:24:14 INFO Received create pin request method=POST path=/api/pins/myapp20162026/10/06 21:24:14 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4178443907/001/store/309l2rhka4fncrafg9vwbrglldwisqc3-pinned-file.txt narinfo_key=309l2rhka4fncrafg9vwbrglldwisqc3.narinfo20172026/10/06 21:24:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures20182026/10/06 21:24:14 INFO Garbage collection started20192026/10/06 21:24:14 INFO Aborted multipart uploads count=0 kept=020202026/10/06 21:24:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.69050977s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20212026/10/06 21:24:14 WARN Force mode enabled - objects will be deleted immediately without grace period20222026/10/06 21:24:14 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=020232026/10/06 21:24:14 INFO Vacuumed table table=pending_closures20242026/10/06 21:24:14 INFO Vacuumed table table=pending_objects20252026/10/06 21:24:14 INFO Vacuumed table table=multipart_uploads20262026/10/06 21:24:14 INFO Vacuumed table table=closures20272026/10/06 21:24:14 INFO Vacuumed table table=objects20282026/10/06 21:24:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02029=== NAME TestClientIntegration2030 client_integration_test.go:323: Objects in database after GC:2031 client_integration_test.go:323: Successfully deleted all objects with GC --force2032--- PASS: TestClientIntegration (2.61s)20332026/10/06 21:24:14 INFO lead: released remote=192.0.2.1:12342034--- PASS: TestLeadElectsOneAndHandsOver (2.75s)2035--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.74s)20362026/10/06 21:24:16 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-config20372026/10/06 21:24:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.644602ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2038=== NAME TestPinProtectsFromGC2039 client_integration_test.go:840: Pin successfully protected closure from garbage collection2040--- PASS: TestPinProtectsFromGC (4.93s)20412026/10/06 21:24:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.752468ms 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:24:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=831.893073ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2043--- PASS: TestConnectWaitsForAPeerMigration (5.18s)20442026/10/06 21:24:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.452264781s 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:24:17 INFO Aborted multipart uploads count=1 kept=020462026/10/06 21:24:17 INFO Received cleanup request method=DELETE path=/api/pending_closures20472026/10/06 21:24:17 INFO Aborted multipart uploads count=1 kept=02048--- PASS: TestPendingCleanupUsesOneCutoff (6.67s)20492026/10/06 21:24:19 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"20502026/10/06 21:24:19 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-config20512026/10/06 21:24:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.158652ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20522026/10/06 21:24:19 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.029895ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20532026/10/06 21:24:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=756.69608ms 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:24:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.589418315s 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:24:22 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_closures20562026/10/06 21:24:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.936581ms 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:24:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=391.61458ms 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:24:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=767.487994ms 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:24:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.659550412s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2060--- PASS: TestClientErrorHandling (0.00s)2061 --- PASS: TestClientErrorHandling/InvalidStorePath (0.26s)2062 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2063 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.54s)2064PASS2065{"timestamp":"2026-10-06T21:24:25.263387978Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:54214","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(391)"}20662026-10-06 21:24:25.659 UTC [129] LOG: received smart shutdown request20672026-10-06 21:24:25.666 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120682026-10-06 21:24:25.674 UTC [134] LOG: shutting down20692026-10-06 21:24:25.675 UTC [134] LOG: checkpoint starting: shutdown immediate20702026-10-06 21:24:27.385 UTC [134] LOG: checkpoint complete: wrote 10802 buffers (65.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.265 s, sync=1.376 s, total=1.711 s; sync files=33373, longest=0.002 s, average=0.001 s; distance=484088 kB, estimate=484088 kB; lsn=0/1F024088, redo lsn=0/1F02408820712026-10-06 21:24:27.474 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--- PASS: TestAudienceForIssuer (0.00s)2112=== CONT TestValidateToken_ValidToken2113=== CONT TestGlobMatch2114=== RUN TestGlobMatch/foo_foo2115=== PAUSE TestGlobMatch/foo_foo2116=== CONT TestPins_ConfigValidation2117=== CONT TestScopes_ConfigValidation2118=== CONT TestScopes_Rules2119=== CONT TestScopes_LegacyProviderDefaultsToWrite2120--- PASS: TestPins_ConfigValidation (0.00s)2121=== CONT TestPins_ReservedForMatchingRule2122=== CONT TestPins_TopLevelShorthand2123--- PASS: TestScopes_ConfigValidation (0.00s)2124=== CONT TestValidateToken_MultipleProviders2125=== CONT TestValidateToken_NoMatchingProvider2126=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2127=== CONT TestValidateToken_Expired2128=== CONT TestValidateToken_BoundSubjectMismatch2129=== CONT TestNewValidator_KubernetesRequiresCA2130=== CONT TestValidateToken_BoundClaimsMismatch2131=== CONT TestValidateToken_WrongAudience2132=== RUN TestGlobMatch/foo_bar2133=== PAUSE TestGlobMatch/foo_bar2134=== 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/?oo_boo2182=== CONT TestGlobMatch/*bar_foo2183=== CONT TestGlobMatch/*bar_bar2184=== CONT TestGlobMatch/refs/*/main_refs/heads/main2185=== CONT TestGlobMatch/foo*_bar2186=== CONT TestGlobMatch/fo?_foo2187=== CONT TestGlobMatch/foo*_foobar2188=== CONT TestGlobMatch/*bar_foobar2189=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2190=== CONT TestGlobMatch/*_anything2191=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2192=== CONT TestGlobMatch/*/*_foo2193=== CONT TestGlobMatch/*/*_foo/bar2194=== CONT TestGlobMatch/foo*bar_foobarbaz2195=== CONT TestGlobMatch/foo*bar_foo123bar2196=== CONT TestGlobMatch/foo*bar_foobar2197=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2198=== CONT TestGlobMatch/foo*_foo2199=== CONT TestGlobMatch/?oo_foo2200=== CONT TestGlobMatch/*_2201=== CONT TestGlobMatch/fo?_fo2202=== CONT TestGlobMatch/foo_bar2203=== CONT TestGlobMatch/fo?_fooo2204=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02205--- PASS: TestGlobMatch (0.01s)2206 --- PASS: TestGlobMatch/foo_foo (0.00s)2207 --- PASS: TestGlobMatch/?oo_boo (0.00s)2208 --- PASS: TestGlobMatch/*bar_foo (0.00s)2209 --- PASS: TestGlobMatch/*bar_bar (0.00s)2210 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2211 --- PASS: TestGlobMatch/foo*_bar (0.00s)2212 --- PASS: TestGlobMatch/fo?_foo (0.00s)2213 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2214 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2215 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2216 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2217 --- PASS: TestGlobMatch/*_anything (0.00s)2218 --- PASS: TestGlobMatch/*/*_foo (0.00s)2219 --- PASS: TestGlobMatch/?oo_foo (0.00s)2220 --- PASS: TestGlobMatch/*_ (0.00s)2221 --- PASS: TestGlobMatch/fo?_fo (0.00s)2222 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2223 --- PASS: TestGlobMatch/foo_bar (0.00s)2224 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2225 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2226 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2227 --- PASS: TestGlobMatch/foo*_foo (0.00s)2228 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2229 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2230 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)22312026/10/06 21:24:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35771/oidc22322026/10/06 21:24:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39711/oidc2233--- PASS: TestPins_TopLevelShorthand (0.02s)2234--- PASS: TestScopes_Rules (0.02s)22352026/10/06 21:24:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38737/oidc22362026/10/06 21:24:30 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:36841/oidc22372026/10/06 21:24:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34179/oidc2238--- PASS: TestValidateToken_WrongAudience (0.02s)2239--- PASS: TestValidateToken_MultipleProviders (0.03s)22402026/10/06 21:24:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39759/oidc2241--- PASS: TestValidateToken_Expired (0.03s)22422026/10/06 21:24:30 http: TLS handshake error from 127.0.0.1:59800: remote error: tls: bad certificate2243--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)22442026/10/06 21:24:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36753/oidc22452026/10/06 21:24:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39699/oidc2246--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)2247--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)22482026/10/06 21:24:30 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322492026/10/06 21:24:30 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4445322502026/10/06 21:24:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38965/oidc2251--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)2252--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)2253--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)22542026/10/06 21:24:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45399/oidc2255--- PASS: TestValidateToken_NoMatchingProvider (0.10s)22562026/10/06 21:24:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36275/oidc2257--- PASS: TestValidateToken_ValidToken (0.11s)22582026/10/06 21:24:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34505/oidc2259--- PASS: TestPins_ReservedForMatchingRule (0.17s)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:24:30 ERROR Failed to queue paths error="permission denied" count=12313=== CONT TestQueueFetchRemoveLifecycle2314=== CONT TestQueueRetryMovesToBack2315=== CONT TestQueueFetchBatchLimit2316=== CONT TestQueueRemove2317=== CONT TestQueueDeduplication2318=== CONT TestWorkerUploadsAndRemoves2319=== CONT TestQueueEnqueueAndFetch2320=== CONT TestDrainGivesUpWhenServerDown2321=== CONT TestWorkerSkipsGCdPaths2322=== CONT TestFailedPathPrunedByLaterClosure2323=== CONT TestRunNotBlockedByPoisonHead2324=== CONT TestDrainTimeout2325=== CONT TestDrainIsolatesPoisonPath2326=== CONT TestWorkerPrunesClosureDeps2327--- PASS: TestServerClientIntegration (0.00s)2328--- PASS: TestServerQueueError (0.00s)23292026/10/06 21:24:30 INFO Upload queue status pending=223302026/10/06 21:24:30 INFO Uploading batch count=423312026/10/06 21:24:30 ERROR Upload failed error="upload failed" count=423322026/10/06 21:24:30 INFO Uploading batch count=223332026/10/06 21:24:30 INFO Uploading batch count=123342026/10/06 21:24:30 ERROR Upload failed error="upload failed" count=12335--- PASS: TestQueueFetchBatchLimit (0.02s)23362026/10/06 21:24:30 INFO Uploading batch count=223372026/10/06 21:24:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1962191187/002/bbb23382026/10/06 21:24:30 INFO Uploading batch count=223392026/10/06 21:24:30 ERROR Upload failed error="upload failed" count=223402026/10/06 21:24:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1099751878/002/a2341--- PASS: TestQueueEnqueueAndFetch (0.02s)23422026/10/06 21:24:30 INFO Upload queue status pending=223432026/10/06 21:24:30 INFO Upload queue status pending=323442026/10/06 21:24:30 INFO Uploading batch count=12345--- PASS: TestQueueRemove (0.02s)23462026/10/06 21:24:30 INFO Upload queue status pending=223472026/10/06 21:24:30 INFO Uploading batch count=123482026/10/06 21:24:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1099751878/002/b23492026/10/06 21:24:30 INFO Uploading batch count=123502026/10/06 21:24:30 ERROR Upload failed error="upload failed" count=123512026/10/06 21:24:30 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3918239102/002/nonexistent23522026/10/06 21:24:30 INFO Uploading batch count=12353--- PASS: TestQueueDeduplication (0.02s)2354--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23552026/10/06 21:24:30 INFO Uploading batch count=22356--- PASS: TestQueueRetryMovesToBack (0.02s)23572026/10/06 21:24:30 ERROR Upload failed error="upload failed" count=223582026/10/06 21:24:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1099751878/002/c23592026/10/06 21:24:30 INFO Uploading batch count=123602026/10/06 21:24:30 INFO Uploading batch count=123612026/10/06 21:24:30 ERROR Upload failed error="upload failed" count=123622026/10/06 21:24:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1099751878/002/d23632026/10/06 21:24:30 INFO Uploading batch count=123642026/10/06 21:24:30 ERROR Upload failed error="upload failed" count=123652026/10/06 21:24:30 INFO Uploading batch count=223662026/10/06 21:24:30 ERROR Upload failed error="upload failed" count=223672026/10/06 21:24:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1099751878/002/e23682026/10/06 21:24:30 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1099751878/002/f2369--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23702026/10/06 21:24:30 INFO Uploading batch count=123712026/10/06 21:24:30 ERROR Upload failed error="upload failed" count=123722026/10/06 21:24:30 ERROR Drain finished with paths left in queue remaining=123732026/10/06 21:24:30 ERROR Drain finished with paths left in queue remaining=102374--- PASS: TestDrainIsolatesPoisonPath (0.02s)2375--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2376--- PASS: TestWorkerUploadsAndRemoves (0.03s)2377--- PASS: TestWorkerPrunesClosureDeps (0.03s)2378--- PASS: TestWorkerSkipsGCdPaths (0.04s)2379--- PASS: TestQueueRemoveLargeClosure (0.08s)23802026/10/06 21:24:30 ERROR Upload failed error="context deadline exceeded" count=223812026/10/06 21:24:30 ERROR Drain finished with paths left in queue remaining=42382--- PASS: TestDrainTimeout (0.22s)2383--- PASS: TestQueueConcurrentWriters (0.38s)23842026/10/06 21:24:31 INFO Uploading batch count=123852026/10/06 21:24:31 INFO Uploading batch count=123862026/10/06 21:24:31 INFO Uploading batch count=123872026/10/06 21:24:31 ERROR Upload failed error="upload failed" count=123882026/10/06 21:24:31 INFO Uploading batch count=123892026/10/06 21:24:31 ERROR Upload failed error="upload failed" count=123902026/10/06 21:24:31 INFO Uploading batch count=123912026/10/06 21:24:31 ERROR Upload failed error="upload failed" count=123922026/10/06 21:24:31 INFO Uploading batch count=123932026/10/06 21:24:31 ERROR Upload failed error="upload failed" count=123942026/10/06 21:24:31 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 TestExternalSignerCancellation2428=== CONT TestSignBatch2429=== CONT TestSignErrors2430=== CONT TestNilKeyPublicKey2431--- PASS: TestNilKeyPublicKey (0.00s)2432=== CONT TestSign2433=== CONT TestExternalSignerProgramErrorKeepsProcess2434=== CONT TestExternalSignerRejectsInvalidPublicKey2435=== CONT TestExternalSignerClose2436=== CONT TestExternalSignerErrors2437=== RUN TestExternalSignerErrors/exit_on_request2438=== CONT TestExternalSignerRestartsAfterCrash2439=== CONT TestGenerateFingerprint2440=== CONT TestParseSigningKey2441=== CONT TestExternalSignerWrongPublicKey2442=== RUN TestExternalSignerRejectsInvalidPublicKey/#002443=== RUN TestParseSigningKey/valid_32-byte_key2444=== PAUSE TestParseSigningKey/valid_32-byte_key2445=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2446=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2447=== RUN TestParseSigningKey/no_colon2448=== PAUSE TestParseSigningKey/no_colon2449=== RUN TestParseSigningKey/empty_name2450=== PAUSE TestParseSigningKey/empty_name2451=== RUN TestParseSigningKey/invalid_base642452=== PAUSE TestParseSigningKey/invalid_base642453=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002454=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2455=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2456=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2457=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2458--- PASS: TestSign (0.00s)2459--- PASS: TestSignBatch (0.00s)2460=== RUN TestSignErrors/nil_key2461=== RUN TestParseSigningKey/wrong_length2462=== PAUSE TestParseSigningKey/wrong_length2463=== CONT TestParseSigningKey/valid_32-byte_key2464=== RUN TestGenerateFingerprint/basic_with_references2465=== CONT TestParseSigningKey/invalid_base642466=== PAUSE TestExternalSignerErrors/exit_on_request2467=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2468=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2469=== PAUSE TestSignErrors/nil_key2470=== RUN TestSignErrors/nil_narinfo2471=== CONT TestParseSigningKey/empty_name2472=== PAUSE TestSignErrors/nil_narinfo2473=== RUN TestSignErrors/invalid_narinfo2474=== PAUSE TestSignErrors/invalid_narinfo2475=== RUN TestSignErrors/canceled2476=== PAUSE TestSignErrors/canceled2477=== CONT TestSignErrors/nil_key2478=== PAUSE TestGenerateFingerprint/basic_with_references2479=== CONT TestSignErrors/canceled2480=== CONT TestParseSigningKey/no_colon2481=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2482=== RUN TestExternalSignerErrors/invalid_JSON2483=== PAUSE TestExternalSignerErrors/invalid_JSON2484=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2485=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2486=== CONT TestParseSigningKey/wrong_length2487=== CONT TestSignErrors/nil_narinfo2488=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2489=== CONT TestSignErrors/invalid_narinfo2490=== RUN TestGenerateFingerprint/no_references2491=== PAUSE TestGenerateFingerprint/no_references2492=== RUN TestExternalSignerErrors/wrong_shape2493=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2494=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2495=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2496=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2497=== RUN TestGenerateFingerprint/invalid_nar_hash_length2498=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2499=== RUN TestGenerateFingerprint/invalid_store_path_prefix2500=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2501=== RUN TestGenerateFingerprint/invalid_reference_prefix2502=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2503=== CONT TestGenerateFingerprint/basic_with_references2504=== PAUSE TestExternalSignerErrors/wrong_shape2505=== RUN TestExternalSignerErrors/null2506=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2507=== PAUSE TestExternalSignerErrors/null2508=== RUN TestExternalSignerErrors/wrong_id2509=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2510=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2511--- PASS: TestParseSigningKey (0.00s)2512 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2513 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2514 --- PASS: TestParseSigningKey/empty_name (0.00s)2515 --- PASS: TestParseSigningKey/no_colon (0.00s)2516 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2517 --- PASS: TestParseSigningKey/wrong_length (0.00s)2518=== CONT TestExternalSignerRejectsInvalidPublicKey/#002519=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2520=== CONT TestGenerateFingerprint/no_references2521--- PASS: TestSignErrors (0.00s)2522 --- PASS: TestSignErrors/nil_key (0.00s)2523 --- PASS: TestSignErrors/canceled (0.00s)2524 --- PASS: TestSignErrors/nil_narinfo (0.00s)2525 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2526=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2527--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2528 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2529 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2530 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2531 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2532 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2533=== CONT TestGenerateFingerprint/invalid_store_path_prefix2534=== CONT TestGenerateFingerprint/invalid_nar_hash_length2535=== CONT TestGenerateFingerprint/invalid_reference_prefix2536--- PASS: TestGenerateFingerprint (0.00s)2537 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2538 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2539 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2540 --- PASS: TestGenerateFingerprint/no_references (0.00s)2541 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2542 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2543 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2544=== PAUSE TestExternalSignerErrors/wrong_id2545=== RUN TestExternalSignerErrors/missing_signatures2546=== PAUSE TestExternalSignerErrors/missing_signatures2547=== RUN TestExternalSignerErrors/unrequested_key2548=== PAUSE TestExternalSignerErrors/unrequested_key2549=== RUN TestExternalSignerErrors/program_error2550=== PAUSE TestExternalSignerErrors/program_error2551=== RUN TestExternalSignerErrors/too_few_signatures2552=== PAUSE TestExternalSignerErrors/too_few_signatures2553=== RUN TestExternalSignerErrors/wrong_signature_name2554=== PAUSE TestExternalSignerErrors/wrong_signature_name2555=== RUN TestExternalSignerErrors/wrong_signatures_shape2556=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2557=== RUN TestExternalSignerErrors/missing_signature_name2558=== PAUSE TestExternalSignerErrors/missing_signature_name2559=== RUN TestExternalSignerErrors/invalid_signature_base642560=== PAUSE TestExternalSignerErrors/invalid_signature_base642561=== RUN TestExternalSignerErrors/exit_at_startup2562=== PAUSE TestExternalSignerErrors/exit_at_startup2563=== RUN TestExternalSignerErrors/null_signatures2564=== PAUSE TestExternalSignerErrors/null_signatures2565=== RUN TestExternalSignerErrors/wrong_signature_length2566=== PAUSE TestExternalSignerErrors/wrong_signature_length2567=== CONT TestExternalSignerErrors/exit_on_request2568=== CONT TestExternalSignerErrors/wrong_signature_name2569=== CONT TestExternalSignerErrors/too_few_signatures2570=== CONT TestExternalSignerErrors/wrong_signature_length2571=== CONT TestExternalSignerErrors/null_signatures2572=== CONT TestExternalSignerErrors/exit_at_startup2573=== CONT TestExternalSignerErrors/wrong_signatures_shape2574=== CONT TestExternalSignerErrors/missing_signature_name2575=== CONT TestExternalSignerErrors/invalid_signature_base642576=== CONT TestExternalSignerErrors/wrong_id2577=== CONT TestExternalSignerErrors/unrequested_key2578=== CONT TestExternalSignerErrors/missing_signatures2579=== CONT TestExternalSignerErrors/wrong_shape2580=== CONT TestExternalSignerErrors/program_error2581=== CONT TestExternalSignerErrors/null2582=== CONT TestExternalSignerErrors/invalid_JSON2583--- PASS: TestExternalSignerWrongPublicKey (0.01s)2584--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2585--- PASS: TestExternalSigner (0.01s)2586--- PASS: TestExternalSignerClose (0.01s)2587--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2588--- PASS: TestExternalSignerErrors (0.00s)2589 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2590 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2591 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2592 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2593 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2594 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2595 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2596 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2597 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2598 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2599 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2600 --- PASS: TestExternalSignerErrors/null (0.01s)2601 --- PASS: TestExternalSignerErrors/program_error (0.01s)2602 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2603 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2604 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (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 TestServe2618=== CONT TestServeRejectsGarbage2619=== CONT TestSignErrors2620=== RUN TestSignErrors/invalid_base642621=== PAUSE TestSignErrors/invalid_base642622--- PASS: TestServeRejectsGarbage (0.00s)2623=== RUN TestSignErrors/http_error2624=== PAUSE TestSignErrors/http_error2625=== RUN TestSignErrors/invalid_json2626=== PAUSE TestSignErrors/invalid_json2627=== RUN TestSignErrors/no_prefix2628--- PASS: TestServe (0.00s)2629=== PAUSE TestSignErrors/no_prefix2630=== CONT TestSignErrors/invalid_base642631=== CONT TestSignErrors/http_error2632=== CONT TestSignErrors/invalid_json2633=== CONT TestSignErrors/no_prefix2634--- PASS: TestSign (0.00s)2635--- PASS: TestSignErrors (0.00s)2636 --- PASS: TestSignErrors/invalid_json (0.00s)2637 --- PASS: TestSignErrors/invalid_base64 (0.00s)2638 --- PASS: TestSignErrors/http_error (0.00s)2639 --- PASS: TestSignErrors/no_prefix (0.00s)2640PASS