niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #361
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestEncodeNixBase32101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102=== CONT TestScriptTokenEmptyCommand103--- PASS: TestScriptTokenEmptyCommand (0.00s)104=== CONT TestStreamPushReportsEveryPath105=== CONT TestScriptTokenScriptFails106=== CONT TestScriptTokenBadJSON107=== CONT TestScriptTokenEmptyToken108=== CONT TestScriptTokenCachesUntilRefresh109=== CONT TestScriptTokenNoExpiryRerunsEveryCall110=== CONT TestFileTokenEmpty111--- PASS: TestStreamPushReportsEveryPath (0.00s)112=== CONT TestFileTokenMissing113=== CONT TestFileTokenReadsAndCaches114=== CONT TestStaticToken115=== CONT TestSetClientTLSErrors116=== CONT TestSetClientTLSDoesNotMutateDefaultTransport117=== CONT TestSetClientTLS118=== CONT TestClientSignaturesByStorePath119=== CONT TestStreamPushReportsSignatures120=== CONT TestStreamPushRequestLine121=== CONT TestStreamPushGivesUpOnDeadServer122=== CONT TestStreamPushIsolatesFailures123=== CONT TestParsePathInfoJSONMultiplePaths124=== CONT TestStreamPushBatchesUnderLoad125=== CONT TestResolveStorePath126=== RUN TestEncodeNixBase32/test_string_hash127--- PASS: TestScriptTokenScriptFails (0.00s)128=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess129=== CONT TestShellSplitErrors130--- PASS: TestShellSplitErrors (0.00s)131=== CONT TestRateLimiterFeedback132=== RUN TestRateLimiterFeedback/429_enables_limiter133=== PAUSE TestRateLimiterFeedback/429_enables_limiter134=== RUN TestRateLimiterFeedback/503_enables_limiter135=== PAUSE TestRateLimiterFeedback/503_enables_limiter136=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter137=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter138=== CONT TestShellSplit1392026/10/06 07:35:26 WARN Rate limiter enabled after throttle name=server-test rate=5140=== CONT TestPathInfoCACompatibility141=== RUN TestPathInfoCACompatibility/null_ca_field142=== PAUSE TestPathInfoCACompatibility/null_ca_field1432026/10/06 07:35:26 ERROR Upload failed error=boom count=1144=== RUN TestPathInfoCACompatibility/old_string_format_-_text145=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text146=== CONT TestDumpPathMatchesNix147=== CONT TestUploadMultipart_PartsInParallel148=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter149=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter150--- PASS: TestFileTokenEmpty (0.00s)151--- PASS: TestStaticToken (0.00s)152--- PASS: TestShellSplit (0.00s)153--- PASS: TestScriptTokenEmptyToken (0.00s)154=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive155=== CONT TestDumpPathWriterError156--- PASS: TestFileTokenMissing (0.00s)157=== CONT TestDumpPathSingleFile158--- PASS: TestFileTokenReadsAndCaches (0.00s)159=== RUN TestSetClientTLSErrors/missing_cert_file160=== PAUSE TestSetClientTLSErrors/missing_cert_file161=== RUN TestSetClientTLSErrors/missing_key_file162=== PAUSE TestSetClientTLSErrors/missing_key_file163=== RUN TestSetClientTLSErrors/missing_ca_file164=== PAUSE TestSetClientTLSErrors/missing_ca_file165=== RUN TestSetClientTLSErrors/invalid_ca_file166=== PAUSE TestSetClientTLSErrors/invalid_ca_file167=== CONT TestGetStorePathHash168=== RUN TestGetStorePathHash/valid_store_path1692026/10/06 07:35:26 ERROR Upload failed error="bad path" count=3170=== PAUSE TestGetStorePathHash/valid_store_path171--- PASS: TestStreamPushIsolatesFailures (0.00s)1722026/10/06 07:35:26 ERROR Upload failed error="connection refused" count=20173=== CONT TestPartSizeForNAR1742026/10/06 07:35:26 ERROR Server seems unavailable, giving up on batch untried=17175=== CONT TestEncodeNixBase32WithRealHash1762026/10/06 07:35:26 ERROR Upload failed error=boom count=1177=== RUN TestPartSizeForNAR/zero_stays_at_minimum178=== CONT TestConvertHashToNix32179=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum180=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths181=== CONT TestUploadMultipart_SupersededByPeer182=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths183=== RUN TestUploadMultipart_SupersededByPeer/exists184=== RUN TestGetStorePathHash/basename_without_hyphen_should_error185=== PAUSE TestUploadMultipart_SupersededByPeer/exists186=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1872026/10/06 07:35:27 WARN Rate limiter enabled after throttle name=server-test rate=5188=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1892026/10/06 07:35:27 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39449190=== PAUSE TestEncodeNixBase32/test_string_hash191=== RUN TestEncodeNixBase32/empty_input192=== PAUSE TestEncodeNixBase32/empty_input193--- PASS: TestClientSignaturesByStorePath (0.00s)194--- PASS: TestStreamPushReportsSignatures (0.00s)195=== CONT TestRegisterUploadedObjectReusesConnections1962026/10/06 07:35:27 WARN Rate limiter backed off name=server-test rate=5197--- PASS: TestEncodeNixBase32WithRealHash (0.00s)1982026/10/06 07:35:27 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39449199--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)200--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)201--- PASS: TestScriptTokenBadJSON (0.01s)202=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica203=== CONT TestParsePathInfoJSON204=== RUN TestParsePathInfoJSON/Nix_format205=== PAUSE TestParsePathInfoJSON/Nix_format206=== RUN TestParsePathInfoJSON/Lix_format207=== PAUSE TestParsePathInfoJSON/Lix_format208=== RUN TestParsePathInfoJSON/empty_input209=== PAUSE TestParsePathInfoJSON/empty_input210=== RUN TestParsePathInfoJSON/whitespace_only211=== PAUSE TestParsePathInfoJSON/whitespace_only212=== RUN TestParsePathInfoJSON/invalid_JSON213=== PAUSE TestParsePathInfoJSON/invalid_JSON214=== CONT TestRateLimiterFeedback/429_enables_limiter215=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter216=== RUN TestSetClientTLS/rejects_connection_without_client_cert217=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert218=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA219=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA220=== RUN TestSetClientTLS/preserves_debug_logging_transport221=== PAUSE TestSetClientTLS/preserves_debug_logging_transport222--- PASS: TestResolveStorePath (0.00s)223--- PASS: TestDoServerRequestAttachesToken (0.04s)224=== RUN TestPartSizeForNAR/small_stays_at_minimum225=== PAUSE TestPartSizeForNAR/small_stays_at_minimum226=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum227=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum228=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts229=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts230=== RUN TestPartSizeForNAR/1_TiB2312026/10/06 07:35:27 WARN Rate limiter enabled after throttle name=server-test rate=5232=== PAUSE TestPartSizeForNAR/1_TiB2332026/10/06 07:35:27 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:34505234=== RUN TestPartSizeForNAR/5_TiB_S3_max_object235=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object236=== RUN TestPartSizeForNAR/capped_at_5_GiB237=== PAUSE TestPartSizeForNAR/capped_at_5_GiB238=== CONT TestRateLimiterFeedback/503_enables_limiter2392026/10/06 07:35:27 INFO Garbage collection started240--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)241=== RUN TestUploadMultipart_SupersededByPeer/missing242=== PAUSE TestUploadMultipart_SupersededByPeer/missing243=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2442026/10/06 07:35:27 WARN Rate limiter backed off name=server-test rate=5245=== CONT TestSetClientTLSErrors/missing_ca_file246=== CONT TestFilterOversizedClosures247=== RUN TestFilterOversizedClosures/no_limit_keeps_everything248=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything249=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped250=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped251=== RUN TestFilterOversizedClosures/all_closures_skipped252=== CONT TestSetClientTLSErrors/invalid_ca_file253=== CONT TestCaseHackSuffix254=== CONT TestSetClientTLSErrors/missing_cert_file2552026/10/06 07:35:27 WARN Rate limiter enabled after throttle name=server-test rate=52562026/10/06 07:35:27 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:40879257=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun258=== CONT TestEncodeNixBase32/test_string_hash259=== CONT TestEncodeNixBase32/empty_input260--- PASS: TestEncodeNixBase32 (0.04s)261 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)262 --- PASS: TestEncodeNixBase32/empty_input (0.00s)263=== RUN TestPathInfoCACompatibility/new_structured_format_-_text264=== CONT TestPathInfoHashCompatibility2652026/10/06 07:35:27 WARN Rate limiter backed off name=server-test rate=5266=== RUN TestConvertHashToNix32/SRI_format_to_Nix32267=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error268=== PAUSE TestFilterOversizedClosures/all_closures_skipped269=== CONT TestParsePathInfoJSON/Nix_format270=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths271=== CONT TestParsePathInfoJSON/Lix_format272=== CONT TestSetClientTLS/rejects_connection_without_client_cert273=== CONT TestSetClientTLS/preserves_debug_logging_transport274=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text275=== CONT TestSetClientTLSErrors/missing_key_file276--- PASS: TestRateLimiterFeedback (0.00s)277 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)278 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)279 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)280 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)2812026/10/06 07:35:27 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0282=== CONT TestParsePathInfoJSON/invalid_JSON283=== CONT TestUploadMultipart_SupersededByPeer/exists2842026/10/06 07:35:27 INFO Garbage collection started285=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA286=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error287=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error288=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error289=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error290=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)291=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)292=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon293=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon294=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI295=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI296=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512297=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512298=== CONT TestPartSizeForNAR/small_stays_at_minimum299=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32300=== CONT TestPartSizeForNAR/5_TiB_S3_max_object301=== CONT TestPartSizeForNAR/1_TiB302=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts303=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum304=== CONT TestUploadMultipart_SupersededByPeer/missing305=== CONT TestParsePathInfoJSON/empty_input306=== CONT TestFilterOversizedClosures/no_limit_keeps_everything307=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths308=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths309=== CONT TestFilterOversizedClosures/all_closures_skipped3102026/10/06 07:35:27 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50311=== CONT TestGetStorePathHash/valid_store_path312=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3132026/10/06 07:35:27 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000314=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3152026/10/06 07:35:27 WARN Garbage collection finished on another replica. Its statistics are not available here316=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error317=== RUN TestConvertHashToNix32/already_Nix32_format318=== PAUSE TestConvertHashToNix32/already_Nix32_format319=== RUN TestConvertHashToNix32/invalid_format320=== PAUSE TestConvertHashToNix32/invalid_format321=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error322=== CONT TestConvertHashToNix32/SRI_format_to_Nix32323=== CONT TestConvertHashToNix32/already_Nix32_format324=== CONT TestConvertHashToNix32/invalid_format325=== CONT TestPartSizeForNAR/zero_stays_at_minimum326=== CONT TestPartSizeForNAR/capped_at_5_GiB327=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method328=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method329=== CONT TestParsePathInfoJSON/whitespace_only330=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512331=== CONT TestGetStorePathHash/basename_without_hyphen_should_error332=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon333=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI334--- PASS: TestSetClientTLSErrors (0.01s)335 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)336 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)337 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)338 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)339=== CONT TestPathInfoCACompatibility/null_ca_field340--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)341 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)342 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)343--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)344--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)345--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)346--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)347=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method348=== CONT TestPathInfoCACompatibility/new_structured_format_-_text349=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive350=== CONT TestPathInfoCACompatibility/old_string_format_-_text351--- PASS: TestParsePathInfoJSON (0.00s)352 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)353 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)354 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)355 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)356 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)357--- PASS: TestGetStorePathHash (0.04s)358 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)359 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)360 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)361 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)362--- PASS: TestPathInfoHashCompatibility (0.00s)363 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)364 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)365 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)366 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)367--- PASS: TestFilterOversizedClosures (0.00s)368 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)369 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)370 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)371--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)372 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)373 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)374--- PASS: TestConvertHashToNix32 (0.04s)375 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)376 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)377 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)378--- PASS: TestPartSizeForNAR (0.03s)379 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)380 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)381 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)382 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)383 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)384 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)385 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)386--- PASS: TestPathInfoCACompatibility (0.04s)387 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)388 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)389 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)390 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)391 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)3922026/10/06 07:35:27 http: TLS handshake error from 127.0.0.1:50906: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.04s)394 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)395 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)397--- PASS: TestStreamPushRequestLine (0.05s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)399--- PASS: TestDumpPathSingleFile (0.07s)400--- PASS: TestCaseHackSuffix (0.03s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.11s)404--- PASS: TestUploadMultipart_PartsInParallel (0.66s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres1869514907/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/postgres1869514907/data -l logfile start434435/build/postgres1869514907:5432 - no response4362026-10-06 07:35:28.873 UTC [130] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 07:35:28.874 UTC [130] LOG: listening on Unix socket "/build/postgres1869514907/.s.PGSQL.5432"4382026-10-06 07:35:28.878 UTC [137] LOG: database system was shut down at 2026-10-06 07:35:28 UTC4392026-10-06 07:35:28.882 UTC [130] LOG: database system is ready to accept connections440/build/postgres1869514907:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== RUN TestResolveDBConnectionString480=== PAUSE TestResolveDBConnectionString481=== RUN TestConnectWaitsForAPeerMigration482=== PAUSE TestConnectWaitsForAPeerMigration483=== RUN TestLeadElectsOneAndHandsOver484=== PAUSE TestLeadElectsOneAndHandsOver485=== RUN TestLeadIncumbentWinsAfterRestart4862026/10/06 07:35:29 INFO lead: acquired remote=192.0.2.1:12344872026/10/06 07:35:30 INFO lead: released remote=192.0.2.1:12344882026/10/06 07:35:30 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 07:35:31 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/06 07:35:31 INFO lead: acquired remote=192.0.2.1:12344972026-10-06 07:35:32.729 UTC [580] FATAL: terminating connection due to administrator command4982026/10/06 07:35:32 INFO lead: acquired remote=192.0.2.1:12344992026/10/06 07:35:33 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/06 07:35:33 INFO lead: released remote=192.0.2.1:12345012026/10/06 07:35:34 INFO lead: released remote=192.0.2.1:1234502--- PASS: TestLeadEndsWhenItsConnectionHangs (2.93s)503=== RUN TestGCAdvisoryLockBlocksConcurrentRun504=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun505=== RUN TestGCBugBareHashReferences506=== PAUSE TestGCBugBareHashReferences507=== RUN TestGCMetrics508=== PAUSE TestGCMetrics509=== RUN TestPushDedupSurvivesConcurrentGC510=== PAUSE TestPushDedupSurvivesConcurrentGC511=== RUN TestDeduplicatedObjectsRecordedAsPending512=== PAUSE TestDeduplicatedObjectsRecordedAsPending513=== RUN TestGCSweepSkipsPendingObjects514=== PAUSE TestGCSweepSkipsPendingObjects515=== RUN TestTombstonedObjectOfferedWithoutWaiting516=== PAUSE TestTombstonedObjectOfferedWithoutWaiting517=== RUN TestGCSweepDeliversEachKeyOnce518=== PAUSE TestGCSweepDeliversEachKeyOnce519=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection520=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== RUN TestForceGCDuringPushOffersSweptObject522=== PAUSE TestForceGCDuringPushOffersSweptObject523=== RUN TestFailedS3DeleteKeepsTombstone524=== PAUSE TestFailedS3DeleteKeepsTombstone525=== RUN TestSweepSkipsRowsLockedByPush526=== PAUSE TestSweepSkipsRowsLockedByPush527=== RUN TestRegisterCompletedObjectNeedsPendingRow528=== PAUSE TestRegisterCompletedObjectNeedsPendingRow529=== RUN TestGetExistingObjectsLocksRows530=== PAUSE TestGetExistingObjectsLocksRows531=== RUN TestSweepRechecksPendingAfterLocking532=== PAUSE TestSweepRechecksPendingAfterLocking533=== RUN TestPushWaitsForSweepHoldingRow534=== PAUSE TestPushWaitsForSweepHoldingRow535=== RUN TestCommitRacingPendingCleanupKeepsObjects536=== PAUSE TestCommitRacingPendingCleanupKeepsObjects537=== RUN TestGCEndsOnShutdown538=== PAUSE TestGCEndsOnShutdown539=== RUN TestGCTaskStore_StartNew540=== PAUSE TestGCTaskStore_StartNew541=== RUN TestGCTaskStore_DeduplicateSameParams542=== PAUSE TestGCTaskStore_DeduplicateSameParams543=== RUN TestGCTaskStore_ConflictDifferentParams544=== PAUSE TestGCTaskStore_ConflictDifferentParams545=== RUN TestGCTaskStore_GetEmpty546=== PAUSE TestGCTaskStore_GetEmpty547=== RUN TestGCTaskStore_GetReturnsLatest548=== PAUSE TestGCTaskStore_GetReturnsLatest549=== RUN TestGCTaskStore_CompletedAllowsNewTask550=== PAUSE TestGCTaskStore_CompletedAllowsNewTask551=== RUN TestGCTaskStore_PhaseUpdates552=== PAUSE TestGCTaskStore_PhaseUpdates553=== RUN TestGCTaskStore_Fail554=== PAUSE TestGCTaskStore_Fail555=== RUN TestGracefulShutdownDrainsInflight556=== PAUSE TestGracefulShutdownDrainsInflight557=== RUN TestService_healthCheckHandler558=== PAUSE TestService_healthCheckHandler559=== RUN TestService_readinessHandler560=== PAUSE TestService_readinessHandler561=== RUN TestGenerateLandingPage562=== PAUSE TestGenerateLandingPage563=== RUN TestCacheConfigHandlerMaxNarSize564=== PAUSE TestCacheConfigHandlerMaxNarSize565=== RUN TestCreatePendingClosureRejectsOversizedNAR566=== PAUSE TestCreatePendingClosureRejectsOversizedNAR567=== RUN TestNARDeduplicationMetadataUploadBug568=== PAUSE TestNARDeduplicationMetadataUploadBug569=== RUN TestMetricsInventory570=== PAUSE TestMetricsInventory571=== RUN TestService_NativeMTLS572=== PAUSE TestService_NativeMTLS573=== RUN TestServerTLSConfig574=== PAUSE TestServerTLSConfig575=== RUN TestMultipartCleanup576=== PAUSE TestMultipartCleanup577=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded578=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== RUN TestPendingCleanupUsesOneCutoff580=== PAUSE TestPendingCleanupUsesOneCutoff581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentNotReportedWhileGCDeletesClosure592=== PAUSE TestPresentNotReportedWhileGCDeletesClosure593=== RUN TestParseSingleRange594=== PAUSE TestParseSingleRange595=== RUN TestProxyHeadersOnlyTrustedOnSocket596=== PAUSE TestProxyHeadersOnlyTrustedOnSocket597=== RUN TestIsValidCachePath598=== PAUSE TestIsValidCachePath599=== RUN TestReadProxyNarinfo600=== PAUSE TestReadProxyNarinfo601=== RUN TestReadProxyNarinfoAlreadyDecompressed602=== PAUSE TestReadProxyNarinfoAlreadyDecompressed603=== RUN TestReadProxyNarStreaming604=== PAUSE TestReadProxyNarStreaming605=== RUN TestReadProxy404606=== PAUSE TestReadProxy404607=== RUN TestReadProxyInvalidPath608=== PAUSE TestReadProxyInvalidPath609=== RUN TestReadProxyHead610=== PAUSE TestReadProxyHead611=== RUN TestReadProxyOutlastsServerWriteTimeout612=== PAUSE TestReadProxyOutlastsServerWriteTimeout613=== RUN TestReadProxyConditionalGet614=== PAUSE TestReadProxyConditionalGet615=== RUN TestReadProxyRootRedirectsToIndexHTML616=== PAUSE TestReadProxyRootRedirectsToIndexHTML617=== RUN TestReadProxyDisabled618=== PAUSE TestReadProxyDisabled619=== RUN TestReadRedirectNar620=== PAUSE TestReadRedirectNar621=== RUN TestReadRedirectKeepsNarinfoProxied622=== PAUSE TestReadRedirectKeepsNarinfoProxied623=== RUN TestReadProxyRangeRequest624=== PAUSE TestReadProxyRangeRequest625=== RUN TestReadRedirectUsesPublicS3URL626=== PAUSE TestReadRedirectUsesPublicS3URL627=== RUN TestPush_OverlappingRootsStoreOneRowPerKey628=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey629=== RUN TestPush_CompleteCommitsEveryRoot630=== PAUSE TestPush_CompleteCommitsEveryRoot631=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit632=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit633=== RUN TestPush_RejectsBadRequests634=== PAUSE TestPush_RejectsBadRequests635=== RUN TestPush_SignsNarinfosOfItsPendingObjects636=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects637=== RUN TestRedundantMultipartUpload638=== PAUSE TestRedundantMultipartUpload639=== RUN TestCompleteMultipartUpload_ErrorButObjectExists640=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists641=== RUN TestCompletedNarNotReofferedAcrossClosures642=== PAUSE TestCompletedNarNotReofferedAcrossClosures643=== RUN TestPresignedUploadRegisteredBeforeCommit644=== PAUSE TestPresignedUploadRegisteredBeforeCommit645=== RUN TestService_Rustfstest646=== PAUSE TestService_Rustfstest647=== RUN TestParseSize648=== PAUSE TestParseSize649=== RUN TestSkippedUploadsHandler650=== PAUSE TestSkippedUploadsHandler651=== RUN TestSystemdListenerNotActivated652--- PASS: TestSystemdListenerNotActivated (0.00s)653=== RUN TestWatchdogBeatsWhenHealthy654--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)655=== RUN TestWatchdogSkipsWhenUnhealthy6562026/10/06 07:35:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/06 07:35:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/06 07:35:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/06 07:35:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 07:35:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 07:35:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 07:35:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 07:35:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 07:35:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 07:35:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"666--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)667=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle668=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle669=== RUN TestProxyWriteTimeout670=== PAUSE TestProxyWriteTimeout671=== RUN TestPendingClosureWriteTimeout672=== PAUSE TestPendingClosureWriteTimeout673=== RUN TestIsValidUploadKey674=== PAUSE TestIsValidUploadKey675=== RUN TestUploadHandlersRejectInvalidKeys676=== PAUSE TestUploadHandlersRejectInvalidKeys677=== RUN TestUploadHandlersRejectOversizedBody678=== PAUSE TestUploadHandlersRejectOversizedBody679=== RUN TestService_cleanupPendingClosuresHandler680=== PAUSE TestService_cleanupPendingClosuresHandler681=== RUN TestService_createPendingClosureHandler682=== PAUSE TestService_createPendingClosureHandler683=== RUN TestService_verifyS3Integrity684=== PAUSE TestService_verifyS3Integrity685=== RUN TestCompleteMultipartUnregistered686=== PAUSE TestCompleteMultipartUnregistered687=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT688=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT689=== CONT TestService_AuthMiddleware690=== CONT TestParseSingleRange691=== RUN TestParseSingleRange/none692=== PAUSE TestParseSingleRange/none693=== RUN TestParseSingleRange/unknown_unit694=== PAUSE TestParseSingleRange/unknown_unit695=== RUN TestParseSingleRange/multi-range_ignored696=== PAUSE TestParseSingleRange/multi-range_ignored697=== RUN TestParseSingleRange/malformed_no_dash698=== PAUSE TestParseSingleRange/malformed_no_dash699=== RUN TestParseSingleRange/malformed_both_empty700=== PAUSE TestParseSingleRange/malformed_both_empty701=== RUN TestParseSingleRange/malformed_end_before_start702=== PAUSE TestParseSingleRange/malformed_end_before_start703=== RUN TestParseSingleRange/closed704=== PAUSE TestParseSingleRange/closed705=== RUN TestParseSingleRange/open-ended706=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT707=== CONT TestCompleteMultipartUnregistered708=== CONT TestService_verifyS3Integrity709=== CONT TestService_createPendingClosureHandler710=== CONT TestService_cleanupPendingClosuresHandler711=== CONT TestUploadHandlersRejectOversizedBody712=== CONT TestUploadHandlersRejectInvalidKeys713=== CONT TestIsValidUploadKey714=== CONT TestPendingClosureWriteTimeout715=== CONT TestProxyWriteTimeout716=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle717=== CONT TestSkippedUploadsHandler718=== CONT TestParseSize719=== CONT TestService_Rustfstest720=== CONT TestPresignedUploadRegisteredBeforeCommit721=== CONT TestCompletedNarNotReofferedAcrossClosures722=== CONT TestCompleteMultipartUpload_ErrorButObjectExists723=== CONT TestRedundantMultipartUpload724=== CONT TestPush_SignsNarinfosOfItsPendingObjects725=== CONT TestPush_RejectsBadRequests726=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit727=== CONT TestPush_CompleteCommitsEveryRoot728=== PAUSE TestParseSingleRange/open-ended729=== RUN TestParseSingleRange/end_clamped_to_size730=== PAUSE TestParseSingleRange/end_clamped_to_size731=== RUN TestParseSingleRange/suffix732=== PAUSE TestParseSingleRange/suffix733=== RUN TestParseSingleRange/suffix_exceeds_size734=== PAUSE TestParseSingleRange/suffix_exceeds_size735=== RUN TestParseSingleRange/single_byte736=== PAUSE TestParseSingleRange/single_byte737=== RUN TestParseSingleRange/start_past_EOF738=== PAUSE TestParseSingleRange/start_past_EOF739=== RUN TestParseSingleRange/start_far_past_EOF740=== PAUSE TestParseSingleRange/start_far_past_EOF741--- PASS: TestParseSize (0.00s)742=== CONT TestReadRedirectUsesPublicS3URL743=== RUN TestIsValidUploadKey/narinfo744=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info745=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info746=== CONT TestPush_OverlappingRootsStoreOneRowPerKey747=== RUN TestProxyWriteTimeout/narinfo748=== PAUSE TestProxyWriteTimeout/narinfo749=== RUN TestProxyWriteTimeout/1_GiB_nar750=== PAUSE TestProxyWriteTimeout/1_GiB_nar7512026/10/06 07:35:34 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000752=== RUN TestProxyWriteTimeout/10_GiB_nar753=== PAUSE TestProxyWriteTimeout/10_GiB_nar754=== RUN TestProxyWriteTimeout/unknown_size755=== PAUSE TestProxyWriteTimeout/unknown_size756=== PAUSE TestIsValidUploadKey/narinfo757=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal758=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal759=== RUN TestPendingClosureWriteTimeout/empty760=== PAUSE TestPendingClosureWriteTimeout/empty761=== RUN TestPendingClosureWriteTimeout/400_objects762=== PAUSE TestPendingClosureWriteTimeout/400_objects763=== RUN TestPendingClosureWriteTimeout/670k_objects764=== PAUSE TestPendingClosureWriteTimeout/670k_objects765=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline766=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline767=== CONT TestReadRedirectKeepsNarinfoProxied768=== RUN TestIsValidUploadKey/nar_zst769=== PAUSE TestIsValidUploadKey/nar_zst770=== CONT TestReadProxyRangeRequest771=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key772=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key773=== RUN TestIsValidUploadKey/nar_xz774=== PAUSE TestIsValidUploadKey/nar_xz775=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key776=== RUN TestIsValidUploadKey/nar_plain777=== PAUSE TestIsValidUploadKey/nar_plain778=== RUN TestIsValidUploadKey/listing779=== PAUSE TestIsValidUploadKey/listing780=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key781=== RUN TestIsValidUploadKey/build_log782=== PAUSE TestIsValidUploadKey/build_log783=== RUN TestIsValidUploadKey/build_log_home-manager_file784=== PAUSE TestIsValidUploadKey/build_log_home-manager_file785=== RUN TestIsValidUploadKey/build_log_plus_in_name786=== PAUSE TestIsValidUploadKey/build_log_plus_in_name787=== RUN TestIsValidUploadKey/build_log_question_mark788=== PAUSE TestIsValidUploadKey/build_log_question_mark789=== RUN TestIsValidUploadKey/build_log_equals790=== PAUSE TestIsValidUploadKey/build_log_equals791=== RUN TestIsValidUploadKey/realisation792=== PAUSE TestIsValidUploadKey/realisation793=== RUN TestIsValidUploadKey/realisation_plus_in_output794=== CONT TestReadRedirectNar795=== PAUSE TestIsValidUploadKey/realisation_plus_in_output796=== RUN TestIsValidUploadKey/nix-cache-info797=== PAUSE TestIsValidUploadKey/nix-cache-info798=== RUN TestIsValidUploadKey/index.html799=== PAUSE TestIsValidUploadKey/index.html800=== RUN TestIsValidUploadKey/narinfo_key,_nar_type801=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type802=== RUN TestIsValidUploadKey/nar_key,_narinfo_type803=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type804=== RUN TestIsValidUploadKey/listing_key,_narinfo_type805=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type806=== RUN TestIsValidUploadKey/traversal807=== PAUSE TestIsValidUploadKey/traversal808=== RUN TestIsValidUploadKey/traversal_nar809=== PAUSE TestIsValidUploadKey/traversal_nar810=== RUN TestIsValidUploadKey/absolute811=== PAUSE TestIsValidUploadKey/absolute812=== RUN TestIsValidUploadKey/empty_key813=== PAUSE TestIsValidUploadKey/empty_key814=== RUN TestIsValidUploadKey/unknown_type815=== PAUSE TestIsValidUploadKey/unknown_type816=== CONT TestReadProxyDisabled817--- PASS: TestSkippedUploadsHandler (0.01s)818=== CONT TestReadProxyRootRedirectsToIndexHTML819=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure820=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure821=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart822=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart823=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts824=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts825=== CONT TestReadProxyConditionalGet8262026/10/06 07:35:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8272026/10/06 07:35:34 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst828--- PASS: TestCompleteMultipartUnregistered (0.49s)829=== CONT TestReadProxyOutlastsServerWriteTimeout8302026/10/06 07:35:34 INFO Received uploads request method=POST path=/api/pending_closures8312026/10/06 07:35:34 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"832--- PASS: TestService_AuthMiddleware (0.53s)833=== CONT TestReadProxyHead8342026/10/06 07:35:34 INFO Received uploads request method=POST path=/api/pending_closures8352026/10/06 07:35:34 INFO Received uploads request method=POST path=/api/pending_closures8362026/10/06 07:35:34 INFO Received uploads request method=POST path=/api/pending_closures837--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.61s)838=== CONT TestReadProxyInvalidPath8392026/10/06 07:35:34 INFO Received cleanup request method=DELETE path=/api/pending_closures8402026/10/06 07:35:34 INFO Aborted multipart uploads count=0 kept=08412026/10/06 07:35:34 INFO Received uploads request method=POST path=/api/pending_closures8422026/10/06 07:35:35 INFO Received cleanup request method=DELETE path=/api/pending_closures8432026/10/06 07:35:35 INFO Aborted multipart uploads count=1 kept=08442026/10/06 07:35:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete845--- PASS: TestService_Rustfstest (0.65s)846=== CONT TestReadProxy4048472026-10-06 07:35:35.013 UTC [655] ERROR: Closure does not exist: id=18482026-10-06 07:35:35.013 UTC [655] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8492026-10-06 07:35:35.013 UTC [655] STATEMENT: -- name: CommitPendingClosure :exec850 SELECT commit_pending_closure($1::bigint)851 852--- PASS: TestService_cleanupPendingClosuresHandler (0.65s)853=== CONT TestReadProxyNarStreaming8542026/10/06 07:35:35 INFO Received push request method=POST path=/api/pushes8552026/10/06 07:35:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8562026/10/06 07:35:35 INFO Signed narinfos id=1 count=18572026/10/06 07:35:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8582026/10/06 07:35:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8592026/10/06 07:35:35 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8602026/10/06 07:35:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8612026/10/06 07:35:35 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8622026/10/06 07:35:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8632026/10/06 07:35:35 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18642026/10/06 07:35:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8652026/10/06 07:35:35 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo866--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.70s)867=== CONT TestReadProxyNarinfoAlreadyDecompressed868=== RUN TestPush_RejectsBadRequests/no_roots869=== PAUSE TestPush_RejectsBadRequests/no_roots870=== RUN TestPush_RejectsBadRequests/no_objects871=== PAUSE TestPush_RejectsBadRequests/no_objects872=== RUN TestPush_RejectsBadRequests/bad_root873=== PAUSE TestPush_RejectsBadRequests/bad_root874=== RUN TestPush_RejectsBadRequests/root_not_in_objects875=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects876=== CONT TestReadProxyNarinfo8772026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures8782026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures8792026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures880--- PASS: TestReadRedirectUsesPublicS3URL (0.77s)881=== CONT TestIsValidCachePath882=== RUN TestIsValidCachePath/narinfo883=== PAUSE TestIsValidCachePath/narinfo884=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars885=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars886=== RUN TestIsValidCachePath/nar_zst887=== PAUSE TestIsValidCachePath/nar_zst888=== RUN TestIsValidCachePath/nar_xz889=== PAUSE TestIsValidCachePath/nar_xz890=== RUN TestIsValidCachePath/nar_bz2891=== PAUSE TestIsValidCachePath/nar_bz2892=== RUN TestIsValidCachePath/nar_uncompressed893=== PAUSE TestIsValidCachePath/nar_uncompressed894=== RUN TestIsValidCachePath/ls895=== PAUSE TestIsValidCachePath/ls896=== RUN TestIsValidCachePath/log897=== PAUSE TestIsValidCachePath/log898=== RUN TestIsValidCachePath/realisation899=== PAUSE TestIsValidCachePath/realisation900=== RUN TestIsValidCachePath/nix-cache-info901=== PAUSE TestIsValidCachePath/nix-cache-info902=== RUN TestIsValidCachePath/index.html903=== PAUSE TestIsValidCachePath/index.html904=== RUN TestIsValidCachePath/traversal_parent905=== PAUSE TestIsValidCachePath/traversal_parent906=== RUN TestIsValidCachePath/traversal_in_middle907=== PAUSE TestIsValidCachePath/traversal_in_middle908=== RUN TestIsValidCachePath/invalid_char_e909=== PAUSE TestIsValidCachePath/invalid_char_e910=== RUN TestIsValidCachePath/invalid_char_u911=== PAUSE TestIsValidCachePath/invalid_char_u912=== RUN TestIsValidCachePath/random_path913=== PAUSE TestIsValidCachePath/random_path914=== RUN TestIsValidCachePath/empty9152026/10/06 07:35:35 INFO Received push request method=POST path=/api/pushes916=== PAUSE TestIsValidCachePath/empty917=== RUN TestIsValidCachePath/leading_slash918=== PAUSE TestIsValidCachePath/leading_slash919=== RUN TestIsValidCachePath/wrong_extension920=== PAUSE TestIsValidCachePath/wrong_extension921=== RUN TestIsValidCachePath/short_hash922=== PAUSE TestIsValidCachePath/short_hash923=== CONT TestProxyHeadersOnlyTrustedOnSocket9242026/10/06 07:35:35 INFO Received complete push request method=POST path=/api/pushes/1/complete9252026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures926--- PASS: TestPush_CompleteCommitsEveryRoot (0.71s)927=== CONT TestService_readinessHandler9282026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures9292026/10/06 07:35:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9302026/10/06 07:35:35 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTA3M2FmM2EtYmYyZi00ZTQ4LTk1ZjktYTQ1YTQxOTNhMGJhLmYzNDgwNmQ0LTVkYjItNGZiZi05YTQyLWM2YTQ0YmUyNzY3ZngxNzkxMjcyMTM1MTgzNDAyOTMy9312026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures9322026/10/06 07:35:35 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9332026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures9342026/10/06 07:35:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTA3M2FmM2EtYmYyZi00ZTQ4LTk1ZjktYTQ1YTQxOTNhMGJhLmYzNDgwNmQ0LTVkYjItNGZiZi05YTQyLWM2YTQ0YmUyNzY3ZngxNzkxMjcyMTM1MTgzNDAyOTMy parts=1935--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.88s)936=== CONT TestSweepSkipsRowsLockedByPush937--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.88s)938=== CONT TestPresentNotReportedWhileGCDeletesClosure9392026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures9402026/10/06 07:35:35 INFO Received push request method=POST path=/api/pushes941--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.86s)942=== CONT TestService_healthCheckHandler943--- PASS: TestReadProxyDisabled (0.86s)944=== CONT TestPresentReportsOnlyClosureRoots9452026/10/06 07:35:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete946--- PASS: TestReadRedirectNar (0.90s)947=== CONT TestGracefulShutdownDrainsInflight9482026/10/06 07:35:35 INFO Starting HTTP server address=127.0.0.1:337279492026/10/06 07:35:35 INFO Shutdown signal received, draining in-flight requests timeout=10s9502026/10/06 07:35:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete951--- PASS: TestReadProxyRangeRequest (0.93s)952=== CONT TestGCTaskStore_Fail953--- PASS: TestGCTaskStore_Fail (0.00s)954=== CONT TestGCTaskStore_PhaseUpdates955--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)956=== CONT TestCreatePin_ReservedPins9572026/10/06 07:35:35 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTA3M2FmM2EtYmYyZi00ZTQ4LTk1ZjktYTQ1YTQxOTNhMGJhLmNmZWZmOGM2LTdjNWYtNDMyYS1iZGEzLTkzNDMxNjIzZGMxMHgxNzkxMjcyMTM0ODg2Mjc1Njky parts=109582026/10/06 07:35:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9592026/10/06 07:35:35 INFO Completed upload id=19602026/10/06 07:35:35 INFO Received push request method=POST path=/api/pushes9612026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures9622026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures9632026/10/06 07:35:35 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9642026/10/06 07:35:35 WARN Found objects in DB but missing from S3, will re-upload count=1965--- PASS: TestService_verifyS3Integrity (1.05s)966=== CONT TestGCTaskStore_CompletedAllowsNewTask967--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)968=== CONT TestOrphanedObjectsGCStressTest969--- PASS: TestGracefulShutdownDrainsInflight (0.07s)9702026/10/06 07:35:35 INFO Received complete push request method=POST path=/api/pushes/1/complete971=== CONT TestGCTaskStore_GetReturnsLatest972--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)973=== CONT TestOrphanedObjectsGC9742026/10/06 07:35:35 INFO Received push request method=POST path=/api/pushes975--- PASS: TestReadRedirectKeepsNarinfoProxied (0.99s)976=== CONT TestGCTaskStore_GetEmpty977--- PASS: TestGCTaskStore_GetEmpty (0.00s)978=== CONT TestObjectStatsTrigger9792026/10/06 07:35:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38571/oidc980--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.01s)981=== CONT TestPendingCleanupUsesOneCutoff9822026/10/06 07:35:35 INFO Aborted multipart uploads count=0 kept=09832026/10/06 07:35:35 WARN Force mode enabled - objects will be deleted immediately without grace period984--- PASS: TestReadProxyConditionalGet (0.95s)985=== CONT TestGCTaskStore_ConflictDifferentParams986--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)987=== CONT TestGCTaskStore_DeduplicateSameParams988--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)989=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9902026/10/06 07:35:35 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=09912026/10/06 07:35:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9922026/10/06 07:35:35 INFO Vacuumed table table=pending_closures9932026/10/06 07:35:35 INFO Vacuumed table table=pending_objects9942026/10/06 07:35:35 INFO Vacuumed table table=multipart_uploads9952026/10/06 07:35:35 INFO Vacuumed table table=closures9962026/10/06 07:35:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTA3M2FmM2EtYmYyZi00ZTQ4LTk1ZjktYTQ1YTQxOTNhMGJhLjc0ODFmMDViLWFjZDItNDRmOC1hMzgyLTVhY2JjNTZmMGJjNngxNzkxMjcyMTM0OTUwNzY5MDMz parts=129972026/10/06 07:35:35 INFO Vacuumed table table=objects9982026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures9992026/10/06 07:35:35 INFO Received complete push request method=POST path=/api/pushes/2/complete1000--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.15s)1001=== CONT TestGCTaskStore_StartNew1002--- PASS: TestGCTaskStore_StartNew (0.00s)1003=== CONT TestMultipartCleanup10042026/10/06 07:35:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10052026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures1006--- PASS: TestReadProxyHead (0.73s)1007=== CONT TestGCEndsOnShutdown1008=== RUN TestGCEndsOnShutdown/before_the_run1009=== PAUSE TestGCEndsOnShutdown/before_the_run1010=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1011=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1012=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1013=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1014=== CONT TestServerTLSConfig1015=== RUN TestServerTLSConfig/no_client_CA1016=== PAUSE TestServerTLSConfig/no_client_CA1017=== RUN TestServerTLSConfig/missing_CA_file1018=== PAUSE TestServerTLSConfig/missing_CA_file1019=== RUN TestServerTLSConfig/not_a_PEM_file1020=== PAUSE TestServerTLSConfig/not_a_PEM_file1021=== CONT TestCommitRacingPendingCleanupKeepsObjects10222026/10/06 07:35:35 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTA3M2FmM2EtYmYyZi00ZTQ4LTk1ZjktYTQ1YTQxOTNhMGJhLmIxMTA0MDY0LTkzOTctNGEzNi05YjExLTc4NzJkOGI1ZmNiN3gxNzkxMjcyMTM1MTA3Mzg1MjQz parts=1010232026/10/06 07:35:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10242026/10/06 07:35:35 INFO Completed upload id=110252026/10/06 07:35:35 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010262026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures1027--- PASS: TestReadProxyInvalidPath (0.67s)1028=== CONT TestService_NativeMTLS10292026/10/06 07:35:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures10302026/10/06 07:35:35 INFO Aborted multipart uploads count=0 kept=010312026/10/06 07:35:35 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=010322026/10/06 07:35:35 INFO Vacuumed table table=pending_closures10332026/10/06 07:35:35 INFO Vacuumed table table=pending_objects10342026/10/06 07:35:35 INFO Vacuumed table table=multipart_uploads10352026/10/06 07:35:35 INFO Vacuumed table table=closures1036--- PASS: TestReadProxyNarStreaming (0.67s)1037=== CONT TestPushWaitsForSweepHoldingRow10382026/10/06 07:35:35 INFO Vacuumed table table=objects10392026/10/06 07:35:35 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001040--- PASS: TestService_createPendingClosureHandler (1.34s)1041=== CONT TestMetricsInventory1042--- PASS: TestReadProxy404 (0.72s)1043=== CONT TestSweepRechecksPendingAfterLocking1044--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.68s)1045=== CONT TestNARDeduplicationMetadataUploadBug10462026/10/06 07:35:35 INFO Starting HTTP server address=127.0.0.1:3959110472026/10/06 07:35:35 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1855447938/001/proxy.sock10482026/10/06 07:35:35 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10492026/10/06 07:35:35 INFO Shutdown signal received, draining in-flight requests timeout=10s1050--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.66s)1051=== CONT TestGetExistingObjectsLocksRows10522026/10/06 07:35:35 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"10532026/10/06 07:35:35 WARN readiness check failed error="closed pool"1054--- PASS: TestService_readinessHandler (0.67s)1055=== CONT TestCreatePendingClosureRejectsOversizedNAR10562026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures1057--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1058=== CONT TestRegisterCompletedObjectNeedsPendingRow10592026/10/06 07:35:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10602026/10/06 07:35:35 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTA3M2FmM2EtYmYyZi00ZTQ4LTk1ZjktYTQ1YTQxOTNhMGJhLjE0ZTg2NmYzLWRhZjItNGZhZC05NzI2LWY1ODYyYWUwZDNiNngxNzkxMjcyMTM1MjczMTE5MzUz parts=1210612026/10/06 07:35:35 INFO Received uploads request method=POST path=/api/pending_closures1062--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.55s)1063=== CONT TestCacheConfigHandlerMaxNarSize1064--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1065=== CONT TestGenerateLandingPage1066--- PASS: TestGenerateLandingPage (0.00s)1067=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10682026/10/06 07:35:35 INFO Aborted multipart uploads count=0 kept=010692026/10/06 07:35:35 WARN Force mode enabled - objects will be deleted immediately without grace period10702026/10/06 07:35:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010712026/10/06 07:35:35 INFO Vacuumed table table=pending_closures10722026/10/06 07:35:35 INFO Vacuumed table table=pending_objects10732026/10/06 07:35:35 INFO Vacuumed table table=multipart_uploads10742026/10/06 07:35:35 INFO Vacuumed table table=closures10752026/10/06 07:35:35 INFO Vacuumed table table=objects10762026/10/06 07:35:35 INFO Aborted multipart uploads count=0 kept=01077--- PASS: TestPresentReportsOnlyClosureRoots (0.66s)1078=== CONT TestFailedS3DeleteKeepsTombstone10792026/10/06 07:35:35 WARN Force mode enabled - objects will be deleted immediately without grace period1080--- PASS: TestService_healthCheckHandler (0.67s)10812026/10/06 07:35:35 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=01082=== CONT TestClientCADerivations10832026/10/06 07:35:35 INFO Vacuumed table table=pending_closures10842026/10/06 07:35:35 INFO Vacuumed table table=pending_objects10852026/10/06 07:35:35 INFO Vacuumed table table=multipart_uploads10862026/10/06 07:35:35 INFO Vacuumed table table=closures10872026/10/06 07:35:36 INFO Vacuumed table table=objects1088--- PASS: TestSweepSkipsRowsLockedByPush (0.75s)1089=== CONT TestForceGCDuringPushOffersSweptObject1090=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1091=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1092=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1093=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1094=== CONT TestClientFallsBackToClosures10952026/10/06 07:35:36 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161096--- PASS: TestReadProxyNarinfo (1.03s)1097=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10982026/10/06 07:35:36 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10992026/10/06 07:35:36 WARN Refused reserved pin name=worker-x86_64-linux11002026/10/06 07:35:36 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11012026/10/06 07:35:36 INFO Received create pin request method=POST path=/api/pins/my-app11022026/10/06 07:35:36 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1103--- PASS: TestCreatePin_ReservedPins (0.71s)1104=== CONT TestClientMultipleUploads1105--- PASS: TestObjectStatsTrigger (0.69s)1106=== CONT TestClientIntegration11072026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures11082026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures11092026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures11102026/10/06 07:35:36 INFO Received cleanup request method=DELETE path=/api/pending_closures1111--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.68s)1112=== CONT TestGCSweepDeliversEachKeyOnce11132026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures11142026/10/06 07:35:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11152026/10/06 07:35:36 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTA3M2FmM2EtYmYyZi00ZTQ4LTk1ZjktYTQ1YTQxOTNhMGJhLjQ4YmM0ZThiLWQxOTktNDM1YS05MzYzLWZhNWVlZmFlNmU2YXgxNzkxMjcyMTM1NjIwODkzNjYz error="Get \"http://127.0.0.1:1/bucket6/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11162026/10/06 07:35:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTA3M2FmM2EtYmYyZi00ZTQ4LTk1ZjktYTQ1YTQxOTNhMGJhLjExM2E1NmY4LWUyNjItNDljNS05ZmM1LWZmNjk0OTNhOTFhYXgxNzkxMjcyMTM1NjEzNDgwNjE4 parts=1211172026/10/06 07:35:36 INFO Received cleanup request method=DELETE path=/api/pending_closures11182026/10/06 07:35:36 INFO Aborted multipart uploads count=1 kept=01119--- PASS: TestRedundantMultipartUpload (1.90s)1120=== CONT TestClientErrorHandling1121=== RUN TestClientErrorHandling/InvalidStorePath1122=== PAUSE TestClientErrorHandling/InvalidStorePath1123=== RUN TestClientErrorHandling/InvalidAuthToken1124=== PAUSE TestClientErrorHandling/InvalidAuthToken1125=== RUN TestClientErrorHandling/ServerNotAvailable1126=== PAUSE TestClientErrorHandling/ServerNotAvailable1127=== CONT TestTombstonedObjectOfferedWithoutWaiting11282026/10/06 07:35:36 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11292026/10/06 07:35:36 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1130--- PASS: TestService_NativeMTLS (0.63s)1131=== CONT TestService_RequireScope_OIDC11322026/10/06 07:35:36 INFO Aborted multipart uploads count=0 kept=011332026/10/06 07:35:36 WARN Force mode enabled - objects will be deleted immediately without grace period11342026/10/06 07:35:36 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=011352026/10/06 07:35:36 INFO Vacuumed table table=pending_closures11362026/10/06 07:35:36 INFO Vacuumed table table=pending_objects11372026/10/06 07:35:36 INFO Vacuumed table table=multipart_uploads11382026/10/06 07:35:36 INFO Vacuumed table table=closures11392026/10/06 07:35:36 INFO Vacuumed table table=objects11402026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures1141--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.70s)1142=== CONT TestGCSweepSkipsPendingObjects11432026/10/06 07:35:36 INFO Received cleanup request method=DELETE path=/api/pending_closures11442026/10/06 07:35:36 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket46/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11452026/10/06 07:35:36 INFO Aborted multipart uploads count=0 kept=111462026/10/06 07:35:36 INFO Received cleanup request method=DELETE path=/api/pending_closures11472026/10/06 07:35:36 INFO Aborted multipart uploads count=1 kept=01148--- PASS: TestMultipartCleanup (0.74s)1149=== CONT TestCacheStatsHandler1150--- PASS: TestMetricsInventory (0.66s)1151=== CONT TestDeduplicatedObjectsRecordedAsPending11522026/10/06 07:35:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34575/oidc1153--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.13s)1154=== CONT TestCacheConfigHandler1155=== RUN TestCacheConfigHandler/full_config,_no_issuer1156=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1157=== RUN TestCacheConfigHandler/no_cache_url_configured1158=== PAUSE TestCacheConfigHandler/no_cache_url_configured1159=== RUN TestCacheConfigHandler/no_signing_keys1160=== PAUSE TestCacheConfigHandler/no_signing_keys1161=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1162=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1163=== CONT TestClientWithDependencies11642026/10/06 07:35:36 INFO Aborted multipart uploads count=0 kept=011652026/10/06 07:35:36 WARN Force mode enabled - objects will be deleted immediately without grace period11662026/10/06 07:35:36 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=011672026/10/06 07:35:36 INFO Vacuumed table table=pending_closures11682026/10/06 07:35:36 INFO Vacuumed table table=pending_objects11692026/10/06 07:35:36 INFO Vacuumed table table=multipart_uploads11702026/10/06 07:35:36 INFO Vacuumed table table=closures11712026/10/06 07:35:36 INFO Vacuumed table table=objects1172--- PASS: TestSweepRechecksPendingAfterLocking (0.69s)1173=== CONT TestPushDedupSurvivesConcurrentGC1174=== NAME TestOrphanedObjectsGC1175 orphaned_objects_gc_test.go:290: GC Test Summary:1176 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1177 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1178 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1179 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1180 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1181--- PASS: TestOrphanedObjectsGC (0.99s)1182=== CONT TestClientPushesUseOnePush1183=== NAME TestNARDeduplicationMetadataUploadBug1184 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1600209789/001/store/jxfw1r1gg5ffx3n9nqm1y2h2cqdnzjnn-file1.txt1185--- PASS: TestGetExistingObjectsLocksRows (0.66s)1186=== CONT TestPinProtectsFromGC1187--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.63s)1188=== CONT TestGCMetrics11892026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures11902026/10/06 07:35:36 INFO Received push request method=POST path=/api/pushes11912026/10/06 07:35:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11922026/10/06 07:35:36 INFO Uploading jxfw1r1gg5ffx3n9nqm1y2h2cqdnzjnn-file1.txt (160B)11932026/10/06 07:35:36 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11942026/10/06 07:35:36 WARN Failed to register uploaded object key=jxfw1r1gg5ffx3n9nqm1y2h2cqdnzjnn.ls error="server returned 404: 404 page not found\n"11952026/10/06 07:35:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11962026/10/06 07:35:36 INFO Signed narinfos id=1 count=111972026/10/06 07:35:36 INFO Uploading 1 narinfos11982026/10/06 07:35:36 INFO Received complete push request method=POST path=/api/pushes/1/complete11992026/10/06 07:35:36 WARN Failed to register uploaded object key=jxfw1r1gg5ffx3n9nqm1y2h2cqdnzjnn.narinfo error="server returned 404: 404 page not found\n"12002026/10/06 07:35:36 INFO Upload complete. (74ms)1201=== NAME TestNARDeduplicationMetadataUploadBug1202 metadata_upload_test.go:54: Retrieved narinfo from S3:1203 StorePath: /build/TestNARDeduplicationMetadataUploadBug1600209789/001/store/jxfw1r1gg5ffx3n9nqm1y2h2cqdnzjnn-file1.txt1204 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1205 Compression: zstd1206 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1207 NarSize: 1601208 References: 1209 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1210 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1211 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1212 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1213 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1600209789/001/store/xgk1xc5fj7ixyd8sf8b3icrwrhlddy9k-file2.txt12142026/10/06 07:35:36 INFO Aborted multipart uploads count=0 kept=012152026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures12162026/10/06 07:35:36 WARN Force mode enabled - objects will be deleted immediately without grace period12172026/10/06 07:35:36 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12182026/10/06 07:35:36 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1219--- PASS: TestFailedS3DeleteKeepsTombstone (0.65s)1220=== CONT TestClientSharedPathCommittedMidPush1221=== NAME TestClientCADerivations1222 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3303108706/001/store/1l6rhjbakzsd6pd3kwrc1sbzx2cahv36-ca-test12232026/10/06 07:35:36 INFO Received push request method=POST path=/api/pushes1224=== NAME TestClientMultipleUploads1225 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1730300758/001/store/5mcv9xpphy4ijd8qm92fm0l7rlp9kbk6-test-file-0.txt1226=== NAME TestClientCADerivations1227 client_ca_test.go:139: Found 1 dependencies (including self)12282026/10/06 07:35:36 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12292026/10/06 07:35:36 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12302026/10/06 07:35:36 WARN Failed to register uploaded object key=xgk1xc5fj7ixyd8sf8b3icrwrhlddy9k.ls error="server returned 404: 404 page not found\n"12312026/10/06 07:35:36 INFO Signed narinfos id=2 count=112322026/10/06 07:35:36 INFO Uploading 1 narinfos12332026/10/06 07:35:36 INFO Received complete push request method=POST path=/api/pushes/2/complete12342026/10/06 07:35:36 WARN Failed to register uploaded object key=xgk1xc5fj7ixyd8sf8b3icrwrhlddy9k.narinfo error="server returned 404: 404 page not found\n"12352026/10/06 07:35:36 INFO Upload complete. (58ms)1236=== NAME TestNARDeduplicationMetadataUploadBug1237 metadata_upload_test.go:76: Retrieved narinfo from S3:1238 StorePath: /build/TestNARDeduplicationMetadataUploadBug1600209789/001/store/xgk1xc5fj7ixyd8sf8b3icrwrhlddy9k-file2.txt1239 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1240 Compression: zstd1241 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1242 NarSize: 1601243 References: 1244 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1245 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1246 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1247 {"version":1,"root":{"type":"regular","size":44}}1248--- PASS: TestNARDeduplicationMetadataUploadBug (0.97s)1249=== CONT TestGCBugBareHashReferences1250=== NAME TestClientMultipleUploads1251 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1730300758/001/store/m11wa6rgrjvswj6pjpilwh9nlzyg4jqn-test-file-1.txt1252=== NAME TestClientIntegration1253 client_integration_test.go:286: Created store path: /build/TestClientIntegration1949723392/002/store/ybqz82jivmd88sad4w33mdjl1bdh8x9s-test-file.txt12542026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures12552026/10/06 07:35:36 INFO Aborted multipart uploads count=0 kept=012562026/10/06 07:35:36 WARN Force mode enabled - objects will be deleted immediately without grace period1257--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.46s)1258=== CONT TestLeadElectsOneAndHandsOver12592026/10/06 07:35:36 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=012602026/10/06 07:35:36 INFO Vacuumed table table=pending_closures12612026/10/06 07:35:36 INFO Vacuumed table table=pending_objects12622026/10/06 07:35:36 INFO Vacuumed table table=multipart_uploads12632026/10/06 07:35:36 INFO Vacuumed table table=closures12642026/10/06 07:35:36 INFO Vacuumed table table=objects12652026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures1266--- PASS: TestGCSweepDeliversEachKeyOnce (0.53s)1267=== CONT TestLeadIncumbentAnnouncesAtOnce1268=== NAME TestClientMultipleUploads1269 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1730300758/001/store/5bsj94ijcxgmim8g6w946sdywlvfwqxm-test-file-2.txt12702026/10/06 07:35:36 INFO Aborted multipart uploads count=0 kept=012712026/10/06 07:35:36 WARN Force mode enabled - objects will be deleted immediately without grace period12722026/10/06 07:35:36 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=012732026/10/06 07:35:36 INFO Vacuumed table table=pending_closures12742026/10/06 07:35:36 INFO Vacuumed table table=pending_objects12752026/10/06 07:35:36 INFO Vacuumed table table=multipart_uploads12762026/10/06 07:35:36 INFO Vacuumed table table=closures12772026/10/06 07:35:36 INFO Vacuumed table table=objects12782026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures1279--- PASS: TestCacheStatsHandler (0.43s)1280=== CONT TestConnectWaitsForAPeerMigration12812026/10/06 07:35:36 INFO Received push request method=POST path=/api/pushes12822026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures12832026/10/06 07:35:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12842026/10/06 07:35:36 INFO Uploading ybqz82jivmd88sad4w33mdjl1bdh8x9s-test-file.txt (152B)1285--- PASS: TestGCSweepSkipsPendingObjects (0.46s)12862026/10/06 07:35:36 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1287=== CONT TestGCAdvisoryLockBlocksConcurrentRun12882026/10/06 07:35:36 INFO Uploading qsgbmcjzj1h7j40wkljzylgmirc17bs4-a (216B)12892026/10/06 07:35:36 INFO Uploading 946g8p3k1gq2rw2n37xx3swqafbpb1qk-shared-dep (136B)12902026/10/06 07:35:36 INFO Received push request method=POST path=/api/pushes12912026/10/06 07:35:36 WARN Failed to register uploaded object key=0kxgfpy64m63ppf7lasphnya9a14rms2.ls error="server returned 404: 404 page not found\n"12922026/10/06 07:35:36 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12932026/10/06 07:35:36 WARN Failed to register uploaded object key=946g8p3k1gq2rw2n37xx3swqafbpb1qk.ls error="server returned 404: 404 page not found\n"12942026/10/06 07:35:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12952026/10/06 07:35:36 WARN Failed to register uploaded object key=ybqz82jivmd88sad4w33mdjl1bdh8x9s.ls error="server returned 404: 404 page not found\n"12962026/10/06 07:35:36 WARN Failed to register uploaded object key=qsgbmcjzj1h7j40wkljzylgmirc17bs4.ls error="server returned 404: 404 page not found\n"12972026/10/06 07:35:36 INFO Signed narinfos id=1 count=112982026/10/06 07:35:36 WARN Failed to register uploaded object key=nar/1hcj8b7d4p152fi5mzdsk7s6hssz52di31x12a37x40sbmgn8di6.nar.zst error="server returned 404: 404 page not found\n"12992026/10/06 07:35:36 INFO Uploading 1 narinfos1300--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.87s)13012026/10/06 07:35:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1302=== CONT TestResolveDBConnectionString13032026/10/06 07:35:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1304=== RUN TestResolveDBConnectionString/flag_wins13052026/10/06 07:35:36 INFO Signed narinfos id=1 count=21306=== PAUSE TestResolveDBConnectionString/flag_wins1307=== RUN TestResolveDBConnectionString/file_when_flag_empty1308=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1309=== RUN TestResolveDBConnectionString/missing_file_is_an_error1310=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error13112026/10/06 07:35:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1312=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1313=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1314=== RUN TestResolveDBConnectionString/nothing_configured1315=== PAUSE TestResolveDBConnectionString/nothing_configured1316=== CONT TestService_ReadScope_PublicByDefault13172026/10/06 07:35:36 INFO Signed narinfos id=2 count=213182026/10/06 07:35:36 INFO Uploading 4 narinfos13192026/10/06 07:35:36 INFO Received complete push request method=POST path=/api/pushes/1/complete13202026/10/06 07:35:36 WARN Failed to register uploaded object key=ybqz82jivmd88sad4w33mdjl1bdh8x9s.narinfo error="server returned 404: 404 page not found\n"13212026/10/06 07:35:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13222026/10/06 07:35:36 INFO Uploading 1l6rhjbakzsd6pd3kwrc1sbzx2cahv36-ca-test (144B)13232026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures13242026/10/06 07:35:36 WARN Failed to register uploaded object key=946g8p3k1gq2rw2n37xx3swqafbpb1qk.narinfo error="server returned 404: 404 page not found\n"13252026/10/06 07:35:36 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13262026/10/06 07:35:36 WARN Failed to register uploaded object key=946g8p3k1gq2rw2n37xx3swqafbpb1qk.narinfo error="server returned 404: 404 page not found\n"13272026/10/06 07:35:36 WARN Failed to register uploaded object key=qsgbmcjzj1h7j40wkljzylgmirc17bs4.narinfo error="server returned 404: 404 page not found\n"13282026/10/06 07:35:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13292026/10/06 07:35:36 WARN Failed to register uploaded object key=1l6rhjbakzsd6pd3kwrc1sbzx2cahv36.ls error="server returned 404: 404 page not found\n"13302026/10/06 07:35:36 WARN Failed to register uploaded object key=0kxgfpy64m63ppf7lasphnya9a14rms2.narinfo error="server returned 404: 404 page not found\n"13312026/10/06 07:35:36 WARN Failed to register uploaded object key=log/cdkdwpqb2glzq4hgqncnscm7n35lk32v-ca-test.drv error="server returned 404: 404 page not found\n"13322026/10/06 07:35:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13332026/10/06 07:35:36 INFO Signed narinfos id=1 count=113342026/10/06 07:35:36 INFO Uploading 1 narinfos13352026/10/06 07:35:36 INFO Upload complete. (63ms)1336--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.45s)1337=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13382026/10/06 07:35:36 INFO Received complete push request method=POST path=/api/pushes/1/complete13392026/10/06 07:35:36 WARN Failed to register uploaded object key=1l6rhjbakzsd6pd3kwrc1sbzx2cahv36.narinfo error="server returned 404: 404 page not found\n"1340--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.73s)1341=== CONT TestService_AuthMiddleware_OIDC13422026/10/06 07:35:36 INFO Received push request method=POST path=/api/pushes13432026/10/06 07:35:36 INFO Completed upload id=113442026/10/06 07:35:36 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13452026/10/06 07:35:36 INFO Upload complete. (122ms)1346=== NAME TestClientCADerivations13472026/10/06 07:35:36 INFO Completed upload id=21348 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3303108706/001/store/1l6rhjbakzsd6pd3kwrc1sbzx2cahv36-ca-test13492026/10/06 07:35:36 INFO Upload complete. (103ms)1350 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1351 Compression: zstd1352 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1353 NarSize: 1441354 References: 1355 Deriver: /build/TestClientCADerivations3303108706/001/store/cdkdwpqb2glzq4hgqncnscm7n35lk32v-ca-test.drv1356 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1357 client_ca_test.go:185: Checking for realisation files in S3...1358=== NAME TestClientFallsBackToClosures1359 client_pushes_test.go:112: Retrieved narinfo from S3:1360 StorePath: /build/TestClientFallsBackToClosures2409885384/001/store/946g8p3k1gq2rw2n37xx3swqafbpb1qk-shared-dep1361 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1362 Compression: zstd1363 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821364 NarSize: 1361365 References: 1366 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1367=== NAME TestClientCADerivations1368 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1369 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1370=== NAME TestClientFallsBackToClosures1371 client_pushes_test.go:112: Retrieved narinfo from S3:1372 StorePath: /build/TestClientFallsBackToClosures2409885384/001/store/qsgbmcjzj1h7j40wkljzylgmirc17bs4-a1373 URL: nar/1hcj8b7d4p152fi5mzdsk7s6hssz52di31x12a37x40sbmgn8di6.nar.zst1374 Compression: zstd1375 NarHash: sha256:1hcj8b7d4p152fi5mzdsk7s6hssz52di31x12a37x40sbmgn8di61376 NarSize: 2161377 References: /build/TestClientFallsBackToClosures2409885384/001/store/946g8p3k1gq2rw2n37xx3swqafbpb1qk-shared-dep1378 CA: text:sha256:17ac394hnxx2h8nyv287r95b0yn5zz6iy3r8bii6p6zi78866qzw1379 client_pushes_test.go:112: Retrieved narinfo from S3:1380 StorePath: /build/TestClientFallsBackToClosures2409885384/001/store/0kxgfpy64m63ppf7lasphnya9a14rms2-b1381 URL: nar/1hcj8b7d4p152fi5mzdsk7s6hssz52di31x12a37x40sbmgn8di6.nar.zst1382 Compression: zstd1383 NarHash: sha256:1hcj8b7d4p152fi5mzdsk7s6hssz52di31x12a37x40sbmgn8di61384 NarSize: 2161385 References: /build/TestClientFallsBackToClosures2409885384/001/store/946g8p3k1gq2rw2n37xx3swqafbpb1qk-shared-dep1386 CA: text:sha256:17ac394hnxx2h8nyv287r95b0yn5zz6iy3r8bii6p6zi78866qzw1387--- PASS: TestPushWaitsForSweepHoldingRow (1.17s)1388=== CONT TestService_ReadAuthMiddleware1389--- PASS: TestClientFallsBackToClosures (0.86s)1390=== CONT TestService_AuthMiddleware_MTLSProxyHeader1391=== RUN TestService_RequireScope_OIDC/builder_may_write1392=== PAUSE TestService_RequireScope_OIDC/builder_may_write1393=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1394=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1395=== RUN TestService_RequireScope_OIDC/ops_may_admin1396=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1397=== RUN TestService_RequireScope_OIDC/ops_may_not_write1398=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1399=== RUN TestService_RequireScope_OIDC/reader_may_not_write1400=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1401=== RUN TestService_RequireScope_OIDC/static_token_may_admin1402=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1403=== RUN TestService_RequireScope_OIDC/static_token_may_write1404=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1405=== RUN TestService_RequireScope_OIDC/reader_may_read1406=== PAUSE TestService_RequireScope_OIDC/reader_may_read1407=== RUN TestService_RequireScope_OIDC/writer_implies_read1408=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1409=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1410=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1411=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1412=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1413=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1414=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1415=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read14162026/10/06 07:35:36 INFO All 1 paths already cached1417=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1418=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1419=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1420=== CONT TestLeadEndsOnShutdown1421=== NAME TestClientIntegration1422 client_integration_test.go:312: Retrieved narinfo from S3:1423 StorePath: /build/TestClientIntegration1949723392/002/store/ybqz82jivmd88sad4w33mdjl1bdh8x9s-test-file.txt1424 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1425 Compression: zstd1426 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11427 NarSize: 1521428 References: 1429 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk114302026/10/06 07:35:36 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14312026/10/06 07:35:36 INFO Uploading 5bsj94ijcxgmim8g6w946sdywlvfwqxm-test-file-2.txt (160B)14322026/10/06 07:35:36 INFO Uploading 5mcv9xpphy4ijd8qm92fm0l7rlp9kbk6-test-file-0.txt (160B)14332026/10/06 07:35:36 INFO Uploading m11wa6rgrjvswj6pjpilwh9nlzyg4jqn-test-file-1.txt (160B)1434 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1435 client_integration_test.go:313: Decompressed .ls content (64 bytes):1436 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1437 client_integration_test.go:316: Testing garbage collection...14382026/10/06 07:35:36 WARN Failed to register uploaded object key=5bsj94ijcxgmim8g6w946sdywlvfwqxm.ls error="server returned 404: 404 page not found\n"14392026/10/06 07:35:36 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14402026/10/06 07:35:36 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14412026/10/06 07:35:36 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14422026/10/06 07:35:36 WARN Failed to register uploaded object key=m11wa6rgrjvswj6pjpilwh9nlzyg4jqn.ls error="server returned 404: 404 page not found\n"14432026/10/06 07:35:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14442026/10/06 07:35:36 WARN Failed to register uploaded object key=5mcv9xpphy4ijd8qm92fm0l7rlp9kbk6.ls error="server returned 404: 404 page not found\n"14452026/10/06 07:35:36 INFO Signed narinfos id=1 count=314462026/10/06 07:35:36 INFO Uploading 3 narinfos14472026/10/06 07:35:36 WARN Failed to register uploaded object key=m11wa6rgrjvswj6pjpilwh9nlzyg4jqn.narinfo error="server returned 404: 404 page not found\n"14482026/10/06 07:35:36 WARN Failed to register uploaded object key=5mcv9xpphy4ijd8qm92fm0l7rlp9kbk6.narinfo error="server returned 404: 404 page not found\n"14492026/10/06 07:35:36 INFO Received complete push request method=POST path=/api/pushes/1/complete14502026/10/06 07:35:36 WARN Failed to register uploaded object key=5bsj94ijcxgmim8g6w946sdywlvfwqxm.narinfo error="server returned 404: 404 page not found\n"14512026/10/06 07:35:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures14522026/10/06 07:35:36 INFO Garbage collection started14532026/10/06 07:35:36 INFO Upload complete. (123ms)1454=== NAME TestClientMultipleUploads1455 client_integration_test.go:369: Uploaded 3 paths in 158.122086ms14562026/10/06 07:35:36 INFO Aborted multipart uploads count=0 kept=01457--- PASS: TestClientMultipleUploads (0.82s)1458=== CONT TestParseSingleRange/none1459=== CONT TestParseSingleRange/suffix1460=== CONT TestParseSingleRange/malformed_end_before_start1461=== CONT TestParseSingleRange/end_clamped_to_size1462=== CONT TestParseSingleRange/open-ended1463=== CONT TestParseSingleRange/closed1464=== CONT TestParseSingleRange/malformed_no_dash1465=== CONT TestParseSingleRange/malformed_both_empty1466=== CONT TestParseSingleRange/multi-range_ignored1467=== CONT TestParseSingleRange/start_far_past_EOF1468=== CONT TestParseSingleRange/start_past_EOF1469=== CONT TestParseSingleRange/single_byte1470=== CONT TestParseSingleRange/suffix_exceeds_size1471=== CONT TestParseSingleRange/unknown_unit1472--- PASS: TestParseSingleRange (0.00s)1473 --- PASS: TestParseSingleRange/none (0.00s)1474 --- PASS: TestParseSingleRange/suffix (0.00s)1475 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1476 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1477 --- PASS: TestParseSingleRange/open-ended (0.00s)1478 --- PASS: TestParseSingleRange/closed (0.00s)1479 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1480 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1481 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1482 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1483 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1484 --- PASS: TestParseSingleRange/single_byte (0.00s)1485 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1486 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1487=== CONT TestProxyWriteTimeout/narinfo1488=== CONT TestProxyWriteTimeout/unknown_size1489=== CONT TestProxyWriteTimeout/10_GiB_nar1490=== CONT TestProxyWriteTimeout/1_GiB_nar1491--- PASS: TestProxyWriteTimeout (0.10s)1492 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1493 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1494 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1495 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1496=== CONT TestPendingClosureWriteTimeout/empty1497=== CONT TestPendingClosureWriteTimeout/670k_objects1498=== CONT TestPendingClosureWriteTimeout/400_objects1499=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15002026/10/06 07:35:36 WARN Force mode enabled - objects will be deleted immediately without grace period15012026/10/06 07:35:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45981/oidc15022026/10/06 07:35:36 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=015032026/10/06 07:35:36 INFO Received uploads request method=POST path=/api/pending_closures15042026/10/06 07:35:36 INFO Vacuumed table table=pending_closures15052026/10/06 07:35:36 INFO Vacuumed table table=pending_objects15062026/10/06 07:35:36 INFO Vacuumed table table=multipart_uploads15072026/10/06 07:35:36 INFO Vacuumed table table=closures1508=== NAME TestClientCADerivations1509 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1510 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1511 error: binary cache 's3://bucket57?endpoint=http://localhost:37115®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3303108706/001/store'1512 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 115132026/10/06 07:35:36 INFO Vacuumed table table=objects1514=== NAME TestClientWithDependencies1515 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1625436809/001/store/a4s22pbpghln88qddj02mhdl1l350204-test-script1516--- PASS: TestClientCADerivations (0.99s)1517=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15182026/10/06 07:35:36 INFO Received uploads request method=POST path=/1519=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15202026/10/06 07:35:36 INFO Received complete multipart upload request method=POST path=/1521=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15222026/10/06 07:35:36 INFO Received uploads request method=POST path=/1523=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15242026/10/06 07:35:36 INFO Received request for more parts method=POST path=/1525--- PASS: TestUploadHandlersRejectInvalidKeys (0.10s)1526 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1527 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1528 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1529 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1530=== CONT TestIsValidUploadKey/narinfo1531=== CONT TestIsValidUploadKey/realisation_plus_in_output1532=== CONT TestIsValidUploadKey/unknown_type1533=== CONT TestIsValidUploadKey/empty_key1534=== CONT TestIsValidUploadKey/absolute1535=== CONT TestIsValidUploadKey/traversal_nar1536=== CONT TestIsValidUploadKey/traversal1537=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1538=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1539=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1540=== CONT TestIsValidUploadKey/index.html1541=== CONT TestIsValidUploadKey/nix-cache-info1542=== CONT TestIsValidUploadKey/build_log_home-manager_file1543=== CONT TestIsValidUploadKey/realisation1544=== CONT TestIsValidUploadKey/build_log_equals1545=== CONT TestIsValidUploadKey/build_log_question_mark1546=== CONT TestIsValidUploadKey/build_log_plus_in_name1547=== CONT TestIsValidUploadKey/nar_plain1548=== CONT TestIsValidUploadKey/build_log1549=== CONT TestIsValidUploadKey/listing1550=== CONT TestIsValidUploadKey/nar_xz1551=== CONT TestIsValidUploadKey/nar_zst1552--- PASS: TestIsValidUploadKey (0.10s)1553 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1554 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1555 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1556 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1557 --- PASS: TestIsValidUploadKey/absolute (0.00s)1558 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1559 --- PASS: TestIsValidUploadKey/traversal (0.00s)1560 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1561 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1562 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1563 --- PASS: TestIsValidUploadKey/index.html (0.00s)1564 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1565 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1566 --- PASS: TestIsValidUploadKey/realisation (0.00s)1567 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1568 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1569 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1570 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1571 --- PASS: TestIsValidUploadKey/build_log (0.00s)1572 --- PASS: TestIsValidUploadKey/listing (0.00s)1573 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1574 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1575=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15762026/10/06 07:35:36 INFO Received uploads request method=POST path=/1577=== NAME TestClientWithDependencies1578 client_integration_test.go:615: Found 1 dependencies (including self)15792026/10/06 07:35:37 INFO Aborted multipart uploads count=0 kept=015802026/10/06 07:35:37 INFO Aborted multipart uploads count=0 kept=015812026/10/06 07:35:37 WARN Force mode enabled - objects will be deleted immediately without grace period15822026/10/06 07:35:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015832026/10/06 07:35:37 INFO Vacuumed table table=pending_closures15842026/10/06 07:35:37 INFO Vacuumed table table=pending_objects15852026/10/06 07:35:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015862026/10/06 07:35:37 INFO Vacuumed table table=multipart_uploads15872026/10/06 07:35:37 INFO Vacuumed table table=pending_closures15882026/10/06 07:35:37 INFO Vacuumed table table=closures15892026/10/06 07:35:37 INFO Vacuumed table table=pending_objects15902026/10/06 07:35:37 INFO Vacuumed table table=multipart_uploads15912026/10/06 07:35:37 INFO Vacuumed table table=closures15922026/10/06 07:35:37 INFO Vacuumed table table=objects15932026/10/06 07:35:37 INFO Vacuumed table table=objects15942026/10/06 07:35:37 INFO Aborted multipart uploads count=0 kept=015952026/10/06 07:35:37 WARN Force mode enabled - objects will be deleted immediately without grace period15962026/10/06 07:35:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015972026/10/06 07:35:37 INFO Vacuumed table table=pending_closures15982026/10/06 07:35:37 INFO Vacuumed table table=pending_objects15992026/10/06 07:35:37 INFO Vacuumed table table=multipart_uploads1600--- PASS: TestGCMetrics (0.57s)1601=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16022026/10/06 07:35:37 INFO Received request for more parts method=POST path=/16032026/10/06 07:35:37 INFO Vacuumed table table=closures16042026/10/06 07:35:37 INFO Vacuumed table table=objects1605--- PASS: TestPushDedupSurvivesConcurrentGC (0.63s)1606=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16072026/10/06 07:35:37 INFO Received complete multipart upload request method=POST path=/1608=== NAME TestPinProtectsFromGC1609 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1575805172/001/store/98s62c1ngkmcvdjf3f1qnagxwb6l5mzr-pinned-file.txt1610 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1575805172/001/store/2k0l6dipvl9wahvcq54w68w3wmdv3814-unpinned-file.txt16112026/10/06 07:35:37 INFO lead: acquired remote=192.0.2.1:12341612=== CONT TestPush_RejectsBadRequests/no_roots16132026/10/06 07:35:37 INFO Received push request method=POST path=/api/pushes1614=== CONT TestPush_RejectsBadRequests/bad_root16152026/10/06 07:35:37 INFO Received push request method=POST path=/api/pushes1616=== CONT TestPush_RejectsBadRequests/root_not_in_objects16172026/10/06 07:35:37 INFO Received push request method=POST path=/api/pushes1618=== CONT TestPush_RejectsBadRequests/no_objects16192026/10/06 07:35:37 INFO Received push request method=POST path=/api/pushes1620=== CONT TestIsValidCachePath/narinfo1621=== CONT TestIsValidCachePath/index.html1622=== CONT TestIsValidCachePath/short_hash1623=== CONT TestIsValidCachePath/wrong_extension1624=== CONT TestIsValidCachePath/leading_slash1625=== CONT TestIsValidCachePath/empty1626=== CONT TestIsValidCachePath/random_path1627=== CONT TestIsValidCachePath/invalid_char_u1628=== CONT TestIsValidCachePath/invalid_char_e1629=== CONT TestIsValidCachePath/traversal_in_middle1630--- PASS: TestPush_RejectsBadRequests (0.70s)1631 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1632 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1633 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1634 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1635=== CONT TestIsValidCachePath/traversal_parent1636=== CONT TestIsValidCachePath/nar_uncompressed1637=== CONT TestIsValidCachePath/nix-cache-info1638=== CONT TestIsValidCachePath/realisation1639=== CONT TestIsValidCachePath/log1640=== CONT TestIsValidCachePath/ls1641=== CONT TestIsValidCachePath/nar_xz1642=== CONT TestIsValidCachePath/nar_bz21643=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1644=== CONT TestIsValidCachePath/nar_zst1645=== CONT TestGCEndsOnShutdown/before_the_run1646--- PASS: TestIsValidCachePath (0.00s)1647 --- PASS: TestIsValidCachePath/narinfo (0.00s)1648 --- PASS: TestIsValidCachePath/index.html (0.00s)1649 --- PASS: TestIsValidCachePath/short_hash (0.00s)1650 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1651 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1652 --- PASS: TestIsValidCachePath/empty (0.00s)1653 --- PASS: TestIsValidCachePath/random_path (0.00s)1654 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1655 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1656 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1657 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1658 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1659 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1660 --- PASS: TestIsValidCachePath/realisation (0.00s)1661 --- PASS: TestIsValidCachePath/log (0.00s)1662 --- PASS: TestIsValidCachePath/ls (0.00s)1663 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1664 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1665 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1666 --- PASS: TestIsValidCachePath/nar_zst (0.00s)16672026/10/06 07:35:37 INFO Received push request method=POST path=/api/pushes1668=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16692026/10/06 07:35:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16702026/10/06 07:35:37 INFO Uploading a4s22pbpghln88qddj02mhdl1l350204-test-script (136B)16712026/10/06 07:35:37 WARN Failed to register uploaded object key=log/chniday9k9ll01ixk8i7rnyn53c1476f-test-script.drv error="server returned 404: 404 page not found\n"16722026/10/06 07:35:37 INFO lead: acquired remote=192.0.2.1:123416732026/10/06 07:35:37 INFO lead: released remote=192.0.2.1:12341674--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.36s)1675=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16762026/10/06 07:35:37 WARN Failed to register uploaded object key=a4s22pbpghln88qddj02mhdl1l350204.ls error="server returned 404: 404 page not found\n"16772026/10/06 07:35:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16782026/10/06 07:35:37 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16792026/10/06 07:35:37 INFO Signed narinfos id=1 count=116802026/10/06 07:35:37 INFO Uploading 1 narinfos16812026/10/06 07:35:37 INFO Received complete push request method=POST path=/api/pushes/1/complete16822026/10/06 07:35:37 WARN Failed to register uploaded object key=a4s22pbpghln88qddj02mhdl1l350204.narinfo error="server returned 404: 404 page not found\n"16832026/10/06 07:35:37 INFO Upload complete. (64ms)1684=== NAME TestClientWithDependencies1685 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1625436809/001/store) requires matching store prefix1686--- PASS: TestClientWithDependencies (0.74s)1687=== CONT TestServerTLSConfig/no_client_CA1688=== CONT TestServerTLSConfig/missing_CA_file1689=== CONT TestServerTLSConfig/not_a_PEM_file1690--- PASS: TestServerTLSConfig (0.00s)1691 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1692 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1693 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1694=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16952026/10/06 07:35:37 INFO Received push request method=POST path=/api/pushes16962026/10/06 07:35:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16972026/10/06 07:35:37 INFO Uploading 98s62c1ngkmcvdjf3f1qnagxwb6l5mzr-pinned-file.txt (128B)16982026/10/06 07:35:37 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1699--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.35s)1700=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17012026/10/06 07:35:37 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17022026/10/06 07:35:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17032026/10/06 07:35:37 WARN Failed to register uploaded object key=98s62c1ngkmcvdjf3f1qnagxwb6l5mzr.ls error="server returned 404: 404 page not found\n"17042026/10/06 07:35:37 INFO Signed narinfos id=1 count=117052026/10/06 07:35:37 INFO Uploading 1 narinfos17062026/10/06 07:35:37 INFO Received complete push request method=POST path=/api/pushes/1/complete17072026/10/06 07:35:37 WARN Failed to register uploaded object key=98s62c1ngkmcvdjf3f1qnagxwb6l5mzr.narinfo error="server returned 404: 404 page not found\n"17082026/10/06 07:35:37 INFO Received push request method=POST path=/api/pushes17092026/10/06 07:35:37 INFO Upload complete. (57ms)1710--- PASS: TestService_ReadScope_PublicByDefault (0.36s)1711=== CONT TestClientErrorHandling/InvalidStorePath17122026/10/06 07:35:37 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17132026/10/06 07:35:37 INFO Uploading y1jlcnqps4inna3g1sm1cns7lw7lcs1g-b (216B)17142026/10/06 07:35:37 INFO Uploading hl3772p2hjn0q07d72kph0i2qxqd1i44-shared-dep (136B)17152026/10/06 07:35:37 WARN Failed to register uploaded object key=8iayb0scv2lh695w0qch66915jrmlbwh.ls error="server returned 404: 404 page not found\n"17162026/10/06 07:35:37 WARN Failed to register uploaded object key=nar/1hcqv0npy1fclb11jfhxlvz36djakl0s6wsl84c18l77lcprd510.nar.zst error="server returned 404: 404 page not found\n"17172026/10/06 07:35:37 WARN Failed to register uploaded object key=y1jlcnqps4inna3g1sm1cns7lw7lcs1g.ls error="server returned 404: 404 page not found\n"17182026/10/06 07:35:37 WARN Failed to register uploaded object key=hl3772p2hjn0q07d72kph0i2qxqd1i44.ls error="server returned 404: 404 page not found\n"17192026/10/06 07:35:37 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17202026/10/06 07:35:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17212026/10/06 07:35:37 INFO Signed narinfos id=1 count=317222026/10/06 07:35:37 INFO Uploading 3 narinfos17232026/10/06 07:35:37 WARN Failed to register uploaded object key=y1jlcnqps4inna3g1sm1cns7lw7lcs1g.narinfo error="server returned 404: 404 page not found\n"17242026/10/06 07:35:37 WARN Failed to register uploaded object key=hl3772p2hjn0q07d72kph0i2qxqd1i44.narinfo error="server returned 404: 404 page not found\n"17252026/10/06 07:35:37 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17262026/10/06 07:35:37 WARN mTLS auth: bound subjects configured but subject DN unavailable17272026/10/06 07:35:37 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1728--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.37s)1729=== CONT TestClientErrorHandling/ServerNotAvailable17302026/10/06 07:35:37 INFO Received complete push request method=POST path=/api/pushes/1/complete17312026/10/06 07:35:37 WARN Failed to register uploaded object key=8iayb0scv2lh695w0qch66915jrmlbwh.narinfo error="server returned 404: 404 page not found\n"17322026/10/06 07:35:37 INFO Received push request method=POST path=/api/pushes17332026/10/06 07:35:37 INFO Upload complete. (84ms)1734=== NAME TestClientPushesUseOnePush1735 client_pushes_test.go:97: Retrieved narinfo from S3:1736 StorePath: /build/TestClientPushesUseOnePush3916993233/001/store/hl3772p2hjn0q07d72kph0i2qxqd1i44-shared-dep1737 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1738 Compression: zstd1739 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821740 NarSize: 1361741 References: 1742 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17432026/10/06 07:35:37 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17442026/10/06 07:35:37 INFO Uploading dl7wwqg1ivb36w1np6dqd5zp0x7zniph-shared-dep (136B)17452026/10/06 07:35:37 INFO Uploading 2q2vc5dwxbxbpsnm42r1yvxll195d26j-top (224B)1746 client_pushes_test.go:97: Retrieved narinfo from S3:1747 StorePath: /build/TestClientPushesUseOnePush3916993233/001/store/8iayb0scv2lh695w0qch66915jrmlbwh-a1748 URL: nar/1hcqv0npy1fclb11jfhxlvz36djakl0s6wsl84c18l77lcprd510.nar.zst1749 Compression: zstd1750 NarHash: sha256:1hcqv0npy1fclb11jfhxlvz36djakl0s6wsl84c18l77lcprd5101751 NarSize: 2161752 References: /build/TestClientPushesUseOnePush3916993233/001/store/hl3772p2hjn0q07d72kph0i2qxqd1i44-shared-dep1753 CA: text:sha256:0qm3n6vhhn2zf4bzqnvaxr72w52fnprzwzgrasqir6d0x8vns15517542026/10/06 07:35:37 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17552026/10/06 07:35:37 WARN Failed to register uploaded object key=dl7wwqg1ivb36w1np6dqd5zp0x7zniph.ls error="server returned 404: 404 page not found\n"1756 client_pushes_test.go:97: Retrieved narinfo from S3:1757 StorePath: /build/TestClientPushesUseOnePush3916993233/001/store/y1jlcnqps4inna3g1sm1cns7lw7lcs1g-b1758 URL: nar/1hcqv0npy1fclb11jfhxlvz36djakl0s6wsl84c18l77lcprd510.nar.zst1759 Compression: zstd1760 NarHash: sha256:1hcqv0npy1fclb11jfhxlvz36djakl0s6wsl84c18l77lcprd51017612026/10/06 07:35:37 WARN Failed to register uploaded object key=nar/1i7kc2c6giai7x67yh5w0jcvlkq2bl67daf9pzdal3l2angspzhq.nar.zst error="server returned 404: 404 page not found\n"1762 NarSize: 21617632026/10/06 07:35:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1764 References: /build/TestClientPushesUseOnePush3916993233/001/store/hl3772p2hjn0q07d72kph0i2qxqd1i44-shared-dep17652026/10/06 07:35:37 WARN Failed to register uploaded object key=2q2vc5dwxbxbpsnm42r1yvxll195d26j.ls error="server returned 404: 404 page not found\n"1766 CA: text:sha256:0qm3n6vhhn2zf4bzqnvaxr72w52fnprzwzgrasqir6d0x8vns15517672026/10/06 07:35:37 INFO Signed narinfos id=1 count=217682026/10/06 07:35:37 INFO Uploading 2 narinfos17692026/10/06 07:35:37 WARN Failed to register uploaded object key=2q2vc5dwxbxbpsnm42r1yvxll195d26j.narinfo error="server returned 404: 404 page not found\n"1770--- PASS: TestClientPushesUseOnePush (0.77s)1771=== CONT TestClientErrorHandling/InvalidAuthToken17722026/10/06 07:35:37 INFO Received complete push request method=POST path=/api/pushes/1/complete17732026/10/06 07:35:37 WARN Failed to register uploaded object key=dl7wwqg1ivb36w1np6dqd5zp0x7zniph.narinfo error="server returned 404: 404 page not found\n"1774--- PASS: TestService_ReadAuthMiddleware (0.35s)1775=== CONT TestCacheConfigHandler/full_config,_no_issuer1776=== CONT TestCacheConfigHandler/no_signing_keys1777=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1778=== CONT TestCacheConfigHandler/no_cache_url_configured1779=== CONT TestResolveDBConnectionString/flag_wins1780=== CONT TestResolveDBConnectionString/missing_file_is_an_error1781--- PASS: TestCacheConfigHandler (0.00s)1782 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1783 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1784 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1785 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1786=== CONT TestResolveDBConnectionString/file_when_flag_empty1787=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1788=== CONT TestResolveDBConnectionString/nothing_configured1789=== CONT TestService_RequireScope_OIDC/builder_may_write1790--- PASS: TestResolveDBConnectionString (0.00s)1791 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1792 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1793 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1794 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1795 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1796=== CONT TestService_RequireScope_OIDC/reader_may_read1797=== CONT TestService_RequireScope_OIDC/reader_may_not_write1798=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1799=== CONT TestService_RequireScope_OIDC/static_token_may_write1800=== CONT TestService_RequireScope_OIDC/static_token_may_admin1801=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18022026/10/06 07:35:37 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]1803=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1804=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1805=== CONT TestService_RequireScope_OIDC/writer_implies_read1806=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1807=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1808=== CONT TestService_RequireScope_OIDC/ops_may_admin1809=== CONT TestService_RequireScope_OIDC/ops_may_not_write1810--- PASS: TestService_RequireScope_OIDC (0.59s)1811 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1812 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1813 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1814 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1815 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1816 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1817 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1818 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1819 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1820 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1821 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1822 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1823 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1824 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)18252026/10/06 07:35:37 INFO Upload complete. (65ms)1826=== NAME TestClientSharedPathCommittedMidPush1827 client_integration_test.go:680: Retrieved narinfo from S3:1828 StorePath: /build/TestClientSharedPathCommittedMidPush420545580/001/store/dl7wwqg1ivb36w1np6dqd5zp0x7zniph-shared-dep1829 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1830 Compression: zstd1831 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821832 NarSize: 1361833 References: 1834 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18352026/10/06 07:35:37 INFO Received push request method=POST path=/api/pushes1836 client_integration_test.go:680: Retrieved narinfo from S3:1837 StorePath: /build/TestClientSharedPathCommittedMidPush420545580/001/store/2q2vc5dwxbxbpsnm42r1yvxll195d26j-top1838 URL: nar/1i7kc2c6giai7x67yh5w0jcvlkq2bl67daf9pzdal3l2angspzhq.nar.zst1839 Compression: zstd1840 NarHash: sha256:1i7kc2c6giai7x67yh5w0jcvlkq2bl67daf9pzdal3l2angspzhq1841 NarSize: 2241842 References: /build/TestClientSharedPathCommittedMidPush420545580/001/store/dl7wwqg1ivb36w1np6dqd5zp0x7zniph-shared-dep1843 CA: text:sha256:0jxqhg0254n2g0j4cy3p1wrxjiv9lxpiy1dx2971s7a68m8934ns18442026/10/06 07:35:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18452026/10/06 07:35:37 INFO Uploading 2k0l6dipvl9wahvcq54w68w3wmdv3814-unpinned-file.txt (128B)1846--- PASS: TestClientSharedPathCommittedMidPush (0.59s)18472026/10/06 07:35:37 WARN Failed to register uploaded object key=2k0l6dipvl9wahvcq54w68w3wmdv3814.ls error="server returned 404: 404 page not found\n"18482026/10/06 07:35:37 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18492026/10/06 07:35:37 INFO Signed narinfos id=2 count=118502026/10/06 07:35:37 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18512026/10/06 07:35:37 INFO Uploading 1 narinfos18522026/10/06 07:35:37 INFO Received complete push request method=POST path=/api/pushes/2/complete18532026/10/06 07:35:37 WARN Failed to register uploaded object key=2k0l6dipvl9wahvcq54w68w3wmdv3814.narinfo error="server returned 404: 404 page not found\n"18542026/10/06 07:35:37 INFO lead: acquired remote=192.0.2.1:123418552026/10/06 07:35:37 INFO Upload complete. (53ms)18562026/10/06 07:35:37 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/present1857--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.40s)18582026/10/06 07:35:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures18592026/10/06 07:35:37 INFO Garbage collection started18602026/10/06 07:35:37 INFO Received uploads request method=POST path=/api/pending_closures18612026/10/06 07:35:37 INFO Aborted multipart uploads count=0 kept=01862--- PASS: TestGCBugBareHashReferences (0.57s)18632026/10/06 07:35:37 WARN Force mode enabled - objects will be deleted immediately without grace period18642026/10/06 07:35:37 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=018652026/10/06 07:35:37 INFO Vacuumed table table=pending_closures18662026/10/06 07:35:37 INFO Vacuumed table table=pending_objects18672026/10/06 07:35:37 INFO Vacuumed table table=multipart_uploads1868=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1869=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1870=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1871=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1872=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1873=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1874=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1875=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1876=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1877=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1878=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured18792026/10/06 07:35:37 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]1880=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18812026/10/06 07:35:37 INFO Vacuumed table table=closures18822026/10/06 07:35:37 WARN Authentication failed token_preview=eyJhbGciOi...-eK5ECuwxQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]18832026/10/06 07:35:37 INFO Vacuumed table table=objects1884--- PASS: TestService_AuthMiddleware_OIDC (0.48s)1885 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1886 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1887 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1888 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)18892026/10/06 07:35:37 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.711593ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18902026/10/06 07:35:37 INFO Aborted multipart uploads count=0 kept=018912026/10/06 07:35:37 WARN Force mode enabled - objects will be deleted immediately without grace period18922026/10/06 07:35:37 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37115/bucket86/?delete=\": context canceled"18932026/10/06 07:35:37 INFO Aborted multipart uploads count=0 kept=018942026/10/06 07:35:37 WARN Force mode enabled - objects will be deleted immediately without grace period18952026-10-06 07:35:37.527 UTC [2017] ERROR: canceling statement due to user request18962026-10-06 07:35:37.527 UTC [2017] CONTEXT: SQL statement "UPDATE object_stats1897 SET object_count = object_count + d_count,1898 total_bytes = total_bytes + d_bytes1899 WHERE id"1900 PL/pgSQL function object_stats_apply() line 17 at SQL statement19012026-10-06 07:35:37.527 UTC [2017] STATEMENT: -- name: MarkStaleObjects :execrows1902 WITH RECURSIVE ct AS (1903 SELECT timezone('UTC', now()) AS now1904 ),1905 closure_reach AS (1906 -- Start with all closure keys1907 SELECT o.key, o.refs1908 FROM objects o1909 INNER JOIN closures c ON o.key = c.key1910 UNION1911 -- Recursively add all referenced objects1912 SELECT o.key, o.refs1913 FROM objects o1914 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1915 ),1916 reachable_objects AS (1917 SELECT DISTINCT key FROM closure_reach1918 ),1919 stale_objects AS (1920 SELECT o.key1921 FROM objects AS o, ct1922 WHERE1923 NOT EXISTS (1924 SELECT 11925 FROM reachable_objects ro1926 WHERE ro.key = o.key1927 )1928 AND NOT EXISTS (1929 SELECT 11930 FROM pending_objects AS po1931 WHERE po.key = o.key1932 )1933 AND o.deleted_at IS NULL -- Only mark fresh objects1934 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1935 FOR UPDATE1936 )1937 UPDATE objects1938 SET1939 deleted_at = ct.now,1940 first_deleted_at = COALESCE(first_deleted_at, ct.now)1941 FROM stale_objects, ct1942 WHERE objects.key = stale_objects.key1943 1944--- PASS: TestGCEndsOnShutdown (0.00s)1945 --- PASS: TestGCEndsOnShutdown/before_the_run (0.36s)1946 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.39s)1947 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.43s)19482026/10/06 07:35:37 INFO Received uploads request method=POST path=/api/pending_closures19492026/10/06 07:35:37 INFO Aborted multipart uploads count=0 kept=019502026/10/06 07:35:37 WARN Force mode enabled - objects will be deleted immediately without grace period19512026/10/06 07:35:37 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=019522026/10/06 07:35:37 INFO Vacuumed table table=pending_closures19532026/10/06 07:35:37 INFO Vacuumed table table=pending_objects19542026/10/06 07:35:37 INFO Vacuumed table table=multipart_uploads19552026/10/06 07:35:37 INFO Vacuumed table table=closures19562026/10/06 07:35:37 INFO Vacuumed table table=objects19572026/10/06 07:35:37 INFO Received uploads request method=POST path=/api/pending_closures19582026/10/06 07:35:37 INFO Aborted multipart uploads count=0 kept=019592026/10/06 07:35:37 WARN Force mode enabled - objects will be deleted immediately without grace period19602026/10/06 07:35:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019612026/10/06 07:35:37 INFO Vacuumed table table=pending_closures19622026/10/06 07:35:37 INFO Vacuumed table table=pending_objects19632026/10/06 07:35:37 INFO Vacuumed table table=multipart_uploads19642026/10/06 07:35:37 INFO Vacuumed table table=closures19652026/10/06 07:35:37 INFO Vacuumed table table=objects1966--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1967 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.45s)1968 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.45s)19692026/10/06 07:35:37 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.982761ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19702026/10/06 07:35:37 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19712026/10/06 07:35:37 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1972=== NAME TestOrphanedObjectsGCStressTest1973 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1974--- PASS: TestUploadHandlersRejectOversizedBody (0.21s)1975 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)1976 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)1977 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.80s)1978=== NAME TestOrphanedObjectsGCStressTest1979 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19802026/10/06 07:35:38 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=776.808368ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1981--- PASS: TestPendingClosureWriteTimeout (0.10s)1982 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1983 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1984 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1985 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.17s)1986=== NAME TestOrphanedObjectsGCStressTest1987 orphaned_objects_gc_test.go:509: Stress test completed successfully:1988 orphaned_objects_gc_test.go:510: - Active objects preserved: 201989 orphaned_objects_gc_test.go:511: - Objects deleted: 2101990 orphaned_objects_gc_test.go:512: - Total GC'd: 2101991--- PASS: TestOrphanedObjectsGCStressTest (2.73s)19922026/10/06 07:35:38 INFO lead: released remote=192.0.2.1:12341993--- PASS: TestLeadEndsOnShutdown (1.41s)19942026/10/06 07:35:38 INFO lead: released remote=192.0.2.1:123419952026/10/06 07:35:38 INFO lead: acquired remote=192.0.2.1:123419962026/10/06 07:35:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.591588661s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19972026/10/06 07:35:38 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01998=== NAME TestClientIntegration1999 client_integration_test.go:323: Objects in database after GC:2000 client_integration_test.go:323: Successfully deleted all objects with GC --force2001--- PASS: TestClientIntegration (2.77s)20022026/10/06 07:35:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020032026/10/06 07:35:39 INFO Received create pin request method=POST path=/api/pins/myapp20042026/10/06 07:35:39 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1575805172/001/store/98s62c1ngkmcvdjf3f1qnagxwb6l5mzr-pinned-file.txt narinfo_key=98s62c1ngkmcvdjf3f1qnagxwb6l5mzr.narinfo20052026/10/06 07:35:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures20062026/10/06 07:35:39 INFO Garbage collection started20072026/10/06 07:35:39 INFO Aborted multipart uploads count=0 kept=020082026/10/06 07:35:39 WARN Force mode enabled - objects will be deleted immediately without grace period20092026/10/06 07:35:39 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=020102026/10/06 07:35:39 INFO Vacuumed table table=pending_closures20112026/10/06 07:35:39 INFO Vacuumed table table=pending_objects20122026/10/06 07:35:39 INFO Vacuumed table table=multipart_uploads20132026/10/06 07:35:39 INFO Vacuumed table table=closures20142026/10/06 07:35:39 INFO Vacuumed table table=objects20152026/10/06 07:35:39 WARN Rate limiter enabled after throttle name=s3-test rate=520162026/10/06 07:35:39 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2017=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2018 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102019 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002020--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.92s)20212026/10/06 07:35:39 INFO lead: released remote=192.0.2.1:12342022--- PASS: TestLeadElectsOneAndHandsOver (2.71s)2023--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.90s)20242026/10/06 07:35:40 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-config20252026/10/06 07:35:40 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.494088ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20262026/10/06 07:35:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=434.341032ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20272026/10/06 07:35:41 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=826.093519ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2028=== NAME TestPinProtectsFromGC2029 client_integration_test.go:840: Pin successfully protected closure from garbage collection2030--- PASS: TestPinProtectsFromGC (4.83s)2031--- PASS: TestConnectWaitsForAPeerMigration (5.20s)20322026/10/06 07:35:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.620802789s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20332026/10/06 07:35:42 INFO Aborted multipart uploads count=1 kept=020342026/10/06 07:35:42 INFO Received cleanup request method=DELETE path=/api/pending_closures20352026/10/06 07:35:42 INFO Aborted multipart uploads count=1 kept=02036--- PASS: TestPendingCleanupUsesOneCutoff (6.74s)20372026/10/06 07:35:43 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"20382026/10/06 07:35:43 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20392026/10/06 07:35:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.074139ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20402026/10/06 07:35:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=438.600564ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20412026/10/06 07:35:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=856.126428ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20422026/10/06 07:35:45 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.514499262s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20432026/10/06 07:35:46 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20442026/10/06 07:35:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.703376ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20452026/10/06 07:35:47 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=365.837865ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20462026/10/06 07:35:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=866.945215ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20472026/10/06 07:35:48 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.586735467s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2048--- PASS: TestClientErrorHandling (0.00s)2049 --- PASS: TestClientErrorHandling/InvalidStorePath (0.46s)2050 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.52s)2051 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.69s)2052PASS20532026-10-06 07:35:50.213 UTC [130] LOG: received smart shutdown request20542026-10-06 07:35:50.220 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 120552026-10-06 07:35:50.231 UTC [135] LOG: shutting down20562026-10-06 07:35:50.232 UTC [135] LOG: checkpoint starting: shutdown immediate20572026-10-06 07:35:52.196 UTC [135] LOG: checkpoint complete: wrote 11010 buffers (67.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.280 s, sync=1.629 s, total=1.965 s; sync files=31000, longest=0.003 s, average=0.001 s; distance=428489 kB, estimate=428489 kB; lsn=0/1B9D8168, redo lsn=0/1B9D816820582026-10-06 07:35:52.283 UTC [130] LOG: database system is shut down2059Running OIDC tests...2060=== RUN TestAudienceForIssuer2061=== PAUSE TestAudienceForIssuer2062=== RUN TestGlobMatch2063=== PAUSE TestGlobMatch2064=== RUN TestValidateToken_ValidToken2065=== PAUSE TestValidateToken_ValidToken2066=== RUN TestValidateToken_WrongAudience2067=== PAUSE TestValidateToken_WrongAudience2068=== RUN TestValidateToken_Expired2069=== PAUSE TestValidateToken_Expired2070=== RUN TestValidateToken_BoundClaimsMismatch2071=== PAUSE TestValidateToken_BoundClaimsMismatch2072=== RUN TestValidateToken_BoundSubjectMismatch2073=== PAUSE TestValidateToken_BoundSubjectMismatch2074=== RUN TestValidateToken_MultipleProviders2075=== PAUSE TestValidateToken_MultipleProviders2076=== RUN TestValidateToken_NoMatchingProvider2077=== PAUSE TestValidateToken_NoMatchingProvider2078=== RUN TestValidateToken_KubernetesServiceAccount2079=== PAUSE TestValidateToken_KubernetesServiceAccount2080=== RUN TestNewValidator_KubernetesRequiresCA2081=== PAUSE TestNewValidator_KubernetesRequiresCA2082=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2083=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2084=== RUN TestPins_ReservedForMatchingRule2085=== PAUSE TestPins_ReservedForMatchingRule2086=== RUN TestPins_TopLevelShorthand2087=== PAUSE TestPins_TopLevelShorthand2088=== RUN TestPins_ConfigValidation2089=== PAUSE TestPins_ConfigValidation2090=== RUN TestScopes_LegacyProviderDefaultsToWrite2091=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2092=== RUN TestScopes_Rules2093=== PAUSE TestScopes_Rules2094=== RUN TestScopes_ConfigValidation2095=== PAUSE TestScopes_ConfigValidation2096=== CONT TestAudienceForIssuer2097=== CONT TestValidateToken_KubernetesServiceAccount2098=== CONT TestPins_ConfigValidation2099=== CONT TestScopes_LegacyProviderDefaultsToWrite2100--- PASS: TestAudienceForIssuer (0.00s)2101=== CONT TestScopes_ConfigValidation2102=== CONT TestValidateToken_NoMatchingProvider2103=== CONT TestValidateToken_MultipleProviders2104=== CONT TestValidateToken_BoundSubjectMismatch2105=== CONT TestValidateToken_BoundClaimsMismatch2106=== CONT TestValidateToken_Expired2107=== CONT TestValidateToken_WrongAudience2108=== CONT TestPins_ReservedForMatchingRule2109=== CONT TestValidateToken_ValidToken2110=== CONT TestPins_TopLevelShorthand2111=== CONT TestGlobMatch2112=== RUN TestGlobMatch/foo_foo2113=== PAUSE TestGlobMatch/foo_foo2114=== RUN TestGlobMatch/foo_bar2115=== PAUSE TestGlobMatch/foo_bar2116=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2117=== CONT TestNewValidator_KubernetesRequiresCA2118=== CONT TestScopes_Rules2119--- PASS: TestPins_ConfigValidation (0.00s)2120--- PASS: TestScopes_ConfigValidation (0.00s)2121=== RUN TestGlobMatch/*_2122=== PAUSE TestGlobMatch/*_2123=== RUN TestGlobMatch/*_anything2124=== PAUSE TestGlobMatch/*_anything2125=== RUN TestGlobMatch/foo*_foo2126=== PAUSE TestGlobMatch/foo*_foo2127=== RUN TestGlobMatch/foo*_foobar2128=== PAUSE TestGlobMatch/foo*_foobar2129=== RUN TestGlobMatch/foo*_bar2130=== PAUSE TestGlobMatch/foo*_bar2131=== RUN TestGlobMatch/*bar_bar2132=== PAUSE TestGlobMatch/*bar_bar2133=== RUN TestGlobMatch/*bar_foobar2134=== PAUSE TestGlobMatch/*bar_foobar2135=== RUN TestGlobMatch/*bar_foo2136=== PAUSE TestGlobMatch/*bar_foo2137=== RUN TestGlobMatch/foo*bar_foobar2138=== PAUSE TestGlobMatch/foo*bar_foobar2139=== RUN TestGlobMatch/foo*bar_foo123bar2140=== PAUSE TestGlobMatch/foo*bar_foo123bar2141=== RUN TestGlobMatch/foo*bar_foobarbaz2142=== PAUSE TestGlobMatch/foo*bar_foobarbaz2143=== RUN TestGlobMatch/*/*_foo/bar2144=== PAUSE TestGlobMatch/*/*_foo/bar2145=== RUN TestGlobMatch/*/*_foo2146=== PAUSE TestGlobMatch/*/*_foo2147=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2148=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2149=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02150=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02151=== RUN TestGlobMatch/refs/*/main_refs/heads/main2152=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2153=== RUN TestGlobMatch/fo?_foo2154=== PAUSE TestGlobMatch/fo?_foo2155=== RUN TestGlobMatch/fo?_fo2156=== PAUSE TestGlobMatch/fo?_fo2157=== RUN TestGlobMatch/fo?_fooo2158=== PAUSE TestGlobMatch/fo?_fooo2159=== RUN TestGlobMatch/?oo_foo2160=== PAUSE TestGlobMatch/?oo_foo2161=== RUN TestGlobMatch/?oo_boo2162=== PAUSE TestGlobMatch/?oo_boo2163=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2164=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2165=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2166=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2167=== CONT TestGlobMatch/foo_foo2168=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2169=== CONT TestGlobMatch/?oo_foo2170=== CONT TestGlobMatch/foo*bar_foobarbaz2171=== CONT TestGlobMatch/refs/*/main_refs/heads/main2172=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02173=== CONT TestGlobMatch/foo*bar_foo123bar2174=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2175=== CONT TestGlobMatch/*/*_foo2176=== CONT TestGlobMatch/fo?_foo2177=== CONT TestGlobMatch/*/*_foo/bar2178=== CONT TestGlobMatch/*bar_bar2179=== CONT TestGlobMatch/foo*_foobar2180=== CONT TestGlobMatch/fo?_fo2181=== CONT TestGlobMatch/fo?_fooo2182=== CONT TestGlobMatch/?oo_boo2183=== CONT TestGlobMatch/foo*_bar2184=== CONT TestGlobMatch/*bar_foo2185=== CONT TestGlobMatch/foo*bar_foobar2186=== CONT TestGlobMatch/*bar_foobar2187=== CONT TestGlobMatch/*_anything2188=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2189=== CONT TestGlobMatch/foo*_foo2190=== CONT TestGlobMatch/*_2191=== CONT TestGlobMatch/foo_bar2192--- PASS: TestGlobMatch (0.00s)2193 --- PASS: TestGlobMatch/foo_foo (0.00s)2194 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2195 --- PASS: TestGlobMatch/?oo_foo (0.00s)2196 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2197 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2198 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2199 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2200 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2201 --- PASS: TestGlobMatch/*/*_foo (0.00s)2202 --- PASS: TestGlobMatch/fo?_foo (0.00s)2203 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2204 --- PASS: TestGlobMatch/*bar_bar (0.00s)2205 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2206 --- PASS: TestGlobMatch/fo?_fo (0.00s)2207 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2208 --- PASS: TestGlobMatch/?oo_boo (0.00s)2209 --- PASS: TestGlobMatch/*bar_foo (0.00s)2210 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2211 --- PASS: TestGlobMatch/foo*_bar (0.00s)2212 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2213 --- PASS: TestGlobMatch/*_anything (0.00s)2214 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2215 --- PASS: TestGlobMatch/foo*_foo (0.00s)2216 --- PASS: TestGlobMatch/*_ (0.00s)2217 --- PASS: TestGlobMatch/foo_bar (0.00s)22182026/10/06 07:35:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40619/oidc2219--- PASS: TestValidateToken_ValidToken (0.02s)22202026/10/06 07:35:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36623/oidc2221--- PASS: TestPins_ReservedForMatchingRule (0.03s)22222026/10/06 07:35:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39683/oidc2223--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)22242026/10/06 07:35:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45335/oidc22252026/10/06 07:35:54 http: TLS handshake error from 127.0.0.1:35636: remote error: tls: bad certificate2226--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)2227--- PASS: TestValidateToken_WrongAudience (0.04s)22282026/10/06 07:35:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42613/oidc2229--- PASS: TestScopes_Rules (0.05s)22302026/10/06 07:35:54 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:447472231--- PASS: TestValidateToken_KubernetesServiceAccount (0.06s)22322026/10/06 07:35:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43147/oidc22332026/10/06 07:35:54 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34209/oidc22342026/10/06 07:35:54 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34341/oidc22352026/10/06 07:35:54 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232236--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)2237--- PASS: TestValidateToken_MultipleProviders (0.08s)2238--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)22392026/10/06 07:35:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36147/oidc2240--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.10s)22412026/10/06 07:35:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35941/oidc2242--- PASS: TestValidateToken_Expired (0.11s)22432026/10/06 07:35:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42815/oidc2244--- PASS: TestPins_TopLevelShorthand (0.11s)22452026/10/06 07:35:54 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41317/oidc2246--- PASS: TestValidateToken_NoMatchingProvider (0.12s)2247PASS2248Running hook tests...2249=== RUN TestSendPathsEmpty2250=== PAUSE TestSendPathsEmpty2251=== RUN TestQueueEnqueueAndFetch2252=== PAUSE TestQueueEnqueueAndFetch2253=== RUN TestQueueDeduplication2254=== PAUSE TestQueueDeduplication2255=== RUN TestQueueRemove2256=== PAUSE TestQueueRemove2257=== RUN TestQueueFetchBatchLimit2258=== PAUSE TestQueueFetchBatchLimit2259=== RUN TestQueueRetryMovesToBack2260=== PAUSE TestQueueRetryMovesToBack2261=== RUN TestQueueFetchRemoveLifecycle2262=== PAUSE TestQueueFetchRemoveLifecycle2263=== RUN TestQueueConcurrentWriters2264=== PAUSE TestQueueConcurrentWriters2265=== RUN TestQueueRemoveLargeClosure2266=== PAUSE TestQueueRemoveLargeClosure2267=== RUN TestServerClientIntegration2268=== PAUSE TestServerClientIntegration2269=== RUN TestServerQueueError2270=== PAUSE TestServerQueueError2271=== RUN TestGetListenerSocketActivation2272 server_test.go:210: === RUN TestGetListenerSocketActivation2273 --- PASS: TestGetListenerSocketActivation (0.00s)2274 PASS2275 2276--- PASS: TestGetListenerSocketActivation (0.01s)2277=== RUN TestDrainIsolatesPoisonPath2278=== PAUSE TestDrainIsolatesPoisonPath2279=== RUN TestRunNotBlockedByPoisonHead2280=== PAUSE TestRunNotBlockedByPoisonHead2281=== RUN TestDrainGivesUpWhenServerDown2282=== PAUSE TestDrainGivesUpWhenServerDown2283=== RUN TestFailedPathPrunedByLaterClosure2284=== PAUSE TestFailedPathPrunedByLaterClosure2285=== RUN TestWorkerUploadsAndRemoves2286=== PAUSE TestWorkerUploadsAndRemoves2287=== RUN TestWorkerSkipsGCdPaths2288=== PAUSE TestWorkerSkipsGCdPaths2289=== RUN TestWorkerPrunesClosureDeps2290=== PAUSE TestWorkerPrunesClosureDeps2291=== RUN TestDrainTimeout2292=== PAUSE TestDrainTimeout2293=== CONT TestSendPathsEmpty2294=== CONT TestServerQueueError2295--- PASS: TestSendPathsEmpty (0.00s)2296=== CONT TestQueueFetchBatchLimit2297=== CONT TestQueueRemove2298=== CONT TestQueueDeduplication2299=== CONT TestQueueEnqueueAndFetch2300=== CONT TestQueueRemoveLargeClosure2301=== CONT TestServerClientIntegration23022026/10/06 07:35:54 ERROR Failed to queue paths error="permission denied" count=12303=== CONT TestWorkerPrunesClosureDeps2304=== CONT TestDrainTimeout2305=== CONT TestQueueConcurrentWriters2306--- PASS: TestServerQueueError (0.00s)2307=== CONT TestWorkerSkipsGCdPaths2308=== CONT TestDrainGivesUpWhenServerDown2309=== CONT TestFailedPathPrunedByLaterClosure2310=== CONT TestQueueFetchRemoveLifecycle2311=== CONT TestRunNotBlockedByPoisonHead2312=== CONT TestDrainIsolatesPoisonPath2313=== CONT TestWorkerUploadsAndRemoves2314=== CONT TestQueueRetryMovesToBack2315--- PASS: TestServerClientIntegration (0.00s)23162026/10/06 07:35:54 INFO Uploading batch count=223172026/10/06 07:35:54 INFO Upload queue status pending=223182026/10/06 07:35:54 INFO Uploading batch count=223192026/10/06 07:35:54 INFO Upload queue status pending=323202026/10/06 07:35:54 INFO Uploading batch count=423212026/10/06 07:35:54 ERROR Upload failed error="upload failed" count=423222026/10/06 07:35:54 INFO Uploading batch count=123232026/10/06 07:35:54 ERROR Upload failed error="upload failed" count=12324--- PASS: TestQueueEnqueueAndFetch (0.02s)23252026/10/06 07:35:54 INFO Upload queue status pending=223262026/10/06 07:35:54 INFO Uploading batch count=223272026/10/06 07:35:54 ERROR Upload failed error="upload failed" count=223282026/10/06 07:35:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1395213736/002/a23292026/10/06 07:35:54 INFO Uploading batch count=123302026/10/06 07:35:54 ERROR Upload failed error="upload failed" count=123312026/10/06 07:35:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1998200009/002/nonexistent23322026/10/06 07:35:54 INFO Upload queue status pending=223332026/10/06 07:35:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3625287930/002/bbb23342026/10/06 07:35:54 INFO Uploading batch count=12335--- PASS: TestQueueDeduplication (0.02s)2336--- PASS: TestQueueRetryMovesToBack (0.02s)23372026/10/06 07:35:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1395213736/002/b23382026/10/06 07:35:54 INFO Uploading batch count=12339--- PASS: TestQueueRemove (0.02s)23402026/10/06 07:35:54 INFO Uploading batch count=12341--- PASS: TestQueueFetchBatchLimit (0.02s)23422026/10/06 07:35:54 INFO Uploading batch count=123432026/10/06 07:35:54 INFO Uploading batch count=223442026/10/06 07:35:54 ERROR Upload failed error="upload failed" count=22345--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23462026/10/06 07:35:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1395213736/002/c23472026/10/06 07:35:54 INFO Uploading batch count=123482026/10/06 07:35:54 ERROR Upload failed error="upload failed" count=123492026/10/06 07:35:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1395213736/002/d23502026/10/06 07:35:54 INFO Uploading batch count=123512026/10/06 07:35:54 ERROR Upload failed error="upload failed" count=123522026/10/06 07:35:54 INFO Uploading batch count=22353--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23542026/10/06 07:35:54 ERROR Upload failed error="upload failed" count=223552026/10/06 07:35:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1395213736/002/e23562026/10/06 07:35:54 INFO Uploading batch count=123572026/10/06 07:35:54 ERROR Upload failed error="upload failed" count=123582026/10/06 07:35:54 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1395213736/002/f23592026/10/06 07:35:54 ERROR Drain finished with paths left in queue remaining=123602026/10/06 07:35:54 ERROR Drain finished with paths left in queue remaining=102361--- PASS: TestDrainIsolatesPoisonPath (0.03s)2362--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2363--- PASS: TestWorkerUploadsAndRemoves (0.04s)2364--- PASS: TestWorkerSkipsGCdPaths (0.04s)2365--- PASS: TestWorkerPrunesClosureDeps (0.04s)2366--- PASS: TestQueueRemoveLargeClosure (0.09s)23672026/10/06 07:35:54 ERROR Upload failed error="context deadline exceeded" count=223682026/10/06 07:35:54 ERROR Drain finished with paths left in queue remaining=42369--- PASS: TestDrainTimeout (0.22s)2370--- PASS: TestQueueConcurrentWriters (0.27s)23712026/10/06 07:35:55 INFO Uploading batch count=123722026/10/06 07:35:55 INFO Uploading batch count=123732026/10/06 07:35:55 INFO Uploading batch count=123742026/10/06 07:35:55 ERROR Upload failed error="upload failed" count=123752026/10/06 07:35:55 INFO Uploading batch count=123762026/10/06 07:35:55 ERROR Upload failed error="upload failed" count=123772026/10/06 07:35:55 INFO Uploading batch count=123782026/10/06 07:35:55 ERROR Upload failed error="upload failed" count=123792026/10/06 07:35:55 INFO Uploading batch count=123802026/10/06 07:35:55 ERROR Upload failed error="upload failed" count=123812026/10/06 07:35:55 ERROR Drain finished with paths left in queue remaining=12382--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2383PASS2384Running signing tests...2385=== RUN TestExternalSigner2386=== PAUSE TestExternalSigner2387=== RUN TestExternalSignerWrongPublicKey2388=== PAUSE TestExternalSignerWrongPublicKey2389=== RUN TestExternalSignerErrors2390=== PAUSE TestExternalSignerErrors2391=== RUN TestExternalSignerRestartsAfterCrash2392=== PAUSE TestExternalSignerRestartsAfterCrash2393=== RUN TestExternalSignerProgramErrorKeepsProcess2394=== PAUSE TestExternalSignerProgramErrorKeepsProcess2395=== RUN TestExternalSignerClose2396=== PAUSE TestExternalSignerClose2397=== RUN TestExternalSignerRejectsInvalidPublicKey2398=== PAUSE TestExternalSignerRejectsInvalidPublicKey2399=== RUN TestExternalSignerCancellation2400=== PAUSE TestExternalSignerCancellation2401=== RUN TestGenerateFingerprint2402=== PAUSE TestGenerateFingerprint2403=== RUN TestParseSigningKey2404=== PAUSE TestParseSigningKey2405=== RUN TestSign2406=== PAUSE TestSign2407=== RUN TestSignBatch2408=== PAUSE TestSignBatch2409=== RUN TestNilKeyPublicKey2410=== PAUSE TestNilKeyPublicKey2411=== RUN TestSignErrors2412=== PAUSE TestSignErrors2413=== CONT TestExternalSigner2414=== CONT TestExternalSignerProgramErrorKeepsProcess2415=== CONT TestSign2416=== CONT TestSignBatch2417=== CONT TestSignErrors2418=== CONT TestNilKeyPublicKey2419--- PASS: TestNilKeyPublicKey (0.00s)2420=== CONT TestExternalSignerRejectsInvalidPublicKey2421=== CONT TestExternalSignerErrors2422=== CONT TestExternalSignerRestartsAfterCrash2423=== CONT TestParseSigningKey2424=== CONT TestGenerateFingerprint2425=== CONT TestExternalSignerWrongPublicKey2426=== CONT TestExternalSignerClose2427=== CONT TestExternalSignerCancellation2428=== RUN TestExternalSignerRejectsInvalidPublicKey/#002429=== RUN TestParseSigningKey/valid_32-byte_key2430=== RUN TestExternalSignerErrors/invalid_signature_base642431=== PAUSE TestExternalSignerErrors/invalid_signature_base642432=== RUN TestGenerateFingerprint/basic_with_references2433--- PASS: TestSign (0.00s)2434--- PASS: TestSignBatch (0.00s)2435=== RUN TestSignErrors/nil_key2436=== PAUSE TestSignErrors/nil_key2437=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002438=== PAUSE TestParseSigningKey/valid_32-byte_key2439=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2440=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2441=== RUN TestExternalSignerErrors/wrong_signature_length2442=== PAUSE TestExternalSignerErrors/wrong_signature_length2443=== RUN TestExternalSignerErrors/program_error2444=== PAUSE TestExternalSignerErrors/program_error2445=== RUN TestExternalSignerErrors/exit_on_request2446=== PAUSE TestGenerateFingerprint/basic_with_references2447=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2448=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2449=== RUN TestSignErrors/nil_narinfo2450=== PAUSE TestSignErrors/nil_narinfo2451=== RUN TestParseSigningKey/no_colon2452=== PAUSE TestExternalSignerErrors/exit_on_request2453=== RUN TestGenerateFingerprint/no_references2454=== RUN TestExternalSignerErrors/too_few_signatures2455=== PAUSE TestGenerateFingerprint/no_references2456=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2457=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2458=== RUN TestSignErrors/invalid_narinfo2459=== PAUSE TestSignErrors/invalid_narinfo2460=== PAUSE TestParseSigningKey/no_colon2461=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2462=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2463=== RUN TestParseSigningKey/empty_name2464=== PAUSE TestParseSigningKey/empty_name2465=== RUN TestParseSigningKey/invalid_base642466=== PAUSE TestParseSigningKey/invalid_base642467=== RUN TestParseSigningKey/wrong_length2468=== PAUSE TestParseSigningKey/wrong_length2469=== CONT TestParseSigningKey/valid_32-byte_key2470=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2471=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2472=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2473=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2474=== CONT TestExternalSignerRejectsInvalidPublicKey/#002475=== CONT TestParseSigningKey/invalid_base642476=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2477=== PAUSE TestExternalSignerErrors/too_few_signatures2478=== RUN TestExternalSignerErrors/wrong_signature_name2479=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2480=== RUN TestSignErrors/canceled2481=== CONT TestParseSigningKey/wrong_length2482=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2483=== CONT TestParseSigningKey/no_colon2484=== CONT TestParseSigningKey/empty_name2485=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2486=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2487=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2488=== PAUSE TestExternalSignerErrors/wrong_signature_name2489=== RUN TestExternalSignerErrors/invalid_JSON2490=== PAUSE TestExternalSignerErrors/invalid_JSON2491=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2492=== RUN TestGenerateFingerprint/invalid_nar_hash_length2493--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2494=== PAUSE TestSignErrors/canceled2495=== CONT TestSignErrors/nil_key2496=== RUN TestExternalSignerErrors/wrong_shape2497=== CONT TestSignErrors/canceled2498--- PASS: TestParseSigningKey (0.00s)2499 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2500 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2501 --- PASS: TestParseSigningKey/wrong_length (0.00s)2502 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2503 --- PASS: TestParseSigningKey/no_colon (0.00s)2504 --- PASS: TestParseSigningKey/empty_name (0.00s)2505--- PASS: TestExternalSignerClose (0.00s)2506=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2507=== CONT TestSignErrors/invalid_narinfo2508=== CONT TestSignErrors/nil_narinfo2509=== PAUSE TestExternalSignerErrors/wrong_shape2510--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2511 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2512 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2513 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2514 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2515 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2516--- PASS: TestExternalSignerWrongPublicKey (0.00s)2517=== RUN TestGenerateFingerprint/invalid_store_path_prefix2518=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2519=== RUN TestGenerateFingerprint/invalid_reference_prefix2520=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2521=== CONT TestGenerateFingerprint/basic_with_references2522=== RUN TestExternalSignerErrors/exit_at_startup2523=== PAUSE TestExternalSignerErrors/exit_at_startup2524--- PASS: TestSignErrors (0.00s)2525 --- PASS: TestSignErrors/nil_key (0.00s)2526 --- PASS: TestSignErrors/canceled (0.00s)2527 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2528 --- PASS: TestSignErrors/nil_narinfo (0.00s)2529=== CONT TestGenerateFingerprint/invalid_nar_hash_length2530=== CONT TestGenerateFingerprint/invalid_reference_prefix2531=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2532=== CONT TestGenerateFingerprint/invalid_store_path_prefix2533=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2534=== CONT TestGenerateFingerprint/no_references2535--- PASS: TestGenerateFingerprint (0.00s)2536 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2537 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2538 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2539 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2540 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2541 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2542 --- PASS: TestGenerateFingerprint/no_references (0.00s)2543=== RUN TestExternalSignerErrors/null2544=== PAUSE TestExternalSignerErrors/null2545=== RUN TestExternalSignerErrors/wrong_id2546=== PAUSE TestExternalSignerErrors/wrong_id2547=== RUN TestExternalSignerErrors/null_signatures2548=== PAUSE TestExternalSignerErrors/null_signatures2549=== RUN TestExternalSignerErrors/missing_signatures2550=== PAUSE TestExternalSignerErrors/missing_signatures2551=== RUN TestExternalSignerErrors/wrong_signatures_shape2552=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2553=== RUN TestExternalSignerErrors/unrequested_key2554=== PAUSE TestExternalSignerErrors/unrequested_key2555=== RUN TestExternalSignerErrors/missing_signature_name2556=== PAUSE TestExternalSignerErrors/missing_signature_name2557=== CONT TestExternalSignerErrors/invalid_signature_base642558=== CONT TestExternalSignerErrors/exit_on_request2559=== CONT TestExternalSignerErrors/exit_at_startup2560=== CONT TestExternalSignerErrors/unrequested_key2561=== CONT TestExternalSignerErrors/wrong_signatures_shape2562=== CONT TestExternalSignerErrors/missing_signatures2563=== CONT TestExternalSignerErrors/null_signatures2564=== CONT TestExternalSignerErrors/wrong_id2565--- PASS: TestExternalSigner (0.01s)2566=== CONT TestExternalSignerErrors/too_few_signatures2567=== CONT TestExternalSignerErrors/null2568=== CONT TestExternalSignerErrors/wrong_shape2569=== CONT TestExternalSignerErrors/invalid_JSON2570=== CONT TestExternalSignerErrors/wrong_signature_name2571=== CONT TestExternalSignerErrors/program_error2572=== CONT TestExternalSignerErrors/wrong_signature_length2573=== CONT TestExternalSignerErrors/missing_signature_name2574--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2575--- PASS: TestExternalSignerErrors (0.01s)2576 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2577 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2578 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2579 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2580 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2581 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2582 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2583 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2584 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2585 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2586 --- PASS: TestExternalSignerErrors/null (0.01s)2587 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2588 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2589 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2590 --- PASS: TestExternalSignerErrors/program_error (0.00s)2591 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2592--- PASS: TestExternalSignerCancellation (0.02s)2593PASS2594Running OpenBao signer tests...2595=== RUN TestSign2596=== PAUSE TestSign2597=== RUN TestSignErrors2598=== PAUSE TestSignErrors2599=== RUN TestServe2600=== PAUSE TestServe2601=== RUN TestServeRejectsGarbage2602=== PAUSE TestServeRejectsGarbage2603=== CONT TestSign2604=== CONT TestServe2605=== CONT TestSignErrors2606=== CONT TestServeRejectsGarbage2607--- PASS: TestServeRejectsGarbage (0.00s)2608=== RUN TestSignErrors/invalid_base642609=== PAUSE TestSignErrors/invalid_base642610--- PASS: TestServe (0.00s)2611=== RUN TestSignErrors/http_error2612=== PAUSE TestSignErrors/http_error2613=== RUN TestSignErrors/invalid_json2614=== PAUSE TestSignErrors/invalid_json2615=== RUN TestSignErrors/no_prefix2616=== PAUSE TestSignErrors/no_prefix2617=== CONT TestSignErrors/invalid_base642618=== CONT TestSignErrors/invalid_json2619=== CONT TestSignErrors/http_error2620=== CONT TestSignErrors/no_prefix2621--- PASS: TestSign (0.00s)2622--- PASS: TestSignErrors (0.00s)2623 --- PASS: TestSignErrors/invalid_json (0.00s)2624 --- PASS: TestSignErrors/http_error (0.00s)2625 --- PASS: TestSignErrors/no_prefix (0.00s)2626 --- PASS: TestSignErrors/invalid_base64 (0.00s)2627PASS