niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #397
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestStreamPushStopsWhenCanceled74=== PAUSE TestStreamPushStopsWhenCanceled75=== RUN TestSetClientTLS76=== PAUSE TestSetClientTLS77=== RUN TestSetClientTLSDoesNotMutateDefaultTransport78=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport79=== RUN TestSetClientTLSErrors80=== PAUSE TestSetClientTLSErrors81=== RUN TestStaticToken82=== PAUSE TestStaticToken83=== RUN TestFileTokenReadsAndCaches84=== PAUSE TestFileTokenReadsAndCaches85=== RUN TestFileTokenMissing86=== PAUSE TestFileTokenMissing87=== RUN TestFileTokenEmpty88=== PAUSE TestFileTokenEmpty89=== RUN TestScriptTokenNoExpiryRerunsEveryCall90=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall91=== RUN TestScriptTokenCachesUntilRefresh92=== PAUSE TestScriptTokenCachesUntilRefresh93=== RUN TestScriptTokenEmptyToken94=== PAUSE TestScriptTokenEmptyToken95=== RUN TestScriptTokenBadJSON96=== PAUSE TestScriptTokenBadJSON97=== RUN TestScriptTokenScriptFails98=== PAUSE TestScriptTokenScriptFails99=== RUN TestScriptTokenEmptyCommand100=== PAUSE TestScriptTokenEmptyCommand101=== CONT TestDoServerRequestAttachesToken102=== CONT TestEncodeNixBase32103=== CONT TestShellSplit104--- PASS: TestShellSplit (0.00s)105=== CONT TestSetClientTLS106=== CONT TestSetClientTLSDoesNotMutateDefaultTransport107=== CONT TestSetClientTLSErrors108=== CONT TestStreamPushGivesUpOnDeadServer109=== CONT TestScriptTokenEmptyCommand110--- PASS: TestScriptTokenEmptyCommand (0.00s)111=== CONT TestPathInfoCACompatibility112=== RUN TestPathInfoCACompatibility/null_ca_field113=== PAUSE TestPathInfoCACompatibility/null_ca_field114=== RUN TestPathInfoCACompatibility/old_string_format_-_text115=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text116=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive117=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive118=== RUN TestPathInfoCACompatibility/new_structured_format_-_text119=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text120=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method121=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method1222026/10/08 12:57:19 ERROR Upload failed error="connection refused" count=201232026/10/08 12:57:19 ERROR Server seems unavailable, giving up on batch untried=17124=== CONT TestStreamPushIsolatesFailures125=== CONT TestScriptTokenScriptFails126--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)127=== CONT TestResolveStorePath128=== CONT TestStreamPushBatchesUnderLoad129=== CONT TestScriptTokenBadJSON130=== CONT TestStreamPushReportsEveryPath131=== CONT TestScriptTokenEmptyToken132=== CONT TestScriptTokenCachesUntilRefresh1332026/10/08 12:57:19 ERROR Upload failed error="bad path" count=3134=== CONT TestScriptTokenNoExpiryRerunsEveryCall135--- PASS: TestStreamPushIsolatesFailures (0.00s)136=== CONT TestShellSplitErrors137--- PASS: TestShellSplitErrors (0.00s)138=== CONT TestStreamPushReportsSignatures139--- PASS: TestResolveStorePath (0.00s)140=== CONT TestClientSignaturesByStorePath141=== CONT TestParsePathInfoJSON1422026/10/08 12:57:19 ERROR Upload failed error=boom count=1143=== CONT TestFileTokenEmpty144=== CONT TestFileTokenMissing145=== CONT TestParsePathInfoJSONMultiplePaths146=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths147=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths149=== CONT TestFileTokenReadsAndCaches150=== CONT TestDoWithRetry_BodyReplayedViaGetBody151=== CONT TestStreamPushRequestLine152=== CONT TestRateLimiterFeedback153=== CONT TestStaticToken154=== RUN TestEncodeNixBase32/test_string_hash155=== CONT TestStreamPushStopsWhenCanceled156=== CONT TestConvertHashToNix32157=== CONT TestPathInfoHashCompatibility158--- PASS: TestStreamPushReportsEveryPath (0.00s)159=== RUN TestParsePathInfoJSON/Nix_format160=== CONT TestUploadMultipart_PartsInParallel161=== CONT TestEncodeNixBase32WithRealHash162=== RUN TestSetClientTLSErrors/missing_cert_file163=== PAUSE TestParsePathInfoJSON/Nix_format164=== RUN TestParsePathInfoJSON/Lix_format1652026/10/08 12:57:19 ERROR Upload failed error=boom count=1166=== PAUSE TestParsePathInfoJSON/Lix_format167=== RUN TestParsePathInfoJSON/empty_input168=== PAUSE TestParsePathInfoJSON/empty_input169=== RUN TestParsePathInfoJSON/whitespace_only170=== PAUSE TestParsePathInfoJSON/whitespace_only171=== RUN TestParsePathInfoJSON/invalid_JSON172=== CONT TestDumpPathWriterError173=== RUN TestRateLimiterFeedback/429_enables_limiter174=== PAUSE TestEncodeNixBase32/test_string_hash175=== RUN TestConvertHashToNix32/SRI_format_to_Nix32176=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32177=== RUN TestConvertHashToNix32/already_Nix32_format178=== RUN TestEncodeNixBase32/empty_input179=== CONT TestDumpPathSingleFile180=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)181--- PASS: TestClientSignaturesByStorePath (0.00s)182=== CONT TestUploadMultipart_SupersededByPeer183=== PAUSE TestSetClientTLSErrors/missing_cert_file184=== CONT TestPartSizeForNAR185=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths186=== PAUSE TestParsePathInfoJSON/invalid_JSON187=== CONT TestDumpPathMatchesNix188=== PAUSE TestRateLimiterFeedback/429_enables_limiter189=== RUN TestSetClientTLS/rejects_connection_without_client_cert190=== CONT TestFilterOversizedClosures191=== RUN TestFilterOversizedClosures/no_limit_keeps_everything192=== CONT TestCaseHackSuffix193=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess194=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica195=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun196=== PAUSE TestConvertHashToNix32/already_Nix32_format197=== PAUSE TestEncodeNixBase32/empty_input198=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)199=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon200=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon201=== CONT TestPathInfoCACompatibility/null_ca_field202=== RUN TestUploadMultipart_SupersededByPeer/exists203=== PAUSE TestUploadMultipart_SupersededByPeer/exists204=== CONT TestRegisterUploadedObjectReusesConnections205=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method206=== RUN TestConvertHashToNix32/invalid_format207=== RUN TestUploadMultipart_SupersededByPeer/missing208=== PAUSE TestUploadMultipart_SupersededByPeer/missing209=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive2102026/10/08 12:57:19 WARN Rate limiter enabled after throttle name=server-test rate=5211=== CONT TestPathInfoCACompatibility/old_string_format_-_text212=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths213=== PAUSE TestConvertHashToNix32/invalid_format2142026/10/08 12:57:19 WARN Rate limiter enabled after throttle name=server-test rate=5215=== CONT TestGetStorePathHash2162026/10/08 12:57:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35463217=== RUN TestGetStorePathHash/valid_store_path218=== PAUSE TestGetStorePathHash/valid_store_path219=== RUN TestGetStorePathHash/basename_without_hyphen_should_error220=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error221=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error222=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error223=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error224=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error225=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert226=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA227=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA228=== RUN TestSetClientTLS/preserves_debug_logging_transport229=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2302026/10/08 12:57:19 WARN Rate limiter backed off name=server-test rate=5231=== CONT TestParsePathInfoJSON/Nix_format2322026/10/08 12:57:19 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35463233=== CONT TestParsePathInfoJSON/invalid_JSON2342026/10/08 12:57:19 INFO Garbage collection started235=== CONT TestParsePathInfoJSON/empty_input236=== CONT TestParsePathInfoJSON/Lix_format237=== CONT TestEncodeNixBase32/test_string_hash2382026/10/08 12:57:19 INFO Garbage collection started239=== CONT TestEncodeNixBase32/empty_input240=== CONT TestUploadMultipart_SupersededByPeer/exists241=== CONT TestUploadMultipart_SupersededByPeer/missing242=== CONT TestConvertHashToNix32/SRI_format_to_Nix32243=== CONT TestConvertHashToNix32/invalid_format244=== CONT TestGetStorePathHash/valid_store_path245=== CONT TestConvertHashToNix32/already_Nix32_format246=== CONT TestSetClientTLS/rejects_connection_without_client_cert247=== CONT TestParsePathInfoJSON/whitespace_only248=== CONT TestGetStorePathHash/basename_without_hyphen_should_error249=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error250=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error251=== CONT TestSetClientTLS/preserves_debug_logging_transport252--- PASS: TestScriptTokenScriptFails (0.00s)253--- PASS: TestStreamPushReportsSignatures (0.00s)254--- PASS: TestDoServerRequestAttachesToken (0.01s)255=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI256=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI257=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512258=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512259=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)260--- PASS: TestStaticToken (0.00s)261--- PASS: TestStreamPushStopsWhenCanceled (0.00s)262--- PASS: TestEncodeNixBase32WithRealHash (0.00s)263--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)264--- PASS: TestFileTokenMissing (0.00s)265--- PASS: TestScriptTokenBadJSON (0.00s)266--- PASS: TestFileTokenEmpty (0.00s)267--- PASS: TestScriptTokenEmptyToken (0.00s)268--- PASS: TestFileTokenReadsAndCaches (0.03s)269=== RUN TestSetClientTLSErrors/missing_key_file270=== PAUSE TestSetClientTLSErrors/missing_key_file271=== RUN TestSetClientTLSErrors/missing_ca_file272=== PAUSE TestSetClientTLSErrors/missing_ca_file273=== RUN TestSetClientTLSErrors/invalid_ca_file274=== PAUSE TestSetClientTLSErrors/invalid_ca_file275=== CONT TestSetClientTLSErrors/missing_cert_file276=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512277=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI278=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon279--- PASS: TestPathInfoHashCompatibility (0.03s)280 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)281 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)282 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)283 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)284=== RUN TestPartSizeForNAR/zero_stays_at_minimum285=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum286=== RUN TestPartSizeForNAR/small_stays_at_minimum287=== PAUSE TestPartSizeForNAR/small_stays_at_minimum288=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum289=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum290=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts291=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts292=== RUN TestPartSizeForNAR/1_TiB293=== PAUSE TestPartSizeForNAR/1_TiB294=== RUN TestPartSizeForNAR/5_TiB_S3_max_object295=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object296=== RUN TestPartSizeForNAR/capped_at_5_GiB297=== PAUSE TestPartSizeForNAR/capped_at_5_GiB298=== CONT TestPartSizeForNAR/zero_stays_at_minimum299=== CONT TestSetClientTLSErrors/invalid_ca_file300=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA301=== CONT TestSetClientTLSErrors/missing_ca_file3022026/10/08 12:57:19 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=0303=== CONT TestSetClientTLSErrors/missing_key_file304=== CONT TestPartSizeForNAR/5_TiB_S3_max_object305=== CONT TestPartSizeForNAR/1_TiB306=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts307=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum308=== CONT TestPartSizeForNAR/small_stays_at_minimum309=== CONT TestPartSizeForNAR/capped_at_5_GiB310--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)311=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything312=== RUN TestRateLimiterFeedback/503_enables_limiter313=== PAUSE TestRateLimiterFeedback/503_enables_limiter314=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter315=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter316=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter317=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter318=== CONT TestRateLimiterFeedback/429_enables_limiter319=== CONT TestPathInfoCACompatibility/new_structured_format_-_text320--- PASS: TestPartSizeForNAR (0.00s)321 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)322 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)323 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)324 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)325 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)326 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)327 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)328=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths329=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped330=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped331=== RUN TestFilterOversizedClosures/all_closures_skipped332=== PAUSE TestFilterOversizedClosures/all_closures_skipped333=== CONT TestFilterOversizedClosures/no_limit_keeps_everything334=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3352026/10/08 12:57:19 WARN Garbage collection finished on another replica. Its statistics are not available here336=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter337=== CONT TestRateLimiterFeedback/503_enables_limiter338--- PASS: TestPathInfoCACompatibility (0.00s)339 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)340 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)341 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)342 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)343 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)3442026/10/08 12:57:19 WARN Rate limiter enabled after throttle name=server-test rate=5345=== CONT TestFilterOversizedClosures/all_closures_skipped3462026/10/08 12:57:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:398993472026/10/08 12:57:19 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=50348=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped349--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)350--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)3512026/10/08 12:57:19 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=20003522026/10/08 12:57:19 WARN Rate limiter backed off name=server-test rate=5353--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)354--- PASS: TestParsePathInfoJSON (0.03s)355 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)356 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)357 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)358 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)359 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)360--- PASS: TestGetStorePathHash (0.01s)361 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)362 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)363 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)364 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)365--- PASS: TestFilterOversizedClosures (0.01s)366 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)367 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)368 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.01s)369--- PASS: TestEncodeNixBase32 (0.04s)370 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)371 --- PASS: TestEncodeNixBase32/empty_input (0.00s)372--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)373 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)374 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)3752026/10/08 12:57:19 WARN Rate limiter enabled after throttle name=server-test rate=5376--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)377 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)378 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)3792026/10/08 12:57:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43913380--- PASS: TestSetClientTLSErrors (0.05s)381 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)382 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)383 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)384 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)385--- PASS: TestConvertHashToNix32 (0.04s)386 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)387 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)388 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)3892026/10/08 12:57:19 WARN Rate limiter backed off name=server-test rate=5390--- PASS: TestRateLimiterFeedback (0.04s)391 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)392 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)393 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)394 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)395--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)3962026/10/08 12:57:19 http: TLS handshake error from 127.0.0.1:42304: remote error: tls: bad certificate397--- PASS: TestSetClientTLS (0.04s)398 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)399 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)400 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)401--- PASS: TestStreamPushRequestLine (0.05s)402--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)403--- PASS: TestDumpPathSingleFile (0.03s)404--- PASS: TestCaseHackSuffix (0.04s)405--- PASS: TestDumpPathWriterError (0.07s)406--- PASS: TestStreamPushBatchesUnderLoad (0.10s)407--- PASS: TestDumpPathMatchesNix (0.10s)408--- PASS: TestUploadMultipart_PartsInParallel (0.65s)409--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)410PASS411Running server tests...412The files belonging to this database system will be owned by user "nixbld".413This user must also own the server process.414415The database cluster will be initialized with locale "C".416The default database encoding has accordingly been set to "SQL_ASCII".417The default text search configuration will be set to "english".418419Data page checksums are enabled.420421creating directory /build/postgres3941843788/data ... ok422creating subdirectories ... ok423selecting dynamic shared memory implementation ... posix424selecting default "max_connections" ... 100425selecting default "shared_buffers" ... 128MB426selecting default time zone ... UTC427creating configuration files ... ok428running bootstrap script ... ok429performing post-bootstrap initialization ... ok430syncing data to disk ... ok431432initdb: warning: enabling "trust" authentication for local connections433initdb: 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.434435Success. You can now start the database server using:436437 pg_ctl -D /build/postgres3941843788/data -l logfile start438439/build/postgres3941843788:5432 - no response4402026-10-08 12:57:21.355 UTC [131] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4412026-10-08 12:57:21.355 UTC [131] LOG: listening on Unix socket "/build/postgres3941843788/.s.PGSQL.5432"4422026-10-08 12:57:21.367 UTC [138] LOG: database system was shut down at 2026-10-08 12:57:21 UTC4432026-10-08 12:57:21.371 UTC [131] LOG: database system is ready to accept connections444/build/postgres3941843788:5432 - accepting connections445{"timestamp":"2026-10-08T12:57:21.759494516Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ae985fd0-fe10-4552-b4bb-51bfca0a17bc","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(394)"}446=== RUN TestService_AuthMiddleware447=== PAUSE TestService_AuthMiddleware448=== RUN TestService_AuthMiddleware_MTLSProxyHeader449=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader450=== RUN TestService_AuthMiddleware_MTLSBoundSubjects451=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects452=== RUN TestService_ReadAuthMiddleware453=== PAUSE TestService_ReadAuthMiddleware454=== RUN TestService_AuthMiddleware_OIDC455=== PAUSE TestService_AuthMiddleware_OIDC456=== RUN TestService_RequireScope_OIDC457=== PAUSE TestService_RequireScope_OIDC458=== RUN TestService_ReadScope_PublicByDefault459=== PAUSE TestService_ReadScope_PublicByDefault460=== RUN TestCacheConfigHandler461=== PAUSE TestCacheConfigHandler462=== RUN TestCacheStatsHandler463=== PAUSE TestCacheStatsHandler464=== RUN TestClientCADerivations465=== PAUSE TestClientCADerivations466=== RUN TestClientErrorHandling467=== PAUSE TestClientErrorHandling468=== RUN TestClientIntegration469=== PAUSE TestClientIntegration470=== RUN TestClientMultipleUploads471=== PAUSE TestClientMultipleUploads472=== RUN TestClientWithDependencies473=== PAUSE TestClientWithDependencies474=== RUN TestClientSharedPathCommittedMidPush475=== PAUSE TestClientSharedPathCommittedMidPush476=== RUN TestPinProtectsFromGC477=== PAUSE TestPinProtectsFromGC478=== RUN TestClientPushesUseOnePush479=== PAUSE TestClientPushesUseOnePush480=== RUN TestClientFallsBackToClosures481=== PAUSE TestClientFallsBackToClosures482=== RUN TestDeleteClosuresRacingPins483=== PAUSE TestDeleteClosuresRacingPins484=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock485=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock486=== RUN TestResolveDBConnectionString487=== PAUSE TestResolveDBConnectionString488=== RUN TestConnectWaitsForAPeerMigration489=== PAUSE TestConnectWaitsForAPeerMigration490=== RUN TestLeadElectsOneAndHandsOver491=== PAUSE TestLeadElectsOneAndHandsOver492=== RUN TestLeadIncumbentWinsAfterRestart4932026/10/08 12:57:22 INFO lead: acquired remote=192.0.2.1:12344942026/10/08 12:57:22 INFO lead: released remote=192.0.2.1:12344952026/10/08 12:57:22 INFO lead: acquired remote=192.0.2.1:12344962026/10/08 12:57:23 INFO lead: released remote=192.0.2.1:1234497--- PASS: TestLeadIncumbentWinsAfterRestart (1.90s)498=== RUN TestLeadIncumbentAnnouncesAtOnce499=== PAUSE TestLeadIncumbentAnnouncesAtOnce500=== RUN TestLeadEndsOnShutdown501=== PAUSE TestLeadEndsOnShutdown502=== RUN TestLeadEndsWhenItsConnectionHangs5032026/10/08 12:57:23 INFO lead: acquired remote=192.0.2.1:12345042026-10-08 12:57:25.289 UTC [578] FATAL: terminating connection due to administrator command5052026/10/08 12:57:25 INFO lead: acquired remote=192.0.2.1:12345062026/10/08 12:57:26 WARN lead: lock connection lost error="timeout: context deadline exceeded"5072026/10/08 12:57:26 INFO lead: released remote=192.0.2.1:12345082026/10/08 12:57:26 INFO lead: released remote=192.0.2.1:1234509--- PASS: TestLeadEndsWhenItsConnectionHangs (2.93s)510=== RUN TestGCAdvisoryLockBlocksConcurrentRun511=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun512=== RUN TestGCBugBareHashReferences513=== PAUSE TestGCBugBareHashReferences514=== RUN TestGCMetrics515=== PAUSE TestGCMetrics516=== RUN TestPushDedupSurvivesConcurrentGC517=== PAUSE TestPushDedupSurvivesConcurrentGC518=== RUN TestDeduplicatedObjectsRecordedAsPending519=== PAUSE TestDeduplicatedObjectsRecordedAsPending520=== RUN TestGCSweepSkipsPendingObjects521=== PAUSE TestGCSweepSkipsPendingObjects522=== RUN TestTombstonedObjectOfferedWithoutWaiting523=== PAUSE TestTombstonedObjectOfferedWithoutWaiting524=== RUN TestGCSweepDeliversEachKeyOnce525=== PAUSE TestGCSweepDeliversEachKeyOnce526=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection527=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection528=== RUN TestForceGCDuringPushOffersSweptObject529=== PAUSE TestForceGCDuringPushOffersSweptObject530=== RUN TestFailedS3DeleteKeepsTombstone531=== PAUSE TestFailedS3DeleteKeepsTombstone532=== RUN TestSweepSkipsRowsLockedByPush533=== PAUSE TestSweepSkipsRowsLockedByPush534=== RUN TestRegisterCompletedObjectNeedsPendingRow535=== PAUSE TestRegisterCompletedObjectNeedsPendingRow536=== RUN TestGetExistingObjectsLocksRows537=== PAUSE TestGetExistingObjectsLocksRows538=== RUN TestSweepRechecksPendingAfterLocking539=== PAUSE TestSweepRechecksPendingAfterLocking540=== RUN TestPushWaitsForSweepHoldingRow541=== PAUSE TestPushWaitsForSweepHoldingRow542=== RUN TestCommitRacingPendingCleanupKeepsObjects543=== PAUSE TestCommitRacingPendingCleanupKeepsObjects544=== RUN TestGCEndsOnShutdown545=== PAUSE TestGCEndsOnShutdown546=== RUN TestGCTaskStore_StartNew547=== PAUSE TestGCTaskStore_StartNew548=== RUN TestGCTaskStore_DeduplicateSameParams549=== PAUSE TestGCTaskStore_DeduplicateSameParams550=== RUN TestGCTaskStore_ConflictDifferentParams551=== PAUSE TestGCTaskStore_ConflictDifferentParams552=== RUN TestGCTaskStore_GetEmpty553=== PAUSE TestGCTaskStore_GetEmpty554=== RUN TestGCTaskStore_GetReturnsLatest555=== PAUSE TestGCTaskStore_GetReturnsLatest556=== RUN TestGCTaskStore_CompletedAllowsNewTask557=== PAUSE TestGCTaskStore_CompletedAllowsNewTask558=== RUN TestGCTaskStore_PhaseUpdates559=== PAUSE TestGCTaskStore_PhaseUpdates560=== RUN TestGCTaskStore_Fail561=== PAUSE TestGCTaskStore_Fail562=== RUN TestGracefulShutdownDrainsInflight563=== PAUSE TestGracefulShutdownDrainsInflight564=== RUN TestService_healthCheckHandler565=== PAUSE TestService_healthCheckHandler566=== RUN TestService_readinessHandler567=== PAUSE TestService_readinessHandler568=== RUN TestGenerateLandingPage569=== PAUSE TestGenerateLandingPage570=== RUN TestCacheConfigHandlerMaxNarSize571=== PAUSE TestCacheConfigHandlerMaxNarSize572=== RUN TestCreatePendingClosureRejectsOversizedNAR573=== PAUSE TestCreatePendingClosureRejectsOversizedNAR574=== RUN TestNARDeduplicationMetadataUploadBug575=== PAUSE TestNARDeduplicationMetadataUploadBug576=== RUN TestMetricsInventory577=== PAUSE TestMetricsInventory578=== RUN TestMetricsCommit579=== PAUSE TestMetricsCommit580=== RUN TestService_NativeMTLS581=== PAUSE TestService_NativeMTLS582=== RUN TestServerTLSConfig583=== PAUSE TestServerTLSConfig584=== RUN TestMultipartCleanup585=== PAUSE TestMultipartCleanup586=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded587=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded588=== RUN TestPendingCleanupUsesOneCutoff589=== PAUSE TestPendingCleanupUsesOneCutoff590=== RUN TestObjectStatsTrigger591=== PAUSE TestObjectStatsTrigger592=== RUN TestObjectStatsLargeCommit593=== PAUSE TestObjectStatsLargeCommit594=== RUN TestOrphanedObjectsGC595=== PAUSE TestOrphanedObjectsGC596=== RUN TestOrphanedObjectsGCStressTest597=== PAUSE TestOrphanedObjectsGCStressTest598=== RUN TestCreatePin_ReservedPins599=== PAUSE TestCreatePin_ReservedPins600=== RUN TestPresentReportsOnlyClosureRoots601=== PAUSE TestPresentReportsOnlyClosureRoots602=== RUN TestPresentRefreshesOnlyStaleClosures603=== PAUSE TestPresentRefreshesOnlyStaleClosures604=== RUN TestPresentNotReportedWhileGCDeletesClosure605=== PAUSE TestPresentNotReportedWhileGCDeletesClosure606=== RUN TestParseSingleRange607=== PAUSE TestParseSingleRange608=== RUN TestProxyHeadersOnlyTrustedOnSocket6092026/10/08 12:57:26 INFO Starting HTTP server address=127.0.0.1:352876102026/10/08 12:57:26 INFO Starting HTTP server address=proxy.sock6112026/10/08 12:57:26 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6122026/10/08 12:57:26 INFO Shutdown signal received, draining in-flight requests timeout=10s613--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.12s)614=== RUN TestIsValidCachePath615=== PAUSE TestIsValidCachePath616=== RUN TestReadProxyNarinfo617=== PAUSE TestReadProxyNarinfo618=== RUN TestReadProxyNarinfoAlreadyDecompressed619=== PAUSE TestReadProxyNarinfoAlreadyDecompressed620=== RUN TestReadProxyContentNegotiation621=== PAUSE TestReadProxyContentNegotiation622=== RUN TestReadProxyNarStreaming623=== PAUSE TestReadProxyNarStreaming624=== RUN TestReadProxy404625=== PAUSE TestReadProxy404626=== RUN TestReadProxyInvalidPath627=== PAUSE TestReadProxyInvalidPath628=== RUN TestReadProxyHead629=== PAUSE TestReadProxyHead630=== RUN TestReadProxyOutlastsServerWriteTimeout631=== PAUSE TestReadProxyOutlastsServerWriteTimeout632=== RUN TestReadProxyConditionalGet633=== PAUSE TestReadProxyConditionalGet634=== RUN TestReadProxyRootRedirectsToIndexHTML635=== PAUSE TestReadProxyRootRedirectsToIndexHTML636=== RUN TestReadProxyDisabled637=== PAUSE TestReadProxyDisabled638=== RUN TestReadRedirectNar639=== PAUSE TestReadRedirectNar640=== RUN TestReadRedirectKeepsNarinfoProxied641=== PAUSE TestReadRedirectKeepsNarinfoProxied642=== RUN TestReadProxyRangeRequest643=== PAUSE TestReadProxyRangeRequest644=== RUN TestReadRedirectUsesPublicS3URL645=== PAUSE TestReadRedirectUsesPublicS3URL646=== RUN TestPush_OverlappingRootsStoreOneRowPerKey647=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey648=== RUN TestPush_CompleteCommitsEveryRoot649=== PAUSE TestPush_CompleteCommitsEveryRoot650=== RUN TestPush_RepeatedRootCommitsOnce651=== PAUSE TestPush_RepeatedRootCommitsOnce652=== RUN TestPush_CompleteWaitsForCleanupOfThePush653=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush654=== RUN TestPush_RootsAreLockedInByteOrder655=== PAUSE TestPush_RootsAreLockedInByteOrder656=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit657=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit658=== RUN TestPush_RejectsBadRequests659=== PAUSE TestPush_RejectsBadRequests660=== RUN TestPush_SignsNarinfosOfItsPendingObjects661=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects662=== RUN TestRedundantMultipartUpload663=== PAUSE TestRedundantMultipartUpload664=== RUN TestCompleteMultipartUpload_ErrorButObjectExists665=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists666=== RUN TestCompletedNarNotReofferedAcrossClosures667=== PAUSE TestCompletedNarNotReofferedAcrossClosures668=== RUN TestPresignedUploadRegisteredBeforeCommit669=== PAUSE TestPresignedUploadRegisteredBeforeCommit670=== RUN TestService_Rustfstest671=== PAUSE TestService_Rustfstest672=== RUN TestParseSize673=== PAUSE TestParseSize674=== RUN TestSkippedUploadsHandler675=== PAUSE TestSkippedUploadsHandler676=== RUN TestSystemdListenerNotActivated677--- PASS: TestSystemdListenerNotActivated (0.00s)678=== RUN TestWatchdogBeatsWhenHealthy679--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)680=== RUN TestWatchdogSkipsWhenUnhealthy6812026/10/08 12:57:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/08 12:57:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/08 12:57:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/08 12:57:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/08 12:57:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6862026/10/08 12:57:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6872026/10/08 12:57:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6882026/10/08 12:57:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6892026/10/08 12:57:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6902026/10/08 12:57:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"691--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)692=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle693=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle694=== RUN TestProxyWriteTimeout695=== PAUSE TestProxyWriteTimeout696=== RUN TestPendingClosureWriteTimeout697=== PAUSE TestPendingClosureWriteTimeout698=== RUN TestIsValidUploadKey699=== PAUSE TestIsValidUploadKey700=== RUN TestUploadHandlersRejectInvalidKeys701=== PAUSE TestUploadHandlersRejectInvalidKeys702=== RUN TestUploadHandlersRejectOversizedBody703=== PAUSE TestUploadHandlersRejectOversizedBody704=== RUN TestService_cleanupPendingClosuresHandler705=== PAUSE TestService_cleanupPendingClosuresHandler706=== RUN TestService_createPendingClosureHandler707=== PAUSE TestService_createPendingClosureHandler708=== RUN TestService_verifyS3Integrity709=== PAUSE TestService_verifyS3Integrity710=== RUN TestCompleteMultipartUnregistered711=== PAUSE TestCompleteMultipartUnregistered712=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT713=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT714=== CONT TestService_AuthMiddleware715=== CONT TestService_cleanupPendingClosuresHandler716=== CONT TestReadProxyHead717=== CONT TestReadRedirectKeepsNarinfoProxied718=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT719=== CONT TestCompleteMultipartUnregistered720=== CONT TestService_verifyS3Integrity721=== CONT TestPush_RejectsBadRequests722=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit723=== CONT TestPush_RootsAreLockedInByteOrder724=== CONT TestPush_CompleteWaitsForCleanupOfThePush725=== CONT TestPush_RepeatedRootCommitsOnce726=== CONT TestPush_CompleteCommitsEveryRoot727=== CONT TestPush_OverlappingRootsStoreOneRowPerKey728=== CONT TestReadRedirectUsesPublicS3URL729=== CONT TestPush_SignsNarinfosOfItsPendingObjects730=== CONT TestService_createPendingClosureHandler731=== CONT TestReadProxyRangeRequest732=== CONT TestReadRedirectNar733=== CONT TestReadProxyDisabled734=== CONT TestReadProxyRootRedirectsToIndexHTML735=== CONT TestReadProxyConditionalGet736=== CONT TestReadProxyOutlastsServerWriteTimeout737=== CONT TestSkippedUploadsHandler7382026/10/08 12:57:27 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000739--- PASS: TestSkippedUploadsHandler (0.01s)740=== CONT TestUploadHandlersRejectOversizedBody741=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure742=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure743=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart744=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart745=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts746=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts747=== CONT TestUploadHandlersRejectInvalidKeys748=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info749=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info750=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal751=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal752=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key753=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key754=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key755=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key756=== CONT TestIsValidUploadKey757=== RUN TestIsValidUploadKey/narinfo758=== PAUSE TestIsValidUploadKey/narinfo759=== RUN TestIsValidUploadKey/nar_zst760=== PAUSE TestIsValidUploadKey/nar_zst761=== RUN TestIsValidUploadKey/nar_xz762=== PAUSE TestIsValidUploadKey/nar_xz763=== RUN TestIsValidUploadKey/nar_plain764=== PAUSE TestIsValidUploadKey/nar_plain765=== RUN TestIsValidUploadKey/listing766=== PAUSE TestIsValidUploadKey/listing767=== RUN TestIsValidUploadKey/build_log768=== PAUSE TestIsValidUploadKey/build_log769=== RUN TestIsValidUploadKey/build_log_home-manager_file770=== PAUSE TestIsValidUploadKey/build_log_home-manager_file771=== RUN TestIsValidUploadKey/build_log_plus_in_name772=== PAUSE TestIsValidUploadKey/build_log_plus_in_name773=== RUN TestIsValidUploadKey/build_log_question_mark774=== PAUSE TestIsValidUploadKey/build_log_question_mark775=== RUN TestIsValidUploadKey/build_log_equals776=== PAUSE TestIsValidUploadKey/build_log_equals777=== RUN TestIsValidUploadKey/realisation778=== PAUSE TestIsValidUploadKey/realisation779=== RUN TestIsValidUploadKey/realisation_plus_in_output780=== PAUSE TestIsValidUploadKey/realisation_plus_in_output781=== RUN TestIsValidUploadKey/nix-cache-info782=== PAUSE TestIsValidUploadKey/nix-cache-info783=== RUN TestIsValidUploadKey/index.html784=== PAUSE TestIsValidUploadKey/index.html785=== RUN TestIsValidUploadKey/narinfo_key,_nar_type786=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type787=== RUN TestIsValidUploadKey/nar_key,_narinfo_type788=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type789=== RUN TestIsValidUploadKey/listing_key,_narinfo_type790=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type791=== RUN TestIsValidUploadKey/traversal792=== PAUSE TestIsValidUploadKey/traversal793=== RUN TestIsValidUploadKey/traversal_nar794=== PAUSE TestIsValidUploadKey/traversal_nar795=== RUN TestIsValidUploadKey/absolute796=== PAUSE TestIsValidUploadKey/absolute797=== RUN TestIsValidUploadKey/empty_key798=== PAUSE TestIsValidUploadKey/empty_key799=== RUN TestIsValidUploadKey/unknown_type800=== PAUSE TestIsValidUploadKey/unknown_type801=== CONT TestPendingClosureWriteTimeout802=== RUN TestPendingClosureWriteTimeout/empty803=== PAUSE TestPendingClosureWriteTimeout/empty804=== RUN TestPendingClosureWriteTimeout/400_objects805=== PAUSE TestPendingClosureWriteTimeout/400_objects806=== RUN TestPendingClosureWriteTimeout/670k_objects807=== PAUSE TestPendingClosureWriteTimeout/670k_objects808=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline809=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline810=== CONT TestProxyWriteTimeout811=== RUN TestProxyWriteTimeout/narinfo812=== PAUSE TestProxyWriteTimeout/narinfo813=== RUN TestProxyWriteTimeout/1_GiB_nar814=== PAUSE TestProxyWriteTimeout/1_GiB_nar815=== RUN TestProxyWriteTimeout/10_GiB_nar816=== PAUSE TestProxyWriteTimeout/10_GiB_nar817=== RUN TestProxyWriteTimeout/unknown_size818=== PAUSE TestProxyWriteTimeout/unknown_size819=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8202026/10/08 12:57:27 INFO Received uploads request method=POST path=/api/pending_closures821--- PASS: TestReadProxyHead (0.48s)822=== CONT TestPresignedUploadRegisteredBeforeCommit823--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.50s)824=== CONT TestParseSize825--- PASS: TestParseSize (0.00s)826=== CONT TestService_Rustfstest827--- PASS: TestReadRedirectKeepsNarinfoProxied (0.52s)828=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8292026/10/08 12:57:27 INFO Received uploads request method=POST path=/api/pending_closures8302026/10/08 12:57:27 INFO Received cleanup request method=DELETE path=/api/pending_closures8312026/10/08 12:57:27 INFO Aborted multipart uploads count=0 kept=08322026/10/08 12:57:27 INFO Received uploads request method=POST path=/api/pending_closures8332026/10/08 12:57:27 INFO Received cleanup request method=DELETE path=/api/pending_closures8342026/10/08 12:57:27 INFO Aborted multipart uploads count=1 kept=08352026/10/08 12:57:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8362026-10-08 12:57:27.610 UTC [662] ERROR: Closure does not exist: id=18372026-10-08 12:57:27.610 UTC [662] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8382026-10-08 12:57:27.610 UTC [662] STATEMENT: -- name: CommitPendingClosure :one839 SELECT commit_pending_closure($1::bigint)::bigint840 841--- PASS: TestService_cleanupPendingClosuresHandler (0.57s)842=== CONT TestCompletedNarNotReofferedAcrossClosures8432026/10/08 12:57:27 INFO Received push request method=POST path=/api/pushes844=== RUN TestPush_RejectsBadRequests/no_roots845=== PAUSE TestPush_RejectsBadRequests/no_roots846=== RUN TestPush_RejectsBadRequests/no_objects847=== PAUSE TestPush_RejectsBadRequests/no_objects848=== RUN TestPush_RejectsBadRequests/bad_root849=== PAUSE TestPush_RejectsBadRequests/bad_root850=== RUN TestPush_RejectsBadRequests/root_not_in_objects851=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects852=== CONT TestRedundantMultipartUpload8532026-10-08 12:57:27.657 UTC [693] ERROR: could not obtain lock on row in relation "closures"8542026-10-08 12:57:27.657 UTC [693] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8552026-10-08 12:57:27.657 UTC [693] ERROR: could not obtain lock on row in relation "closures"8562026-10-08 12:57:27.657 UTC [693] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8572026-10-08 12:57:27.658 UTC [693] ERROR: could not obtain lock on row in relation "closures"8582026-10-08 12:57:27.658 UTC [693] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8592026-10-08 12:57:27.658 UTC [693] ERROR: could not obtain lock on row in relation "closures"8602026-10-08 12:57:27.658 UTC [693] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8612026-10-08 12:57:27.658 UTC [693] ERROR: could not obtain lock on row in relation "closures"8622026-10-08 12:57:27.658 UTC [693] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT863--- PASS: TestPush_RootsAreLockedInByteOrder (0.62s)864=== CONT TestCommitRacingPendingCleanupKeepsObjects8652026/10/08 12:57:27 INFO Received push request method=POST path=/api/pushes8662026/10/08 12:57:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8672026/10/08 12:57:27 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst868--- PASS: TestCompleteMultipartUnregistered (0.66s)869=== CONT TestReadProxyInvalidPath8702026/10/08 12:57:27 INFO Received push request method=POST path=/api/pushes871--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.70s)872=== CONT TestReadProxy4048732026/10/08 12:57:27 INFO Received push request method=POST path=/api/pushes8742026/10/08 12:57:27 INFO Received complete push request method=POST path=/api/pushes/1/complete875--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.73s)876=== CONT TestReadProxyNarStreaming8772026/10/08 12:57:27 INFO Completed push id=1 objects=6 duration=9.874032ms878--- PASS: TestPush_CompleteCommitsEveryRoot (0.74s)879=== CONT TestReadProxyContentNegotiation8802026/10/08 12:57:27 INFO Received push request method=POST path=/api/pushes8812026/10/08 12:57:27 INFO Received complete push request method=POST path=/api/pushes/1/complete8822026/10/08 12:57:27 INFO Completed push id=1 objects=4 duration=9.148283ms8832026/10/08 12:57:27 INFO Received push request method=POST path=/api/pushes884--- PASS: TestReadRedirectNar (0.79s)885=== CONT TestReadProxyNarinfoAlreadyDecompressed886--- PASS: TestReadProxyDisabled (0.80s)887=== CONT TestReadProxyNarinfo8882026/10/08 12:57:27 INFO Received push request method=POST path=/api/pushes8892026/10/08 12:57:27 INFO Aborted multipart uploads count=0 kept=08902026/10/08 12:57:27 WARN Force mode enabled - objects will be deleted immediately without grace period8912026/10/08 12:57:27 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"892--- PASS: TestService_AuthMiddleware (0.86s)893=== CONT TestIsValidCachePath894=== RUN TestIsValidCachePath/narinfo895=== PAUSE TestIsValidCachePath/narinfo896=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars897=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars898=== RUN TestIsValidCachePath/nar_zst899=== PAUSE TestIsValidCachePath/nar_zst900=== RUN TestIsValidCachePath/nar_xz901=== PAUSE TestIsValidCachePath/nar_xz902=== RUN TestIsValidCachePath/nar_bz2903=== PAUSE TestIsValidCachePath/nar_bz2904=== RUN TestIsValidCachePath/nar_uncompressed905=== PAUSE TestIsValidCachePath/nar_uncompressed906=== RUN TestIsValidCachePath/ls907=== PAUSE TestIsValidCachePath/ls908=== RUN TestIsValidCachePath/log909=== PAUSE TestIsValidCachePath/log910=== RUN TestIsValidCachePath/realisation911=== PAUSE TestIsValidCachePath/realisation912=== RUN TestIsValidCachePath/nix-cache-info913=== PAUSE TestIsValidCachePath/nix-cache-info914=== RUN TestIsValidCachePath/index.html915=== PAUSE TestIsValidCachePath/index.html916=== RUN TestIsValidCachePath/traversal_parent917=== PAUSE TestIsValidCachePath/traversal_parent918=== RUN TestIsValidCachePath/traversal_in_middle919=== PAUSE TestIsValidCachePath/traversal_in_middle920=== RUN TestIsValidCachePath/invalid_char_e921=== PAUSE TestIsValidCachePath/invalid_char_e922=== RUN TestIsValidCachePath/invalid_char_u923=== PAUSE TestIsValidCachePath/invalid_char_u924=== RUN TestIsValidCachePath/random_path925=== PAUSE TestIsValidCachePath/random_path926=== RUN TestIsValidCachePath/empty927=== PAUSE TestIsValidCachePath/empty928=== RUN TestIsValidCachePath/leading_slash929=== PAUSE TestIsValidCachePath/leading_slash930=== RUN TestIsValidCachePath/wrong_extension931=== PAUSE TestIsValidCachePath/wrong_extension932=== RUN TestIsValidCachePath/short_hash933=== PAUSE TestIsValidCachePath/short_hash934=== CONT TestParseSingleRange935=== RUN TestParseSingleRange/none936=== PAUSE TestParseSingleRange/none937=== RUN TestParseSingleRange/unknown_unit938=== PAUSE TestParseSingleRange/unknown_unit939=== RUN TestParseSingleRange/multi-range_ignored940=== PAUSE TestParseSingleRange/multi-range_ignored941=== RUN TestParseSingleRange/malformed_no_dash942=== PAUSE TestParseSingleRange/malformed_no_dash943=== RUN TestParseSingleRange/malformed_both_empty944=== PAUSE TestParseSingleRange/malformed_both_empty945=== RUN TestParseSingleRange/malformed_end_before_start946=== PAUSE TestParseSingleRange/malformed_end_before_start947=== RUN TestParseSingleRange/closed948=== PAUSE TestParseSingleRange/closed949=== RUN TestParseSingleRange/open-ended950=== PAUSE TestParseSingleRange/open-ended951=== RUN TestParseSingleRange/end_clamped_to_size952=== PAUSE TestParseSingleRange/end_clamped_to_size953=== RUN TestParseSingleRange/suffix954=== PAUSE TestParseSingleRange/suffix955=== RUN TestParseSingleRange/suffix_exceeds_size956=== PAUSE TestParseSingleRange/suffix_exceeds_size957=== RUN TestParseSingleRange/single_byte958=== PAUSE TestParseSingleRange/single_byte959=== RUN TestParseSingleRange/start_past_EOF960=== PAUSE TestParseSingleRange/start_past_EOF961=== RUN TestParseSingleRange/start_far_past_EOF962=== PAUSE TestParseSingleRange/start_far_past_EOF963=== CONT TestCreatePendingClosureRejectsOversizedNAR9642026/10/08 12:57:27 INFO Received uploads request method=POST path=/api/pending_closures965--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)966=== CONT TestCacheConfigHandlerMaxNarSize967--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)968=== CONT TestGenerateLandingPage969--- PASS: TestGenerateLandingPage (0.00s)970=== CONT TestService_readinessHandler9712026/10/08 12:57:27 INFO Received complete push request method=POST path=/api/pushes/1/complete9722026/10/08 12:57:27 INFO Completed push id=1 objects=4 duration=10.124031ms973--- PASS: TestPush_RepeatedRootCommitsOnce (0.88s)974=== CONT TestService_healthCheckHandler9752026/10/08 12:57:27 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=09762026/10/08 12:57:27 INFO Vacuumed table table=pending_closures9772026/10/08 12:57:27 INFO Vacuumed table table=pending_objects9782026/10/08 12:57:27 INFO Vacuumed table table=multipart_uploads9792026/10/08 12:57:27 INFO Vacuumed table table=closures9802026/10/08 12:57:27 INFO Vacuumed table table=objects981--- PASS: TestReadProxyRangeRequest (0.90s)982=== CONT TestGracefulShutdownDrainsInflight9832026/10/08 12:57:27 INFO Received complete push request method=POST path=/api/pushes/2/complete9842026/10/08 12:57:27 INFO Starting HTTP server address=127.0.0.1:383839852026/10/08 12:57:27 INFO Shutdown signal received, draining in-flight requests timeout=10s9862026/10/08 12:57:27 INFO Completed push id=2 objects=4 duration=3.486553ms987--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.90s)988=== CONT TestGCTaskStore_Fail989--- PASS: TestGCTaskStore_Fail (0.00s)990=== CONT TestGCTaskStore_PhaseUpdates991--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)992=== CONT TestGCTaskStore_CompletedAllowsNewTask993--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)994=== CONT TestGCTaskStore_GetReturnsLatest995--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)996=== CONT TestGCTaskStore_GetEmpty997--- PASS: TestGCTaskStore_GetEmpty (0.00s)998=== CONT TestNARDeduplicationMetadataUploadBug999--- PASS: TestReadProxyConditionalGet (0.92s)1000=== CONT TestGCTaskStore_ConflictDifferentParams1001--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1002=== CONT TestPresentNotReportedWhileGCDeletesClosure1003=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1004=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1005=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1006=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1007=== CONT TestGCTaskStore_DeduplicateSameParams1008--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1009=== CONT TestPresentRefreshesOnlyStaleClosures10102026/10/08 12:57:27 INFO Received uploads request method=POST path=/api/pending_closures10112026/10/08 12:57:27 INFO Received uploads request method=POST path=/api/pending_closures10122026/10/08 12:57:27 INFO Received uploads request method=POST path=/api/pending_closures10132026/10/08 12:57:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10142026-10-08 12:57:28.000 UTC [702] ERROR: Push does not exist: id=110152026-10-08 12:57:28.000 UTC [702] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10162026-10-08 12:57:28.000 UTC [702] STATEMENT: SELECT commit_push($1)1017--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.96s)1018=== CONT TestGCTaskStore_StartNew1019--- PASS: TestGCTaskStore_StartNew (0.00s)1020=== CONT TestGCEndsOnShutdown1021=== RUN TestGCEndsOnShutdown/before_the_run1022=== PAUSE TestGCEndsOnShutdown/before_the_run1023=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1024=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1025=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1026=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1027=== CONT TestPresentReportsOnlyClosureRoots1028--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1029=== CONT TestCreatePin_ReservedPins1030--- PASS: TestReadRedirectUsesPublicS3URL (0.98s)1031=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10322026/10/08 12:57:28 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZGRjNzJmNzAtZmEwYi00NzAxLWIyYTctZTJhMWQ3ZGVmZGRlLjAzMWVlM2ZlLTAwZDgtNGIyNS1iY2VjLTYyZmE1MjdkNzJmN3gxNzkxNDY0MjQ3NTc0OTQ0MzE0 parts=1010332026/10/08 12:57:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10342026/10/08 12:57:28 INFO Completed upload id=1 objects=2 duration=6.447738ms10352026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures10362026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures10372026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures10382026/10/08 12:57:28 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10392026/10/08 12:57:28 WARN Found objects in DB but missing from S3, will re-upload count=11040--- PASS: TestService_verifyS3Integrity (1.00s)1041=== CONT TestOrphanedObjectsGCStressTest10422026/10/08 12:57:28 INFO Received push request method=POST path=/api/pushes10432026/10/08 12:57:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10442026/10/08 12:57:28 INFO Signed narinfos id=1 count=110452026/10/08 12:57:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10462026/10/08 12:57:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10472026/10/08 12:57:28 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10482026/10/08 12:57:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10492026/10/08 12:57:28 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10502026/10/08 12:57:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10512026/10/08 12:57:28 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110522026/10/08 12:57:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10532026/10/08 12:57:28 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1054--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.04s)1055=== CONT TestMultipartCleanup1056--- PASS: TestService_Rustfstest (0.59s)1057=== CONT TestOrphanedObjectsGC10582026/10/08 12:57:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10592026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures10602026/10/08 12:57:28 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10612026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures1062--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.69s)1063=== CONT TestServerTLSConfig1064=== RUN TestServerTLSConfig/no_client_CA1065=== PAUSE TestServerTLSConfig/no_client_CA1066=== RUN TestServerTLSConfig/missing_CA_file1067=== PAUSE TestServerTLSConfig/missing_CA_file1068=== RUN TestServerTLSConfig/not_a_PEM_file1069=== PAUSE TestServerTLSConfig/not_a_PEM_file1070=== CONT TestObjectStatsLargeCommit10712026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures10722026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures10732026/10/08 12:57:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10742026/10/08 12:57:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGRjNzJmNzAtZmEwYi00NzAxLWIyYTctZTJhMWQ3ZGVmZGRlLjBjMzk0MTMwLWIyYjEtNDBhZi1iNTAzLTBjMGUyYTk3MWQ5ZXgxNzkxNDY0MjQ4MjM4NDE4OTE410752026/10/08 12:57:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGRjNzJmNzAtZmEwYi00NzAxLWIyYTctZTJhMWQ3ZGVmZGRlLjBjMzk0MTMwLWIyYjEtNDBhZi1iNTAzLTBjMGUyYTk3MWQ5ZXgxNzkxNDY0MjQ4MjM4NDE4OTE4 parts=11076--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.72s)1077=== CONT TestService_NativeMTLS10782026/10/08 12:57:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36703/oidc10792026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures10802026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures1081--- PASS: TestReadProxyInvalidPath (0.67s)1082=== CONT TestObjectStatsTrigger10832026/10/08 12:57:28 INFO Aborted multipart uploads count=0 kept=010842026/10/08 12:57:28 WARN Force mode enabled - objects will be deleted immediately without grace period10852026/10/08 12:57:28 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=010862026/10/08 12:57:28 INFO Vacuumed table table=pending_closures10872026/10/08 12:57:28 INFO Vacuumed table table=pending_objects10882026/10/08 12:57:28 INFO Vacuumed table table=multipart_uploads10892026/10/08 12:57:28 INFO Vacuumed table table=closures10902026/10/08 12:57:28 INFO Vacuumed table table=objects1091--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.75s)1092=== CONT TestPendingCleanupUsesOneCutoff1093--- PASS: TestReadProxy404 (0.68s)1094=== CONT TestMetricsInventory10952026/10/08 12:57:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1096--- PASS: TestReadProxyNarStreaming (0.66s)1097=== CONT TestMetricsCommit10982026/10/08 12:57:28 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZGRjNzJmNzAtZmEwYi00NzAxLWIyYTctZTJhMWQ3ZGVmZGRlLjkxNmQwYzM5LWFkZTEtNDFjNy1iZjJjLWJkMjRmNzQ3Njk5NXgxNzkxNDY0MjQ3OTkzODU1OTIw parts=1010992026/10/08 12:57:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11002026/10/08 12:57:28 INFO Completed upload id=1 objects=2 duration=5.48589ms11012026/10/08 12:57:28 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011022026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures11032026/10/08 12:57:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures11042026/10/08 12:57:28 INFO Aborted multipart uploads count=0 kept=01105--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.67s)1106=== CONT TestConnectWaitsForAPeerMigration11072026/10/08 12:57:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011082026/10/08 12:57:28 INFO Vacuumed table table=pending_closures11092026/10/08 12:57:28 INFO Vacuumed table table=pending_objects11102026/10/08 12:57:28 INFO Vacuumed table table=multipart_uploads1111--- PASS: TestReadProxyContentNegotiation (0.74s)1112=== CONT TestTombstonedObjectOfferedWithoutWaiting11132026/10/08 12:57:28 INFO Vacuumed table table=closures11142026/10/08 12:57:28 INFO Vacuumed table table=objects11152026/10/08 12:57:28 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001116--- PASS: TestService_createPendingClosureHandler (1.48s)1117=== CONT TestGCSweepSkipsPendingObjects11182026/10/08 12:57:28 WARN readiness check failed error="closed pool"1119--- PASS: TestService_readinessHandler (0.64s)1120=== CONT TestDeduplicatedObjectsRecordedAsPending1121--- PASS: TestService_healthCheckHandler (0.69s)1122=== CONT TestPushWaitsForSweepHoldingRow11232026/10/08 12:57:28 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1124--- PASS: TestReadProxyNarinfo (0.79s)1125=== CONT TestLeadEndsOnShutdown1126--- PASS: TestPresentRefreshesOnlyStaleClosures (0.72s)1127=== CONT TestSweepRechecksPendingAfterLocking1128=== NAME TestNARDeduplicationMetadataUploadBug1129 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug430778463/001/store/7l125xv77ac8b294g1zadb7mdgwjjkxs-file1.txt11302026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures1131--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.71s)1132=== CONT TestLeadIncumbentAnnouncesAtOnce1133--- PASS: TestPresentReportsOnlyClosureRoots (0.75s)1134=== CONT TestGetExistingObjectsLocksRows11352026/10/08 12:57:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11362026/10/08 12:57:28 INFO Received push request method=POST path=/api/pushes11372026/10/08 12:57:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11382026/10/08 12:57:28 INFO Uploading 7l125xv77ac8b294g1zadb7mdgwjjkxs-file1.txt (160B)11392026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures11402026/10/08 12:57:28 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11412026/10/08 12:57:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11422026/10/08 12:57:28 WARN Failed to register uploaded object key=7l125xv77ac8b294g1zadb7mdgwjjkxs.ls error="server returned 404: 404 page not found\n"11432026/10/08 12:57:28 INFO Signed narinfos id=1 count=111442026/10/08 12:57:28 INFO Uploading 1 narinfos11452026/10/08 12:57:28 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZGRjNzJmNzAtZmEwYi00NzAxLWIyYTctZTJhMWQ3ZGVmZGRlLjAxN2ZiMTIwLWNmYmItNDRkZC1iYmRiLWU4YzE2NDc5NDY1MXgxNzkxNDY0MjQ4MjcyNzQxNjA1 parts=1211462026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures11472026/10/08 12:57:28 INFO Received complete push request method=POST path=/api/pushes/1/complete11482026/10/08 12:57:28 WARN Failed to register uploaded object key=7l125xv77ac8b294g1zadb7mdgwjjkxs.narinfo error="server returned 404: 404 page not found\n"1149--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.21s)1150=== CONT TestLeadElectsOneAndHandsOver11512026/10/08 12:57:28 INFO Completed push id=1 objects=3 duration=10.610921ms11522026/10/08 12:57:28 INFO Upload complete. (78ms)1153=== NAME TestNARDeduplicationMetadataUploadBug1154 metadata_upload_test.go:54: Retrieved narinfo from S3:1155 StorePath: /build/TestNARDeduplicationMetadataUploadBug430778463/001/store/7l125xv77ac8b294g1zadb7mdgwjjkxs-file1.txt1156 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1157 Compression: zstd1158 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1159 NarSize: 1601160 References: 1161 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1162 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1163 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1164 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11652026/10/08 12:57:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11662026/10/08 12:57:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGRjNzJmNzAtZmEwYi00NzAxLWIyYTctZTJhMWQ3ZGVmZGRlLmVjOTA2ZTVhLTg2ZTUtNDU5MS1hY2U1LWYyZDc2ODhlZDgyYngxNzkxNDY0MjQ4MzA3Njg3NDEw parts=1211672026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures11682026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures1169 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug430778463/001/store/fy1q0qsqb8rapqfc808w3r6v5ipis72g-file2.txt11702026/10/08 12:57:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11712026/10/08 12:57:28 WARN Refused reserved pin name=worker-x86_64-linux11722026/10/08 12:57:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11732026/10/08 12:57:28 INFO Received create pin request method=POST path=/api/pins/my-app11742026/10/08 12:57:28 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1175--- PASS: TestCreatePin_ReservedPins (0.88s)1176=== CONT TestRegisterCompletedObjectNeedsPendingRow11772026/10/08 12:57:28 INFO Received cleanup request method=DELETE path=/api/pending_closures11782026/10/08 12:57:28 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket47/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11792026/10/08 12:57:28 INFO Aborted multipart uploads count=0 kept=111802026/10/08 12:57:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11812026/10/08 12:57:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1182--- PASS: TestService_NativeMTLS (0.65s)1183=== CONT TestGCMetrics11842026/10/08 12:57:28 INFO Received cleanup request method=DELETE path=/api/pending_closures11852026/10/08 12:57:28 INFO Aborted multipart uploads count=1 kept=01186--- PASS: TestMultipartCleanup (0.86s)1187=== CONT TestSweepSkipsRowsLockedByPush11882026/10/08 12:57:28 INFO Received push request method=POST path=/api/pushes1189--- PASS: TestObjectStatsTrigger (0.62s)1190=== CONT TestGCAdvisoryLockBlocksConcurrentRun11912026/10/08 12:57:28 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11922026/10/08 12:57:28 INFO Received uploads request method=POST path=/api/pending_closures11932026/10/08 12:57:28 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11942026/10/08 12:57:28 WARN Failed to register uploaded object key=fy1q0qsqb8rapqfc808w3r6v5ipis72g.ls error="server returned 404: 404 page not found\n"11952026/10/08 12:57:28 INFO Signed narinfos id=2 count=111962026/10/08 12:57:28 INFO Uploading 1 narinfos11972026/10/08 12:57:29 INFO Received complete push request method=POST path=/api/pushes/2/complete11982026/10/08 12:57:29 WARN Failed to register uploaded object key=fy1q0qsqb8rapqfc808w3r6v5ipis72g.narinfo error="server returned 404: 404 page not found\n"11992026/10/08 12:57:29 INFO Completed push id=2 objects=3 duration=2.369156ms12002026/10/08 12:57:29 INFO Upload complete. (67ms)1201=== NAME TestNARDeduplicationMetadataUploadBug1202 metadata_upload_test.go:76: Retrieved narinfo from S3:1203 StorePath: /build/TestNARDeduplicationMetadataUploadBug430778463/001/store/fy1q0qsqb8rapqfc808w3r6v5ipis72g-file2.txt1204 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1205 Compression: zstd1206 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1207 NarSize: 1601208 References: 1209 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1210 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1211 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1212 {"version":1,"root":{"type":"regular","size":44}}12132026/10/08 12:57:29 INFO Received uploads request method=POST path=/api/pending_closures1214--- PASS: TestNARDeduplicationMetadataUploadBug (1.07s)1215=== CONT TestFailedS3DeleteKeepsTombstone12162026/10/08 12:57:29 INFO Received cleanup request method=DELETE path=/api/pending_closures12172026/10/08 12:57:29 INFO Received push request method=POST path=/api/pushes1218--- PASS: TestMetricsInventory (0.63s)1219=== CONT TestPushDedupSurvivesConcurrentGC12202026/10/08 12:57:29 INFO Received uploads request method=POST path=/api/pending_closures12212026/10/08 12:57:29 INFO Received complete push request method=POST path=/api/pushes/1/complete12222026/10/08 12:57:29 INFO Completed push id=1 objects=4 duration=9.318463ms12232026/10/08 12:57:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12242026/10/08 12:57:29 INFO Completed upload id=2 objects=2 duration=1.829847ms12252026/10/08 12:57:29 INFO Aborted multipart uploads count=0 kept=01226--- PASS: TestMetricsCommit (0.68s)1227=== CONT TestGCBugBareHashReferences12282026/10/08 12:57:29 INFO Received uploads request method=POST path=/api/pending_closures12292026/10/08 12:57:29 WARN Force mode enabled - objects will be deleted immediately without grace period12302026/10/08 12:57:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01231--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.61s)1232=== CONT TestForceGCDuringPushOffersSweptObject1233=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1234=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1235=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1236=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1237=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12382026/10/08 12:57:29 INFO Vacuumed table table=pending_closures12392026/10/08 12:57:29 INFO Vacuumed table table=pending_objects12402026/10/08 12:57:29 INFO Vacuumed table table=multipart_uploads12412026/10/08 12:57:29 INFO Vacuumed table table=closures12422026/10/08 12:57:29 INFO Vacuumed table table=objects12432026/10/08 12:57:29 INFO Received uploads request method=POST path=/api/pending_closures1244--- PASS: TestGCSweepSkipsPendingObjects (0.62s)1245=== CONT TestClientIntegration1246--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.60s)1247=== CONT TestGCSweepDeliversEachKeyOnce12482026/10/08 12:57:29 INFO Received uploads request method=POST path=/api/pending_closures1249=== NAME TestOrphanedObjectsGC1250 orphaned_objects_gc_test.go:287: GC Test Summary:1251 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1252 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1253 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1254 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1255 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1256--- PASS: TestOrphanedObjectsGC (1.05s)1257=== CONT TestClientPushesUseOnePush12582026/10/08 12:57:29 INFO lead: acquired remote=192.0.2.1:123412592026/10/08 12:57:29 INFO Aborted multipart uploads count=0 kept=012602026/10/08 12:57:29 WARN Force mode enabled - objects will be deleted immediately without grace period12612026/10/08 12:57:29 INFO lead: acquired remote=192.0.2.1:123412622026/10/08 12:57:29 INFO lead: released remote=192.0.2.1:12341263--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.52s)1264=== CONT TestClientWithDependencies12652026/10/08 12:57:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012662026/10/08 12:57:29 INFO Vacuumed table table=pending_closures12672026/10/08 12:57:29 INFO Vacuumed table table=pending_objects12682026/10/08 12:57:29 INFO Vacuumed table table=multipart_uploads12692026/10/08 12:57:29 INFO Vacuumed table table=closures12702026/10/08 12:57:29 INFO Vacuumed table table=objects1271--- PASS: TestSweepRechecksPendingAfterLocking (0.59s)1272=== CONT TestResolveDBConnectionString1273=== RUN TestResolveDBConnectionString/flag_wins1274=== PAUSE TestResolveDBConnectionString/flag_wins1275=== RUN TestResolveDBConnectionString/file_when_flag_empty1276=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1277=== RUN TestResolveDBConnectionString/missing_file_is_an_error1278=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1279=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1280=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1281=== RUN TestResolveDBConnectionString/nothing_configured1282=== PAUSE TestResolveDBConnectionString/nothing_configured1283=== CONT TestClientSharedPathCommittedMidPush1284--- PASS: TestGetExistingObjectsLocksRows (0.54s)1285=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12862026/10/08 12:57:29 INFO lead: acquired remote=192.0.2.1:12341287--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.44s)1288=== CONT TestPinProtectsFromGC12892026/10/08 12:57:29 INFO Aborted multipart uploads count=0 kept=012902026/10/08 12:57:29 WARN Force mode enabled - objects will be deleted immediately without grace period12912026/10/08 12:57:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012922026/10/08 12:57:29 INFO Vacuumed table table=pending_closures12932026/10/08 12:57:29 INFO Vacuumed table table=pending_objects12942026/10/08 12:57:29 INFO Vacuumed table table=multipart_uploads12952026/10/08 12:57:29 INFO Vacuumed table table=closures12962026/10/08 12:57:29 INFO Vacuumed table table=objects12972026/10/08 12:57:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1298--- PASS: TestGCMetrics (0.45s)1299=== CONT TestClientMultipleUploads13002026/10/08 12:57:29 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGRjNzJmNzAtZmEwYi00NzAxLWIyYTctZTJhMWQ3ZGVmZGRlLmYxOTE2MjQwLTNlY2MtNGE3MS05Zjk3LTNkNDI2MTQ4N2JhNngxNzkxNDY0MjQ4ODgwNjgxOTYy error="Get \"http://127.0.0.1:1/bucket32/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13012026/10/08 12:57:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGRjNzJmNzAtZmEwYi00NzAxLWIyYTctZTJhMWQ3ZGVmZGRlLjYzMGFmMGJhLTkyMzMtNGY2My1iNzM1LTdiMWFmYjlhZjUzNngxNzkxNDY0MjQ4ODczNTQyOTQ1 parts=1213022026/10/08 12:57:29 INFO Received cleanup request method=DELETE path=/api/pending_closures13032026/10/08 12:57:29 INFO Aborted multipart uploads count=0 kept=013042026/10/08 12:57:29 INFO Aborted multipart uploads count=1 kept=013052026/10/08 12:57:29 WARN Force mode enabled - objects will be deleted immediately without grace period13062026/10/08 12:57:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01307--- PASS: TestRedundantMultipartUpload (1.76s)1308=== CONT TestDeleteClosuresRacingPins13092026/10/08 12:57:29 INFO Vacuumed table table=pending_closures13102026/10/08 12:57:29 INFO Vacuumed table table=pending_objects13112026/10/08 12:57:29 INFO Vacuumed table table=multipart_uploads13122026/10/08 12:57:29 INFO Vacuumed table table=closures13132026/10/08 12:57:29 INFO Vacuumed table table=objects13142026/10/08 12:57:29 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1315--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.43s)1316=== CONT TestService_ReadScope_PublicByDefault13172026/10/08 12:57:29 INFO Aborted multipart uploads count=0 kept=013182026/10/08 12:57:29 WARN Force mode enabled - objects will be deleted immediately without grace period13192026/10/08 12:57:29 INFO Received uploads request method=POST path=/api/pending_closures13202026/10/08 12:57:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=013212026/10/08 12:57:29 INFO Vacuumed table table=pending_closures13222026/10/08 12:57:29 INFO Vacuumed table table=pending_objects13232026/10/08 12:57:29 INFO Vacuumed table table=multipart_uploads13242026/10/08 12:57:29 INFO Vacuumed table table=closures13252026/10/08 12:57:29 INFO Vacuumed table table=objects1326--- PASS: TestSweepSkipsRowsLockedByPush (0.50s)1327=== CONT TestClientFallsBackToClosures13282026/10/08 12:57:29 INFO Received uploads request method=POST path=/api/pending_closures13292026/10/08 12:57:29 INFO Received uploads request method=POST path=/api/pending_closures13302026/10/08 12:57:29 INFO Aborted multipart uploads count=0 kept=013312026/10/08 12:57:29 WARN Force mode enabled - objects will be deleted immediately without grace period13322026/10/08 12:57:29 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13332026/10/08 12:57:29 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1334--- PASS: TestFailedS3DeleteKeepsTombstone (0.51s)1335=== CONT TestClientErrorHandling1336=== RUN TestClientErrorHandling/InvalidStorePath1337=== PAUSE TestClientErrorHandling/InvalidStorePath1338=== RUN TestClientErrorHandling/InvalidAuthToken1339=== PAUSE TestClientErrorHandling/InvalidAuthToken1340=== RUN TestClientErrorHandling/ServerNotAvailable1341=== PAUSE TestClientErrorHandling/ServerNotAvailable1342=== CONT TestService_ReadAuthMiddleware13432026/10/08 12:57:29 INFO Aborted multipart uploads count=0 kept=013442026/10/08 12:57:29 INFO Aborted multipart uploads count=0 kept=013452026/10/08 12:57:29 WARN Force mode enabled - objects will be deleted immediately without grace period13462026/10/08 12:57:29 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=013472026/10/08 12:57:29 INFO Vacuumed table table=pending_closures13482026/10/08 12:57:29 INFO Vacuumed table table=pending_objects13492026/10/08 12:57:29 INFO Vacuumed table table=multipart_uploads13502026/10/08 12:57:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=013512026/10/08 12:57:29 INFO Vacuumed table table=pending_closures13522026/10/08 12:57:29 INFO Vacuumed table table=pending_objects13532026/10/08 12:57:29 INFO Vacuumed table table=multipart_uploads13542026/10/08 12:57:29 INFO Vacuumed table table=closures13552026/10/08 12:57:29 INFO Vacuumed table table=closures13562026/10/08 12:57:29 INFO Vacuumed table table=objects13572026/10/08 12:57:29 INFO Vacuumed table table=objects1358--- PASS: TestGCSweepDeliversEachKeyOnce (0.43s)1359=== CONT TestCacheStatsHandler13602026/10/08 12:57:29 INFO Aborted multipart uploads count=0 kept=013612026/10/08 12:57:29 WARN Force mode enabled - objects will be deleted immediately without grace period13622026/10/08 12:57:29 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013632026/10/08 12:57:29 INFO Vacuumed table table=pending_closures13642026/10/08 12:57:29 INFO Vacuumed table table=pending_objects13652026/10/08 12:57:29 INFO Vacuumed table table=multipart_uploads13662026/10/08 12:57:29 INFO Vacuumed table table=closures13672026/10/08 12:57:29 INFO Vacuumed table table=objects1368=== NAME TestClientIntegration1369 client_integration_test.go:286: Created store path: /build/TestClientIntegration278214646/002/store/xyjxz8l744mja1idm2kd1kyksmv5j0k1-test-file.txt1370--- PASS: TestPushDedupSurvivesConcurrentGC (0.57s)1371=== CONT TestCacheConfigHandler1372=== RUN TestCacheConfigHandler/full_config,_no_issuer1373=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1374=== RUN TestCacheConfigHandler/no_cache_url_configured1375=== PAUSE TestCacheConfigHandler/no_cache_url_configured1376=== RUN TestCacheConfigHandler/no_signing_keys1377=== PAUSE TestCacheConfigHandler/no_signing_keys1378=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1379=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1380=== CONT TestClientCADerivations1381--- PASS: TestPushWaitsForSweepHoldingRow (1.07s)1382=== CONT TestService_RequireScope_OIDC13832026/10/08 12:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34657/oidc1384--- PASS: TestGCBugBareHashReferences (0.60s)1385=== CONT TestService_AuthMiddleware_MTLSProxyHeader1386--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.59s)1387=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13882026/10/08 12:57:29 INFO Received push request method=POST path=/api/pushes13892026/10/08 12:57:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13902026/10/08 12:57:29 INFO Uploading xyjxz8l744mja1idm2kd1kyksmv5j0k1-test-file.txt (152B)13912026/10/08 12:57:29 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13922026/10/08 12:57:29 WARN Failed to register uploaded object key=xyjxz8l744mja1idm2kd1kyksmv5j0k1.ls error="server returned 404: 404 page not found\n"13932026/10/08 12:57:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13942026/10/08 12:57:29 INFO Signed narinfos id=1 count=113952026/10/08 12:57:29 INFO Uploading 1 narinfos13962026/10/08 12:57:29 INFO Received complete push request method=POST path=/api/pushes/1/complete13972026/10/08 12:57:29 WARN Failed to register uploaded object key=xyjxz8l744mja1idm2kd1kyksmv5j0k1.narinfo error="server returned 404: 404 page not found\n"1398=== NAME TestClientWithDependencies1399 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2283181806/001/store/8wf0cki3xj88z5j5ji4kr2azcslimpz7-test-script14002026/10/08 12:57:29 INFO Completed push id=1 objects=3 duration=20.408062ms14012026/10/08 12:57:29 INFO Upload complete. (102ms)1402 client_integration_test.go:615: Found 1 dependencies (including self)1403--- PASS: TestService_ReadScope_PublicByDefault (0.41s)1404=== CONT TestService_AuthMiddleware_OIDC1405=== NAME TestClientMultipleUploads1406 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads578872097/001/store/8fg9aiw884hgzs0zsjmaf3ahipzy3fwc-test-file-0.txt1407=== NAME TestPinProtectsFromGC1408 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3648073092/001/store/dadyg0sss1ff6x9b3x3waw08hgnsf8mv-pinned-file.txt14092026/10/08 12:57:29 INFO All 1 paths already cached1410 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3648073092/001/store/g0lhdqciiilayy7g23ziykksac2y5z1q-unpinned-file.txt1411=== NAME TestClientIntegration1412 client_integration_test.go:312: Retrieved narinfo from S3:1413 StorePath: /build/TestClientIntegration278214646/002/store/xyjxz8l744mja1idm2kd1kyksmv5j0k1-test-file.txt1414 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1415 Compression: zstd1416 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11417 NarSize: 1521418 References: 1419 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11420 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1421 client_integration_test.go:313: Decompressed .ls content (64 bytes):1422 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1423 client_integration_test.go:316: Testing garbage collection...1424--- PASS: TestObjectStatsLargeCommit (1.67s)1425=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14262026/10/08 12:57:29 INFO Received uploads request method=POST path=/14272026/10/08 12:57:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43423/oidc14282026/10/08 12:57:29 INFO Received push request method=POST path=/api/pushes14292026/10/08 12:57:29 INFO Received push request method=POST path=/api/pushes1430=== NAME TestClientMultipleUploads1431 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads578872097/001/store/4kygy5mw3y5z1j4r3cx04ynwzk6w4609-test-file-1.txt1432--- PASS: TestService_ReadAuthMiddleware (0.37s)1433=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14342026/10/08 12:57:29 INFO Received request for more parts method=POST path=/14352026/10/08 12:57:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14362026/10/08 12:57:29 INFO Uploading lshknnfhb7wjqpm957yf9i4w7bivfvhr-a (216B)14372026/10/08 12:57:29 INFO Uploading iiw3xkh5l01jy3sq9ifr64sy9npmxhpw-shared-dep (136B)14382026/10/08 12:57:29 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14392026/10/08 12:57:29 INFO Uploading 3h471icxw8v9xh8y7xic5gsx60whjx7y-top (224B)14402026/10/08 12:57:29 INFO Uploading xsdbv74kxg9q40fj3ss1sqsni2qcypaa-shared-dep (136B)14412026/10/08 12:57:29 WARN Failed to register uploaded object key=0dmdfcwg9g4iivwb2yb7d15s040i9a5d.ls error="server returned 404: 404 page not found\n"14422026/10/08 12:57:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures14432026/10/08 12:57:29 INFO Garbage collection started14442026/10/08 12:57:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14452026/10/08 12:57:29 WARN Failed to register uploaded object key=nar/1sizqghgk4ws54j1n7hlk8jbqmhyd9iaab5qdk7df9158rh28wn3.nar.zst error="server returned 404: 404 page not found\n"14462026/10/08 12:57:29 INFO Received push request method=POST path=/api/pushes14472026/10/08 12:57:29 WARN Failed to register uploaded object key=xsdbv74kxg9q40fj3ss1sqsni2qcypaa.ls error="server returned 404: 404 page not found\n"14482026/10/08 12:57:29 WARN Failed to register uploaded object key=iiw3xkh5l01jy3sq9ifr64sy9npmxhpw.ls error="server returned 404: 404 page not found\n"14492026/10/08 12:57:29 WARN Failed to register uploaded object key=lshknnfhb7wjqpm957yf9i4w7bivfvhr.ls error="server returned 404: 404 page not found\n"14502026/10/08 12:57:29 WARN Failed to register uploaded object key=3h471icxw8v9xh8y7xic5gsx60whjx7y.ls error="server returned 404: 404 page not found\n"14512026/10/08 12:57:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14522026/10/08 12:57:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14532026/10/08 12:57:29 WARN Failed to register uploaded object key=nar/0k6fw68l9kvfp10xl1x4hg4f2ala0r0abqbciy05riil2zww7zj4.nar.zst error="server returned 404: 404 page not found\n"14542026/10/08 12:57:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14552026/10/08 12:57:29 INFO Signed narinfos id=1 count=314562026/10/08 12:57:29 INFO Uploading 3 narinfos14572026/10/08 12:57:29 INFO Signed narinfos id=1 count=214582026/10/08 12:57:29 INFO Uploading 2 narinfos14592026/10/08 12:57:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14602026/10/08 12:57:29 WARN Failed to register uploaded object key=iiw3xkh5l01jy3sq9ifr64sy9npmxhpw.narinfo error="server returned 404: 404 page not found\n"14612026/10/08 12:57:29 INFO Uploading 8wf0cki3xj88z5j5ji4kr2azcslimpz7-test-script (136B)14622026/10/08 12:57:29 WARN Failed to register uploaded object key=lshknnfhb7wjqpm957yf9i4w7bivfvhr.narinfo error="server returned 404: 404 page not found\n"14632026/10/08 12:57:29 WARN Failed to register uploaded object key=3h471icxw8v9xh8y7xic5gsx60whjx7y.narinfo error="server returned 404: 404 page not found\n"14642026/10/08 12:57:29 INFO Received complete push request method=POST path=/api/pushes/1/complete14652026/10/08 12:57:29 INFO Received complete push request method=POST path=/api/pushes/1/complete14662026/10/08 12:57:29 WARN Failed to register uploaded object key=xsdbv74kxg9q40fj3ss1sqsni2qcypaa.narinfo error="server returned 404: 404 page not found\n"14672026/10/08 12:57:29 WARN Failed to register uploaded object key=0dmdfcwg9g4iivwb2yb7d15s040i9a5d.narinfo error="server returned 404: 404 page not found\n"14682026/10/08 12:57:29 INFO Aborted multipart uploads count=0 kept=014692026/10/08 12:57:29 WARN Failed to register uploaded object key=log/27mmwwf5x8z1bfxdc3z736fx6mql1q6x-test-script.drv error="server returned 404: 404 page not found\n"14702026/10/08 12:57:29 WARN Failed to register uploaded object key=8wf0cki3xj88z5j5ji4kr2azcslimpz7.ls error="server returned 404: 404 page not found\n"14712026/10/08 12:57:29 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14722026/10/08 12:57:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14732026/10/08 12:57:29 INFO Signed narinfos id=1 count=114742026/10/08 12:57:29 INFO Uploading 1 narinfos14752026/10/08 12:57:29 INFO Received complete push request method=POST path=/api/pushes/1/complete14762026/10/08 12:57:29 WARN Failed to register uploaded object key=8wf0cki3xj88z5j5ji4kr2azcslimpz7.narinfo error="server returned 404: 404 page not found\n"14772026/10/08 12:57:29 WARN Force mode enabled - objects will be deleted immediately without grace period14782026/10/08 12:57:29 INFO Completed push id=1 objects=6 duration=8.012685ms14792026/10/08 12:57:29 INFO Completed push id=1 objects=8 duration=8.084605ms14802026/10/08 12:57:29 INFO Upload complete. (82ms)14812026/10/08 12:57:29 INFO Upload complete. (86ms)1482--- PASS: TestCacheStatsHandler (0.35s)1483=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14842026/10/08 12:57:29 INFO Received complete multipart upload request method=POST path=/1485=== NAME TestClientSharedPathCommittedMidPush1486 client_integration_test.go:680: Retrieved narinfo from S3:1487 StorePath: /build/TestClientSharedPathCommittedMidPush475956225/001/store/xsdbv74kxg9q40fj3ss1sqsni2qcypaa-shared-dep1488 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1489 Compression: zstd1490 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821491 NarSize: 1361492=== NAME TestClientPushesUseOnePush1493 client_pushes_test.go:97: Retrieved narinfo from S3:1494 StorePath: /build/TestClientPushesUseOnePush2207782982/001/store/iiw3xkh5l01jy3sq9ifr64sy9npmxhpw-shared-dep1495 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1496 Compression: zstd1497 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821498 NarSize: 1361499 References: 1500 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1501=== NAME TestClientSharedPathCommittedMidPush1502 References: 1503 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15042026/10/08 12:57:29 INFO Completed push id=1 objects=4 duration=6.170159ms15052026/10/08 12:57:29 INFO Upload complete. (65ms)1506=== NAME TestClientPushesUseOnePush1507 client_pushes_test.go:97: Retrieved narinfo from S3:1508 StorePath: /build/TestClientPushesUseOnePush2207782982/001/store/lshknnfhb7wjqpm957yf9i4w7bivfvhr-a1509 URL: nar/1sizqghgk4ws54j1n7hlk8jbqmhyd9iaab5qdk7df9158rh28wn3.nar.zst1510 Compression: zstd1511 NarHash: sha256:1sizqghgk4ws54j1n7hlk8jbqmhyd9iaab5qdk7df9158rh28wn31512 NarSize: 2161513 References: /build/TestClientPushesUseOnePush2207782982/001/store/iiw3xkh5l01jy3sq9ifr64sy9npmxhpw-shared-dep1514 CA: text:sha256:0ghjg2k8yszjqnwrlpl24z18nyjd90hlkpf9wyy6h1dy5p7cyyn11515=== NAME TestClientSharedPathCommittedMidPush1516 client_integration_test.go:680: Retrieved narinfo from S3:1517 StorePath: /build/TestClientSharedPathCommittedMidPush475956225/001/store/3h471icxw8v9xh8y7xic5gsx60whjx7y-top1518 URL: nar/0k6fw68l9kvfp10xl1x4hg4f2ala0r0abqbciy05riil2zww7zj4.nar.zst1519 Compression: zstd1520 NarHash: sha256:0k6fw68l9kvfp10xl1x4hg4f2ala0r0abqbciy05riil2zww7zj41521 NarSize: 2241522 References: /build/TestClientSharedPathCommittedMidPush475956225/001/store/xsdbv74kxg9q40fj3ss1sqsni2qcypaa-shared-dep1523 CA: text:sha256:0bsbgpd8w35kl22nlsm2g1ifhjhyvimpilg80h5n7bbgxjgrxrc31524=== NAME TestClientWithDependencies1525 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2283181806/001/store) requires matching store prefix1526=== NAME TestClientPushesUseOnePush1527 client_pushes_test.go:97: Retrieved narinfo from S3:1528 StorePath: /build/TestClientPushesUseOnePush2207782982/001/store/0dmdfcwg9g4iivwb2yb7d15s040i9a5d-b1529 URL: nar/1sizqghgk4ws54j1n7hlk8jbqmhyd9iaab5qdk7df9158rh28wn3.nar.zst1530 Compression: zstd1531 NarHash: sha256:1sizqghgk4ws54j1n7hlk8jbqmhyd9iaab5qdk7df9158rh28wn31532 NarSize: 2161533 References: /build/TestClientPushesUseOnePush2207782982/001/store/iiw3xkh5l01jy3sq9ifr64sy9npmxhpw-shared-dep1534 CA: text:sha256:0ghjg2k8yszjqnwrlpl24z18nyjd90hlkpf9wyy6h1dy5p7cyyn11535--- PASS: TestClientWithDependencies (0.69s)1536=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15372026/10/08 12:57:29 INFO Received uploads request method=POST path=/1538=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15392026/10/08 12:57:29 INFO Received request for more parts method=POST path=/1540--- PASS: TestClientSharedPathCommittedMidPush (0.66s)1541=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15422026/10/08 12:57:29 INFO Received complete multipart upload request method=POST path=/1543=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1544=== CONT TestIsValidUploadKey/narinfo15452026/10/08 12:57:29 INFO Received uploads request method=POST path=/1546=== CONT TestIsValidUploadKey/realisation_plus_in_output1547--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1548 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1549 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1550 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1551 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1552=== CONT TestIsValidUploadKey/unknown_type1553=== CONT TestIsValidUploadKey/absolute1554=== CONT TestIsValidUploadKey/traversal_nar1555=== CONT TestIsValidUploadKey/traversal1556=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1557=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1558=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1559=== CONT TestIsValidUploadKey/empty_key1560=== CONT TestIsValidUploadKey/build_log_home-manager_file1561=== CONT TestIsValidUploadKey/realisation1562=== CONT TestIsValidUploadKey/index.html1563=== CONT TestIsValidUploadKey/build_log_question_mark1564=== CONT TestIsValidUploadKey/build_log_plus_in_name1565--- PASS: TestClientPushesUseOnePush (0.75s)1566=== CONT TestIsValidUploadKey/nix-cache-info1567=== CONT TestIsValidUploadKey/build_log_equals1568=== CONT TestIsValidUploadKey/nar_plain1569=== CONT TestIsValidUploadKey/nar_xz1570=== CONT TestIsValidUploadKey/nar_zst1571=== CONT TestIsValidUploadKey/build_log1572=== CONT TestPendingClosureWriteTimeout/670k_objects1573=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1574=== CONT TestIsValidUploadKey/listing1575--- PASS: TestIsValidUploadKey (0.00s)1576 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1577 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1578 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1579 --- PASS: TestIsValidUploadKey/absolute (0.00s)1580 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1581 --- PASS: TestIsValidUploadKey/traversal (0.00s)1582 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1583 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1584 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1585 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1586 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1587 --- PASS: TestIsValidUploadKey/realisation (0.00s)1588 --- PASS: TestIsValidUploadKey/index.html (0.00s)1589 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1590 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1591 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1592 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1593 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1594 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1595 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1596 --- PASS: TestIsValidUploadKey/build_log (0.00s)1597 --- PASS: TestIsValidUploadKey/listing (0.00s)1598=== CONT TestPendingClosureWriteTimeout/empty15992026/10/08 12:57:29 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=01600=== CONT TestPendingClosureWriteTimeout/400_objects1601=== CONT TestProxyWriteTimeout/narinfo1602=== CONT TestProxyWriteTimeout/10_GiB_nar1603=== CONT TestProxyWriteTimeout/1_GiB_nar1604=== CONT TestProxyWriteTimeout/unknown_size1605--- PASS: TestProxyWriteTimeout (0.00s)1606 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1607 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1608 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1609 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1610=== CONT TestPush_RejectsBadRequests/no_roots16112026/10/08 12:57:29 INFO Received push request method=POST path=/api/pushes1612=== CONT TestPush_RejectsBadRequests/bad_root16132026/10/08 12:57:29 INFO Received push request method=POST path=/api/pushes1614=== CONT TestPush_RejectsBadRequests/root_not_in_objects1615=== CONT TestPush_RejectsBadRequests/no_objects16162026/10/08 12:57:29 INFO Received push request method=POST path=/api/pushes16172026/10/08 12:57:29 INFO Received push request method=POST path=/api/pushes1618=== CONT TestIsValidCachePath/narinfo1619=== CONT TestIsValidCachePath/short_hash1620=== CONT TestIsValidCachePath/wrong_extension1621=== CONT TestIsValidCachePath/leading_slash1622=== CONT TestIsValidCachePath/empty1623=== CONT TestIsValidCachePath/random_path1624=== CONT TestIsValidCachePath/invalid_char_u1625=== CONT TestIsValidCachePath/invalid_char_e1626=== CONT TestIsValidCachePath/traversal_in_middle1627=== CONT TestIsValidCachePath/traversal_parent1628=== CONT TestIsValidCachePath/nar_uncompressed1629=== CONT TestIsValidCachePath/nix-cache-info1630=== CONT TestIsValidCachePath/realisation1631=== CONT TestIsValidCachePath/log1632=== CONT TestIsValidCachePath/ls1633=== CONT TestIsValidCachePath/nar_xz1634=== CONT TestIsValidCachePath/index.html1635--- PASS: TestPush_RejectsBadRequests (0.61s)1636 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1637 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1638 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1639 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1640=== CONT TestIsValidCachePath/nar_bz21641=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1642=== CONT TestIsValidCachePath/nar_zst1643--- PASS: TestIsValidCachePath (0.00s)1644 --- PASS: TestIsValidCachePath/narinfo (0.00s)1645 --- PASS: TestIsValidCachePath/short_hash (0.00s)1646 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1647 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1648 --- PASS: TestIsValidCachePath/empty (0.00s)1649 --- PASS: TestIsValidCachePath/random_path (0.00s)1650 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1651 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1652 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1653 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1654 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1655 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1656 --- PASS: TestIsValidCachePath/realisation (0.00s)1657 --- PASS: TestIsValidCachePath/log (0.00s)1658 --- PASS: TestIsValidCachePath/ls (0.00s)1659 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1660 --- PASS: TestIsValidCachePath/index.html (0.00s)1661 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1662 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1663 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1664=== CONT TestParseSingleRange/none1665=== CONT TestParseSingleRange/open-ended1666=== CONT TestParseSingleRange/start_past_EOF1667=== CONT TestParseSingleRange/single_byte1668=== CONT TestParseSingleRange/suffix_exceeds_size1669=== CONT TestParseSingleRange/suffix1670=== CONT TestParseSingleRange/end_clamped_to_size1671=== CONT TestParseSingleRange/malformed_both_empty1672=== CONT TestParseSingleRange/closed1673=== CONT TestParseSingleRange/malformed_end_before_start1674=== CONT TestParseSingleRange/multi-range_ignored1675=== CONT TestParseSingleRange/malformed_no_dash1676=== CONT TestParseSingleRange/unknown_unit1677=== CONT TestParseSingleRange/start_far_past_EOF1678=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1679--- PASS: TestParseSingleRange (0.00s)1680 --- PASS: TestParseSingleRange/none (0.00s)1681 --- PASS: TestParseSingleRange/open-ended (0.00s)1682 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1683 --- PASS: TestParseSingleRange/single_byte (0.00s)1684 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1685 --- PASS: TestParseSingleRange/suffix (0.00s)1686 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1687 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1688 --- PASS: TestParseSingleRange/closed (0.00s)1689 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1690 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1691 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1692 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1693 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1694=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16952026/10/08 12:57:29 INFO Vacuumed table table=pending_closures1696=== NAME TestClientMultipleUploads1697 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads578872097/001/store/1pl7kl27sdh6v2marfbcd98l60jfbkm3-test-file-2.txt16982026/10/08 12:57:29 INFO Vacuumed table table=pending_objects1699=== CONT TestGCEndsOnShutdown/before_the_run17002026/10/08 12:57:29 INFO Vacuumed table table=multipart_uploads17012026/10/08 12:57:29 INFO Vacuumed table table=closures17022026/10/08 12:57:29 INFO Vacuumed table table=objects17032026/10/08 12:57:29 INFO Received push request method=POST path=/api/pushes17042026/10/08 12:57:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17052026/10/08 12:57:29 INFO Uploading dadyg0sss1ff6x9b3x3waw08hgnsf8mv-pinned-file.txt (128B)1706=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1707=== RUN TestService_RequireScope_OIDC/builder_may_write1708=== PAUSE TestService_RequireScope_OIDC/builder_may_write1709=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1710=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1711=== RUN TestService_RequireScope_OIDC/ops_may_admin1712=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1713=== RUN TestService_RequireScope_OIDC/ops_may_not_write1714=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1715=== RUN TestService_RequireScope_OIDC/reader_may_not_write1716=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1717=== RUN TestService_RequireScope_OIDC/static_token_may_admin1718=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1719=== RUN TestService_RequireScope_OIDC/static_token_may_write1720=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1721=== RUN TestService_RequireScope_OIDC/reader_may_read1722=== PAUSE TestService_RequireScope_OIDC/reader_may_read1723=== RUN TestService_RequireScope_OIDC/writer_implies_read1724=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1725=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1726=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1727=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1728=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1729=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1730=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1731=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1732=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1733=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1734=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1735=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17362026/10/08 12:57:29 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17372026/10/08 12:57:29 WARN Failed to register uploaded object key=dadyg0sss1ff6x9b3x3waw08hgnsf8mv.ls error="server returned 404: 404 page not found\n"17382026/10/08 12:57:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17392026/10/08 12:57:29 INFO Signed narinfos id=1 count=117402026/10/08 12:57:29 INFO Uploading 1 narinfos17412026/10/08 12:57:29 INFO Received complete push request method=POST path=/api/pushes/1/complete17422026/10/08 12:57:29 WARN Failed to register uploaded object key=dadyg0sss1ff6x9b3x3waw08hgnsf8mv.narinfo error="server returned 404: 404 page not found\n"1743--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.71s)1744=== CONT TestServerTLSConfig/no_client_CA1745=== CONT TestServerTLSConfig/not_a_PEM_file1746=== CONT TestServerTLSConfig/missing_CA_file1747--- PASS: TestServerTLSConfig (0.00s)1748 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1749 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1750 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)17512026/10/08 12:57:30 INFO Completed push id=1 objects=3 duration=9.210803ms1752=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17532026/10/08 12:57:30 INFO Upload complete. (98ms)1754--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.29s)1755=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17562026/10/08 12:57:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17572026/10/08 12:57:30 WARN mTLS auth: bound subjects configured but subject DN unavailable17582026/10/08 12:57:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1759--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.30s)1760=== CONT TestResolveDBConnectionString/flag_wins1761=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1762=== CONT TestResolveDBConnectionString/nothing_configured1763=== CONT TestResolveDBConnectionString/missing_file_is_an_error1764=== CONT TestResolveDBConnectionString/file_when_flag_empty1765=== CONT TestClientErrorHandling/InvalidStorePath1766--- PASS: TestResolveDBConnectionString (0.00s)1767 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1768 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1769 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1770 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1771 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17722026/10/08 12:57:30 INFO Received push request method=POST path=/api/pushes17732026/10/08 12:57:30 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17742026/10/08 12:57:30 INFO Uploading 4kygy5mw3y5z1j4r3cx04ynwzk6w4609-test-file-1.txt (160B)17752026/10/08 12:57:30 INFO Uploading 1pl7kl27sdh6v2marfbcd98l60jfbkm3-test-file-2.txt (160B)17762026/10/08 12:57:30 INFO Uploading 8fg9aiw884hgzs0zsjmaf3ahipzy3fwc-test-file-0.txt (160B)17772026/10/08 12:57:30 WARN Failed to register uploaded object key=4kygy5mw3y5z1j4r3cx04ynwzk6w4609.ls error="server returned 404: 404 page not found\n"17782026/10/08 12:57:30 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17792026/10/08 12:57:30 WARN Failed to register uploaded object key=1pl7kl27sdh6v2marfbcd98l60jfbkm3.ls error="server returned 404: 404 page not found\n"17802026/10/08 12:57:30 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17812026/10/08 12:57:30 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17822026/10/08 12:57:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17832026/10/08 12:57:30 WARN Failed to register uploaded object key=8fg9aiw884hgzs0zsjmaf3ahipzy3fwc.ls error="server returned 404: 404 page not found\n"17842026/10/08 12:57:30 INFO Signed narinfos id=1 count=317852026/10/08 12:57:30 INFO Uploading 3 narinfos17862026/10/08 12:57:30 WARN Failed to register uploaded object key=4kygy5mw3y5z1j4r3cx04ynwzk6w4609.narinfo error="server returned 404: 404 page not found\n"17872026/10/08 12:57:30 WARN Failed to register uploaded object key=8fg9aiw884hgzs0zsjmaf3ahipzy3fwc.narinfo error="server returned 404: 404 page not found\n"17882026/10/08 12:57:30 INFO Received complete push request method=POST path=/api/pushes/1/complete17892026/10/08 12:57:30 WARN Failed to register uploaded object key=1pl7kl27sdh6v2marfbcd98l60jfbkm3.narinfo error="server returned 404: 404 page not found\n"1790=== NAME TestClientCADerivations1791 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations523885247/001/store/s23xfz8hj5l5mirbvm5h679lky4h6dl1-ca-test17922026/10/08 12:57:30 INFO Completed push id=1 objects=9 duration=22.595469ms17932026/10/08 12:57:30 INFO Upload complete. (83ms)1794=== NAME TestClientMultipleUploads1795 client_integration_test.go:369: Uploaded 3 paths in 133.956843ms1796--- PASS: TestClientMultipleUploads (0.70s)1797=== CONT TestClientErrorHandling/ServerNotAvailable17982026/10/08 12:57:30 INFO Received push request method=POST path=/api/pushes17992026/10/08 12:57:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18002026/10/08 12:57:30 INFO Uploading g0lhdqciiilayy7g23ziykksac2y5z1q-unpinned-file.txt (128B)18012026/10/08 12:57:30 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18022026/10/08 12:57:30 WARN Failed to register uploaded object key=g0lhdqciiilayy7g23ziykksac2y5z1q.ls error="server returned 404: 404 page not found\n"18032026/10/08 12:57:30 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18042026/10/08 12:57:30 INFO Signed narinfos id=2 count=118052026/10/08 12:57:30 INFO Uploading 1 narinfos18062026/10/08 12:57:30 INFO Received complete push request method=POST path=/api/pushes/2/complete18072026/10/08 12:57:30 WARN Failed to register uploaded object key=g0lhdqciiilayy7g23ziykksac2y5z1q.narinfo error="server returned 404: 404 page not found\n"1808=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1809=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1810=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1811=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1812=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1813=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1814=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1815=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1816=== CONT TestClientErrorHandling/InvalidAuthToken18172026/10/08 12:57:30 INFO Completed push id=2 objects=3 duration=5.43774ms18182026/10/08 12:57:30 INFO Upload complete. (70ms)1819=== NAME TestClientCADerivations1820 client_ca_test.go:139: Found 1 dependencies (including self)18212026/10/08 12:57:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures18222026/10/08 12:57:30 INFO Garbage collection started18232026/10/08 12:57:30 INFO Received uploads request method=POST path=/api/pending_closures18242026/10/08 12:57:30 INFO Received uploads request method=POST path=/api/pending_closures18252026/10/08 12:57:30 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18262026/10/08 12:57:30 INFO Uploading kmi08wk4whcqmdjfdhzxpqvz51ckk7d3-b (216B)18272026/10/08 12:57:30 INFO Uploading chdlbrx66dx7i97zsdnk0w202h68nazy-shared-dep (136B)18282026/10/08 12:57:30 INFO Aborted multipart uploads count=0 kept=018292026/10/08 12:57:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18302026/10/08 12:57:30 WARN Failed to register uploaded object key=nar/0msz2fnfdrvgxkx1xq77r19bgl2b7x63d542q24w5j4ln57vlk12.nar.zst error="server returned 404: 404 page not found\n"18312026/10/08 12:57:30 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18322026/10/08 12:57:30 WARN Failed to register uploaded object key=blh4jmv362x3skkaksavy5qrh991xab4.ls error="server returned 404: 404 page not found\n"18332026/10/08 12:57:30 WARN Failed to register uploaded object key=chdlbrx66dx7i97zsdnk0w202h68nazy.ls error="server returned 404: 404 page not found\n"18342026/10/08 12:57:30 WARN Force mode enabled - objects will be deleted immediately without grace period18352026/10/08 12:57:30 INFO lead: released remote=192.0.2.1:123418362026/10/08 12:57:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1837--- PASS: TestLeadEndsOnShutdown (1.62s)1838=== CONT TestCacheConfigHandler/full_config,_no_issuer18392026/10/08 12:57:30 WARN Failed to register uploaded object key=kmi08wk4whcqmdjfdhzxpqvz51ckk7d3.ls error="server returned 404: 404 page not found\n"1840=== CONT TestCacheConfigHandler/no_signing_keys18412026/10/08 12:57:30 INFO Received uploads request method=POST path=/api/pending_closures1842=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator18432026/10/08 12:57:30 INFO Signed narinfos id=1 count=21844=== CONT TestCacheConfigHandler/no_cache_url_configured1845=== CONT TestService_RequireScope_OIDC/builder_may_write1846--- PASS: TestCacheConfigHandler (0.00s)1847 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1848 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1849 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1850 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)18512026/10/08 12:57:30 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18522026/10/08 12:57:30 INFO Signed narinfos id=2 count=218532026/10/08 12:57:30 INFO Uploading 4 narinfos1854=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1855=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1856=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1857=== CONT TestService_RequireScope_OIDC/writer_implies_read1858=== CONT TestService_RequireScope_OIDC/reader_may_read1859=== CONT TestService_RequireScope_OIDC/static_token_may_write1860=== CONT TestService_RequireScope_OIDC/static_token_may_admin1861=== CONT TestService_RequireScope_OIDC/reader_may_not_write1862=== CONT TestService_RequireScope_OIDC/ops_may_not_write1863=== CONT TestService_RequireScope_OIDC/ops_may_admin1864=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1865=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1866=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18672026/10/08 12:57:30 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1868=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1869--- PASS: TestService_RequireScope_OIDC (0.30s)1870 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1871 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1872 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1873 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1874 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1875 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1876 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1877 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1878 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1879 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1880 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1881 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1882 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1883 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1884=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18852026/10/08 12:57:30 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1886=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1887=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18882026/10/08 12:57:30 WARN Failed to register uploaded object key=chdlbrx66dx7i97zsdnk0w202h68nazy.narinfo error="server returned 404: 404 page not found\n"18892026/10/08 12:57:30 WARN Failed to register uploaded object key=kmi08wk4whcqmdjfdhzxpqvz51ckk7d3.narinfo error="server returned 404: 404 page not found\n"18902026/10/08 12:57:30 WARN Failed to register uploaded object key=blh4jmv362x3skkaksavy5qrh991xab4.narinfo error="server returned 404: 404 page not found\n"18912026/10/08 12:57:30 WARN Authentication failed token_preview=eyJhbGciOi...aZL-zQO3Ng token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1892--- PASS: TestService_AuthMiddleware_OIDC (0.28s)1893 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1894 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1895 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1896 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18972026/10/08 12:57:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18982026/10/08 12:57:30 WARN Failed to register uploaded object key=chdlbrx66dx7i97zsdnk0w202h68nazy.narinfo error="server returned 404: 404 page not found\n"18992026/10/08 12:57:30 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=019002026/10/08 12:57:30 INFO Completed upload id=1 objects=6 duration=7.015587ms19012026/10/08 12:57:30 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.9897ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19022026/10/08 12:57:30 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19032026/10/08 12:57:30 INFO Completed upload id=2 objects=6 duration=941.759µs19042026/10/08 12:57:30 INFO Upload complete. (188ms)1905=== NAME TestClientFallsBackToClosures1906 client_pushes_test.go:112: Retrieved narinfo from S3:1907 StorePath: /build/TestClientFallsBackToClosures1310444317/001/store/chdlbrx66dx7i97zsdnk0w202h68nazy-shared-dep1908 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1909 Compression: zstd1910 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821911 NarSize: 1361912 References: 19132026/10/08 12:57:30 INFO Vacuumed table table=pending_closures1914 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1915 client_pushes_test.go:112: Retrieved narinfo from S3:1916 StorePath: /build/TestClientFallsBackToClosures1310444317/001/store/blh4jmv362x3skkaksavy5qrh991xab4-a1917 URL: nar/0msz2fnfdrvgxkx1xq77r19bgl2b7x63d542q24w5j4ln57vlk12.nar.zst1918 Compression: zstd1919 NarHash: sha256:0msz2fnfdrvgxkx1xq77r19bgl2b7x63d542q24w5j4ln57vlk121920 NarSize: 2161921 References: /build/TestClientFallsBackToClosures1310444317/001/store/chdlbrx66dx7i97zsdnk0w202h68nazy-shared-dep1922 CA: text:sha256:05h0lmpnkx168vqsk0xranyy50nmg6h69dryb5z1c379mri53hyf19232026/10/08 12:57:30 INFO Vacuumed table table=pending_objects19242026/10/08 12:57:30 INFO Vacuumed table table=multipart_uploads1925 client_pushes_test.go:112: Retrieved narinfo from S3:1926 StorePath: /build/TestClientFallsBackToClosures1310444317/001/store/kmi08wk4whcqmdjfdhzxpqvz51ckk7d3-b1927 URL: nar/0msz2fnfdrvgxkx1xq77r19bgl2b7x63d542q24w5j4ln57vlk12.nar.zst1928 Compression: zstd1929 NarHash: sha256:0msz2fnfdrvgxkx1xq77r19bgl2b7x63d542q24w5j4ln57vlk121930 NarSize: 2161931 References: /build/TestClientFallsBackToClosures1310444317/001/store/chdlbrx66dx7i97zsdnk0w202h68nazy-shared-dep1932 CA: text:sha256:05h0lmpnkx168vqsk0xranyy50nmg6h69dryb5z1c379mri53hyf19332026/10/08 12:57:30 INFO Vacuumed table table=closures19342026/10/08 12:57:30 INFO Vacuumed table table=objects1935--- PASS: TestClientFallsBackToClosures (0.84s)19362026/10/08 12:57:30 INFO Received push request method=POST path=/api/pushes19372026/10/08 12:57:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19382026/10/08 12:57:30 INFO Uploading s23xfz8hj5l5mirbvm5h679lky4h6dl1-ca-test (144B)19392026/10/08 12:57:30 WARN Failed to register uploaded object key=s23xfz8hj5l5mirbvm5h679lky4h6dl1.ls error="server returned 404: 404 page not found\n"19402026/10/08 12:57:30 WARN Failed to register uploaded object key=log/jp8mv1x77ciz6wag1v630vn251zcfcaz-ca-test.drv error="server returned 404: 404 page not found\n"19412026/10/08 12:57:30 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19422026/10/08 12:57:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19432026/10/08 12:57:30 INFO Signed narinfos id=1 count=119442026/10/08 12:57:30 INFO Uploading 1 narinfos19452026/10/08 12:57:30 INFO Received complete push request method=POST path=/api/pushes/1/complete19462026/10/08 12:57:30 WARN Failed to register uploaded object key=s23xfz8hj5l5mirbvm5h679lky4h6dl1.narinfo error="server returned 404: 404 page not found\n"19472026/10/08 12:57:30 INFO Aborted multipart uploads count=0 kept=019482026/10/08 12:57:30 INFO Completed push id=1 objects=4 duration=5.775339ms19492026/10/08 12:57:30 INFO Upload complete. (161ms)19502026/10/08 12:57:30 WARN Force mode enabled - objects will be deleted immediately without grace period1951=== NAME TestClientCADerivations1952 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations523885247/001/store/s23xfz8hj5l5mirbvm5h679lky4h6dl1-ca-test1953 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1954 Compression: zstd1955 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1956 NarSize: 1441957 References: 1958 Deriver: /build/TestClientCADerivations523885247/001/store/jp8mv1x77ciz6wag1v630vn251zcfcaz-ca-test.drv1959 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1960 client_ca_test.go:185: Checking for realisation files in S3...1961 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1962 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19632026/10/08 12:57:30 INFO Aborted multipart uploads count=0 kept=019642026/10/08 12:57:30 WARN Force mode enabled - objects will be deleted immediately without grace period19652026/10/08 12:57:30 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:46489/bucket95/?delete=\": context canceled"1966--- PASS: TestGCEndsOnShutdown (0.00s)1967 --- PASS: TestGCEndsOnShutdown/before_the_run (0.38s)1968 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.38s)1969 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.38s)19702026/10/08 12:57:30 INFO Received uploads request method=POST path=/api/pending_closures19712026/10/08 12:57:30 INFO Aborted multipart uploads count=0 kept=019722026/10/08 12:57:30 WARN Force mode enabled - objects will be deleted immediately without grace period19732026/10/08 12:57:30 INFO Received uploads request method=POST path=/api/pending_closures19742026/10/08 12:57:30 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=019752026/10/08 12:57:30 INFO Vacuumed table table=pending_closures19762026/10/08 12:57:30 INFO Vacuumed table table=pending_objects19772026/10/08 12:57:30 INFO Vacuumed table table=multipart_uploads19782026/10/08 12:57:30 INFO Vacuumed table table=closures19792026/10/08 12:57:30 INFO Vacuumed table table=objects19802026/10/08 12:57:30 INFO Aborted multipart uploads count=0 kept=019812026/10/08 12:57:30 WARN Force mode enabled - objects will be deleted immediately without grace period19822026/10/08 12:57:30 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019832026/10/08 12:57:30 INFO Vacuumed table table=pending_closures19842026/10/08 12:57:30 INFO Vacuumed table table=pending_objects19852026/10/08 12:57:30 INFO Vacuumed table table=multipart_uploads19862026/10/08 12:57:30 INFO Vacuumed table table=closures19872026/10/08 12:57:30 INFO Vacuumed table table=objects1988--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1989 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.41s)1990 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.42s)19912026/10/08 12:57:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=390.869211ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1992=== NAME TestClientCADerivations1993 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1994 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1995 error: binary cache 's3://bucket86?endpoint=http://localhost:46489®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations523885247/001/store'1996 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11997--- PASS: TestClientCADerivations (0.88s)19982026/10/08 12:57:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1999=== NAME TestOrphanedObjectsGCStressTest2000 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains20012026/10/08 12:57:30 INFO lead: released remote=192.0.2.1:12342002 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20032026/10/08 12:57:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20042026/10/08 12:57:30 INFO lead: acquired remote=192.0.2.1:12342005--- PASS: TestUploadHandlersRejectOversizedBody (0.22s)2006 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2007 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2008 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.77s)2009--- PASS: TestDeleteClosuresRacingPins (1.32s)2010=== NAME TestOrphanedObjectsGCStressTest2011 orphaned_objects_gc_test.go:503: Stress test completed successfully:2012 orphaned_objects_gc_test.go:504: - Active objects preserved: 202013 orphaned_objects_gc_test.go:505: - Objects deleted: 2102014 orphaned_objects_gc_test.go:506: - Total GC'd: 2102015--- PASS: TestOrphanedObjectsGCStressTest (2.75s)20162026/10/08 12:57:30 WARN Rate limiter enabled after throttle name=s3-test rate=520172026/10/08 12:57:30 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2018=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2019 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102020 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002021--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.51s)2022--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2023 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.85s)2024 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.93s)20252026/10/08 12:57:30 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=863.597515ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2026--- PASS: TestPendingClosureWriteTimeout (0.00s)2027 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2028 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2029 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2030 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.14s)20312026/10/08 12:57:31 INFO lead: released remote=192.0.2.1:12342032--- PASS: TestLeadElectsOneAndHandsOver (2.89s)20332026/10/08 12:57:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.700066721s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20342026/10/08 12:57:31 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02035=== NAME TestClientIntegration2036 client_integration_test.go:323: Objects in database after GC:2037 client_integration_test.go:323: Successfully deleted all objects with GC --force2038--- PASS: TestClientIntegration (2.77s)20392026/10/08 12:57:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020402026/10/08 12:57:32 INFO Received create pin request method=POST path=/api/pins/myapp20412026/10/08 12:57:32 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3648073092/001/store/dadyg0sss1ff6x9b3x3waw08hgnsf8mv-pinned-file.txt narinfo_key=dadyg0sss1ff6x9b3x3waw08hgnsf8mv.narinfo20422026/10/08 12:57:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures20432026/10/08 12:57:32 INFO Garbage collection started20442026/10/08 12:57:32 INFO Aborted multipart uploads count=0 kept=020452026/10/08 12:57:32 WARN Force mode enabled - objects will be deleted immediately without grace period20462026/10/08 12:57:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020472026/10/08 12:57:32 INFO Vacuumed table table=pending_closures20482026/10/08 12:57:32 INFO Vacuumed table table=pending_objects20492026/10/08 12:57:32 INFO Vacuumed table table=multipart_uploads20502026/10/08 12:57:32 INFO Vacuumed table table=closures20512026/10/08 12:57:32 INFO Vacuumed table table=objects2052--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.26s)20532026/10/08 12:57:33 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20542026/10/08 12:57:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.246666ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2055--- PASS: TestConnectWaitsForAPeerMigration (5.18s)20562026/10/08 12:57:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=367.884541ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2057=== NAME TestPinProtectsFromGC2058 client_integration_test.go:840: Pin successfully protected closure from garbage collection2059--- PASS: TestPinProtectsFromGC (4.86s)20602026/10/08 12:57:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=840.650074ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20612026/10/08 12:57:35 INFO Aborted multipart uploads count=1 kept=020622026/10/08 12:57:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.661436044s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20632026/10/08 12:57:35 INFO Received cleanup request method=DELETE path=/api/pending_closures20642026/10/08 12:57:35 INFO Aborted multipart uploads count=1 kept=02065--- PASS: TestPendingCleanupUsesOneCutoff (6.63s)20662026/10/08 12:57:36 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"20672026/10/08 12:57:36 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-config20682026/10/08 12:57:36 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.07212ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20692026/10/08 12:57:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.542959ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20702026/10/08 12:57:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=846.867945ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20712026/10/08 12:57:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.580112535s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20722026/10/08 12:57:39 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_closures20732026/10/08 12:57:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.187828ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20742026/10/08 12:57:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.553161ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20752026/10/08 12:57:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=804.270135ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20762026/10/08 12:57:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.74590265s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2077--- PASS: TestClientErrorHandling (0.00s)2078 --- PASS: TestClientErrorHandling/InvalidStorePath (0.41s)2079 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.46s)2080 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.95s)2081PASS20822026-10-08 12:57:43.495 UTC [131] LOG: received smart shutdown request20832026-10-08 12:57:43.499 UTC [131] LOG: background worker "logical replication launcher" (PID 141) exited with exit code 120842026-10-08 12:57:43.514 UTC [136] LOG: shutting down20852026-10-08 12:57:43.515 UTC [136] LOG: checkpoint starting: shutdown immediate20862026-10-08 12:57:45.816 UTC [136] LOG: checkpoint complete: wrote 10764 buffers (65.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.318 s, sync=1.912 s, total=2.302 s; sync files=34045, longest=0.051 s, average=0.001 s; distance=531556 kB, estimate=531556 kB; lsn=0/21E7F018, redo lsn=0/21E7F01820872026-10-08 12:57:45.905 UTC [131] LOG: database system is shut down2088Running OIDC tests...2089=== RUN TestAudienceForIssuer2090=== PAUSE TestAudienceForIssuer2091=== RUN TestGlobMatch2092=== PAUSE TestGlobMatch2093=== RUN TestValidateToken_ValidToken2094=== PAUSE TestValidateToken_ValidToken2095=== RUN TestValidateToken_WrongAudience2096=== PAUSE TestValidateToken_WrongAudience2097=== RUN TestValidateToken_Expired2098=== PAUSE TestValidateToken_Expired2099=== RUN TestValidateToken_BoundClaimsMismatch2100=== PAUSE TestValidateToken_BoundClaimsMismatch2101=== RUN TestValidateToken_BoundSubjectMismatch2102=== PAUSE TestValidateToken_BoundSubjectMismatch2103=== RUN TestValidateToken_MultipleProviders2104=== PAUSE TestValidateToken_MultipleProviders2105=== RUN TestValidateToken_NoMatchingProvider2106=== PAUSE TestValidateToken_NoMatchingProvider2107=== RUN TestValidateToken_KubernetesServiceAccount2108=== PAUSE TestValidateToken_KubernetesServiceAccount2109=== RUN TestNewValidator_KubernetesRequiresCA2110=== PAUSE TestNewValidator_KubernetesRequiresCA2111=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2112=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2113=== RUN TestPins_ReservedForMatchingRule2114=== PAUSE TestPins_ReservedForMatchingRule2115=== RUN TestPins_TopLevelShorthand2116=== PAUSE TestPins_TopLevelShorthand2117=== RUN TestPins_ConfigValidation2118=== PAUSE TestPins_ConfigValidation2119=== RUN TestScopes_LegacyProviderDefaultsToWrite2120=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2121=== RUN TestScopes_Rules2122=== PAUSE TestScopes_Rules2123=== RUN TestScopes_ConfigValidation2124=== PAUSE TestScopes_ConfigValidation2125=== CONT TestAudienceForIssuer2126=== CONT TestPins_ConfigValidation2127--- PASS: TestAudienceForIssuer (0.00s)2128=== CONT TestScopes_Rules2129=== CONT TestValidateToken_KubernetesServiceAccount2130=== CONT TestPins_TopLevelShorthand2131=== CONT TestPins_ReservedForMatchingRule2132--- PASS: TestPins_ConfigValidation (0.00s)2133=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2134=== CONT TestNewValidator_KubernetesRequiresCA2135=== CONT TestScopes_LegacyProviderDefaultsToWrite2136=== CONT TestScopes_ConfigValidation2137=== CONT TestValidateToken_BoundClaimsMismatch2138=== CONT TestValidateToken_NoMatchingProvider2139=== CONT TestValidateToken_MultipleProviders2140--- PASS: TestScopes_ConfigValidation (0.00s)2141=== CONT TestValidateToken_BoundSubjectMismatch2142=== CONT TestValidateToken_WrongAudience2143=== CONT TestValidateToken_Expired2144=== CONT TestValidateToken_ValidToken2145=== CONT TestGlobMatch2146=== RUN TestGlobMatch/foo_foo2147=== PAUSE TestGlobMatch/foo_foo2148=== RUN TestGlobMatch/foo_bar2149=== PAUSE TestGlobMatch/foo_bar2150=== RUN TestGlobMatch/*_2151=== PAUSE TestGlobMatch/*_2152=== RUN TestGlobMatch/*_anything2153=== PAUSE TestGlobMatch/*_anything2154=== RUN TestGlobMatch/foo*_foo2155=== PAUSE TestGlobMatch/foo*_foo2156=== RUN TestGlobMatch/foo*_foobar2157=== PAUSE TestGlobMatch/foo*_foobar2158=== RUN TestGlobMatch/foo*_bar2159=== PAUSE TestGlobMatch/foo*_bar2160=== RUN TestGlobMatch/*bar_bar2161=== PAUSE TestGlobMatch/*bar_bar2162=== RUN TestGlobMatch/*bar_foobar2163=== PAUSE TestGlobMatch/*bar_foobar2164=== RUN TestGlobMatch/*bar_foo2165=== PAUSE TestGlobMatch/*bar_foo2166=== RUN TestGlobMatch/foo*bar_foobar2167=== PAUSE TestGlobMatch/foo*bar_foobar2168=== RUN TestGlobMatch/foo*bar_foo123bar2169=== PAUSE TestGlobMatch/foo*bar_foo123bar2170=== RUN TestGlobMatch/foo*bar_foobarbaz2171=== PAUSE TestGlobMatch/foo*bar_foobarbaz2172=== RUN TestGlobMatch/*/*_foo/bar2173=== PAUSE TestGlobMatch/*/*_foo/bar2174=== RUN TestGlobMatch/*/*_foo2175=== PAUSE TestGlobMatch/*/*_foo2176=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2177=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2178=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02179=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02180=== RUN TestGlobMatch/refs/*/main_refs/heads/main2181=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2182=== RUN TestGlobMatch/fo?_foo2183=== PAUSE TestGlobMatch/fo?_foo2184=== RUN TestGlobMatch/fo?_fo2185=== PAUSE TestGlobMatch/fo?_fo2186=== RUN TestGlobMatch/fo?_fooo2187=== PAUSE TestGlobMatch/fo?_fooo2188=== RUN TestGlobMatch/?oo_foo2189=== PAUSE TestGlobMatch/?oo_foo2190=== RUN TestGlobMatch/?oo_boo2191=== PAUSE TestGlobMatch/?oo_boo2192=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2193=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2194=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2195=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2196=== CONT TestGlobMatch/foo_foo2197=== CONT TestGlobMatch/foo*bar_foobarbaz2198=== CONT TestGlobMatch/foo*bar_foo123bar2199=== CONT TestGlobMatch/foo*bar_foobar2200=== CONT TestGlobMatch/*bar_foo2201=== CONT TestGlobMatch/*bar_foobar2202=== CONT TestGlobMatch/*bar_bar2203=== CONT TestGlobMatch/foo*_bar2204=== CONT TestGlobMatch/foo*_foobar2205=== CONT TestGlobMatch/foo*_foo2206=== CONT TestGlobMatch/*_anything2207=== CONT TestGlobMatch/*_2208=== CONT TestGlobMatch/fo?_fo2209=== CONT TestGlobMatch/refs/*/main_refs/heads/main2210=== CONT TestGlobMatch/*/*_foo/bar2211=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2212=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2213=== CONT TestGlobMatch/?oo_boo2214=== CONT TestGlobMatch/?oo_foo2215=== CONT TestGlobMatch/fo?_fooo2216=== CONT TestGlobMatch/foo_bar2217=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02218=== CONT TestGlobMatch/fo?_foo2219=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2220=== CONT TestGlobMatch/*/*_foo2221--- PASS: TestGlobMatch (0.00s)2222 --- PASS: TestGlobMatch/foo_foo (0.00s)2223 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2224 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2225 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2226 --- PASS: TestGlobMatch/*bar_foo (0.00s)2227 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2228 --- PASS: TestGlobMatch/*bar_bar (0.00s)2229 --- PASS: TestGlobMatch/foo*_bar (0.00s)2230 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2231 --- PASS: TestGlobMatch/foo*_foo (0.00s)2232 --- PASS: TestGlobMatch/*_anything (0.00s)2233 --- PASS: TestGlobMatch/*_ (0.00s)2234 --- PASS: TestGlobMatch/fo?_fo (0.00s)2235 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2236 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2237 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2238 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2239 --- PASS: TestGlobMatch/?oo_boo (0.00s)2240 --- PASS: TestGlobMatch/?oo_foo (0.00s)2241 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2242 --- PASS: TestGlobMatch/foo_bar (0.00s)2243 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2244 --- PASS: TestGlobMatch/fo?_foo (0.00s)2245 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2246 --- PASS: TestGlobMatch/*/*_foo (0.00s)22472026/10/08 12:57:49 http: TLS handshake error from 127.0.0.1:57000: remote error: tls: bad certificate2248--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)22492026/10/08 12:57:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40513/oidc2250--- PASS: TestValidateToken_BoundSubjectMismatch (0.04s)22512026/10/08 12:57:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44099/oidc22522026/10/08 12:57:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34839/oidc2253--- PASS: TestValidateToken_ValidToken (0.04s)2254--- PASS: TestPins_TopLevelShorthand (0.05s)22552026/10/08 12:57:49 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4225322562026/10/08 12:57:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46593/oidc2257--- PASS: TestValidateToken_KubernetesServiceAccount (0.05s)2258--- PASS: TestScopes_Rules (0.06s)22592026/10/08 12:57:49 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232260--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)22612026/10/08 12:57:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43169/oidc2262--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)22632026/10/08 12:57:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43529/oidc2264--- PASS: TestValidateToken_WrongAudience (0.09s)22652026/10/08 12:57:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42019/oidc2266--- PASS: TestValidateToken_Expired (0.09s)22672026/10/08 12:57:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36119/oidc2268--- PASS: TestPins_ReservedForMatchingRule (0.12s)22692026/10/08 12:57:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37631/oidc2270--- PASS: TestValidateToken_NoMatchingProvider (0.12s)22712026/10/08 12:57:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38137/oidc2272--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.15s)22732026/10/08 12:57:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39875/oidc22742026/10/08 12:57:49 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:43289/oidc2275--- PASS: TestValidateToken_MultipleProviders (0.26s)2276PASS2277Running hook tests...2278=== RUN TestSendPathsEmpty2279=== PAUSE TestSendPathsEmpty2280=== RUN TestQueueEnqueueAndFetch2281=== PAUSE TestQueueEnqueueAndFetch2282=== RUN TestQueueDeduplication2283=== PAUSE TestQueueDeduplication2284=== RUN TestQueueRemove2285=== PAUSE TestQueueRemove2286=== RUN TestQueueFetchBatchLimit2287=== PAUSE TestQueueFetchBatchLimit2288=== RUN TestQueueRetryMovesToBack2289=== PAUSE TestQueueRetryMovesToBack2290=== RUN TestQueueFetchRemoveLifecycle2291=== PAUSE TestQueueFetchRemoveLifecycle2292=== RUN TestQueueConcurrentWriters2293=== PAUSE TestQueueConcurrentWriters2294=== RUN TestQueueRemoveLargeClosure2295=== PAUSE TestQueueRemoveLargeClosure2296=== RUN TestServerClientIntegration2297--- PASS: TestServerClientIntegration (0.00s)2298=== RUN TestServerQueueError22992026/10/08 12:57:49 ERROR Failed to queue paths error="permission denied" count=12300--- PASS: TestServerQueueError (0.00s)2301=== RUN TestGetListenerSocketActivation2302 server_test.go:219: === RUN TestGetListenerSocketActivation2303 --- PASS: TestGetListenerSocketActivation (0.00s)2304 PASS2305 2306--- PASS: TestGetListenerSocketActivation (0.01s)2307=== RUN TestDrainIsolatesPoisonPath2308=== PAUSE TestDrainIsolatesPoisonPath2309=== RUN TestRunNotBlockedByPoisonHead2310=== PAUSE TestRunNotBlockedByPoisonHead2311=== RUN TestDrainGivesUpWhenServerDown2312=== PAUSE TestDrainGivesUpWhenServerDown2313=== RUN TestFailedPathPrunedByLaterClosure2314=== PAUSE TestFailedPathPrunedByLaterClosure2315=== RUN TestWorkerUploadsAndRemoves2316=== PAUSE TestWorkerUploadsAndRemoves2317=== RUN TestWorkerSkipsGCdPaths2318=== PAUSE TestWorkerSkipsGCdPaths2319=== RUN TestWorkerPrunesClosureDeps2320=== PAUSE TestWorkerPrunesClosureDeps2321=== RUN TestDrainTimeout2322=== PAUSE TestDrainTimeout2323=== CONT TestSendPathsEmpty2324=== CONT TestWorkerPrunesClosureDeps2325--- PASS: TestSendPathsEmpty (0.00s)2326=== CONT TestDrainTimeout2327=== CONT TestDrainIsolatesPoisonPath2328=== CONT TestQueueRemoveLargeClosure2329=== CONT TestQueueConcurrentWriters2330=== CONT TestQueueFetchRemoveLifecycle2331=== CONT TestQueueRetryMovesToBack2332=== CONT TestQueueFetchBatchLimit2333=== CONT TestQueueRemove2334=== CONT TestQueueDeduplication2335=== CONT TestQueueEnqueueAndFetch2336=== CONT TestDrainGivesUpWhenServerDown2337=== CONT TestFailedPathPrunedByLaterClosure2338=== CONT TestWorkerSkipsGCdPaths2339=== CONT TestWorkerUploadsAndRemoves2340=== CONT TestRunNotBlockedByPoisonHead23412026/10/08 12:57:49 INFO Uploading batch count=223422026/10/08 12:57:49 ERROR Upload failed error="upload failed" count=223432026/10/08 12:57:49 INFO Uploading batch count=423442026/10/08 12:57:49 ERROR Upload failed error="upload failed" count=423452026/10/08 12:57:49 INFO Upload queue status pending=223462026/10/08 12:57:49 INFO Uploading batch count=223472026/10/08 12:57:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2276569081/002/a23482026/10/08 12:57:49 INFO Upload queue status pending=223492026/10/08 12:57:49 INFO Uploading batch count=123502026/10/08 12:57:49 INFO Uploading batch count=223512026/10/08 12:57:49 INFO Upload queue status pending=22352--- PASS: TestQueueFetchBatchLimit (0.02s)23532026/10/08 12:57:49 INFO Upload queue status pending=323542026/10/08 12:57:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3213584125/002/bbb23552026/10/08 12:57:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2276569081/002/b23562026/10/08 12:57:49 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2259896758/002/nonexistent2357--- PASS: TestQueueEnqueueAndFetch (0.02s)23582026/10/08 12:57:49 INFO Uploading batch count=123592026/10/08 12:57:49 ERROR Upload failed error="upload failed" count=123602026/10/08 12:57:49 INFO Uploading batch count=123612026/10/08 12:57:49 ERROR Upload failed error="upload failed" count=123622026/10/08 12:57:49 INFO Uploading batch count=22363--- PASS: TestQueueRemove (0.02s)23642026/10/08 12:57:49 INFO Uploading batch count=123652026/10/08 12:57:49 ERROR Upload failed error="upload failed" count=223662026/10/08 12:57:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2276569081/002/c23672026/10/08 12:57:49 INFO Uploading batch count=12368--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2369--- PASS: TestQueueRetryMovesToBack (0.02s)2370--- PASS: TestQueueDeduplication (0.02s)23712026/10/08 12:57:49 INFO Uploading batch count=123722026/10/08 12:57:49 ERROR Upload failed error="upload failed" count=123732026/10/08 12:57:49 INFO Uploading batch count=123742026/10/08 12:57:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2276569081/002/d23752026/10/08 12:57:49 INFO Uploading batch count=123762026/10/08 12:57:49 ERROR Upload failed error="upload failed" count=123772026/10/08 12:57:49 INFO Uploading batch count=123782026/10/08 12:57:49 ERROR Upload failed error="upload failed" count=123792026/10/08 12:57:49 INFO Uploading batch count=223802026/10/08 12:57:49 ERROR Upload failed error="upload failed" count=223812026/10/08 12:57:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2276569081/002/e2382--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)23832026/10/08 12:57:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2276569081/002/f23842026/10/08 12:57:49 ERROR Drain finished with paths left in queue remaining=123852026/10/08 12:57:49 ERROR Drain finished with paths left in queue remaining=102386--- PASS: TestDrainIsolatesPoisonPath (0.03s)2387--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2388--- PASS: TestWorkerSkipsGCdPaths (0.04s)2389--- PASS: TestWorkerPrunesClosureDeps (0.04s)2390--- PASS: TestWorkerUploadsAndRemoves (0.04s)2391--- PASS: TestQueueRemoveLargeClosure (0.07s)23922026/10/08 12:57:49 ERROR Upload failed error="context deadline exceeded" count=223932026/10/08 12:57:49 ERROR Drain finished with paths left in queue remaining=42394--- PASS: TestDrainTimeout (0.22s)2395--- PASS: TestQueueConcurrentWriters (0.38s)23962026/10/08 12:57:50 INFO Uploading batch count=123972026/10/08 12:57:50 INFO Uploading batch count=123982026/10/08 12:57:50 INFO Uploading batch count=123992026/10/08 12:57:50 ERROR Upload failed error="upload failed" count=124002026/10/08 12:57:50 INFO Uploading batch count=124012026/10/08 12:57:50 ERROR Upload failed error="upload failed" count=124022026/10/08 12:57:50 INFO Uploading batch count=124032026/10/08 12:57:50 ERROR Upload failed error="upload failed" count=124042026/10/08 12:57:50 INFO Uploading batch count=124052026/10/08 12:57:50 ERROR Upload failed error="upload failed" count=124062026/10/08 12:57:50 ERROR Drain finished with paths left in queue remaining=12407--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2408PASS2409Running signing tests...2410=== RUN TestExternalSigner2411=== PAUSE TestExternalSigner2412=== RUN TestExternalSignerWrongPublicKey2413=== PAUSE TestExternalSignerWrongPublicKey2414=== RUN TestExternalSignerErrors2415=== PAUSE TestExternalSignerErrors2416=== RUN TestExternalSignerRestartsAfterCrash2417=== PAUSE TestExternalSignerRestartsAfterCrash2418=== RUN TestExternalSignerProgramErrorKeepsProcess2419=== PAUSE TestExternalSignerProgramErrorKeepsProcess2420=== RUN TestExternalSignerClose2421=== PAUSE TestExternalSignerClose2422=== RUN TestExternalSignerRejectsInvalidPublicKey2423=== PAUSE TestExternalSignerRejectsInvalidPublicKey2424=== RUN TestExternalSignerCancellation2425=== PAUSE TestExternalSignerCancellation2426=== RUN TestGenerateFingerprint2427=== PAUSE TestGenerateFingerprint2428=== RUN TestParseSigningKey2429=== PAUSE TestParseSigningKey2430=== RUN TestSign2431=== PAUSE TestSign2432=== RUN TestSignBatch2433=== PAUSE TestSignBatch2434=== RUN TestNilKeyPublicKey2435=== PAUSE TestNilKeyPublicKey2436=== RUN TestSignErrors2437=== PAUSE TestSignErrors2438=== CONT TestExternalSigner2439=== CONT TestExternalSignerCancellation2440=== CONT TestSignBatch2441=== CONT TestExternalSignerProgramErrorKeepsProcess2442=== CONT TestExternalSignerRejectsInvalidPublicKey2443=== RUN TestExternalSignerRejectsInvalidPublicKey/#002444=== CONT TestExternalSignerClose2445=== CONT TestSignErrors2446=== CONT TestParseSigningKey2447=== CONT TestSign2448=== CONT TestNilKeyPublicKey2449=== CONT TestExternalSignerErrors2450=== CONT TestExternalSignerRestartsAfterCrash2451=== CONT TestGenerateFingerprint2452=== CONT TestExternalSignerWrongPublicKey2453=== RUN TestParseSigningKey/valid_32-byte_key2454=== PAUSE TestParseSigningKey/valid_32-byte_key2455=== RUN TestGenerateFingerprint/basic_with_references2456=== PAUSE TestGenerateFingerprint/basic_with_references2457=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2458=== RUN TestExternalSignerErrors/wrong_id2459=== PAUSE TestExternalSignerErrors/wrong_id2460=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2461=== RUN TestParseSigningKey/no_colon2462=== PAUSE TestParseSigningKey/no_colon2463=== RUN TestParseSigningKey/empty_name2464=== RUN TestSignErrors/nil_key2465--- PASS: TestNilKeyPublicKey (0.00s)2466--- PASS: TestSign (0.00s)2467--- PASS: TestSignBatch (0.00s)2468=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002469=== PAUSE TestParseSigningKey/empty_name2470=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2471=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2472=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2473=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2474=== RUN TestParseSigningKey/invalid_base642475=== RUN TestExternalSignerErrors/too_few_signatures2476=== PAUSE TestExternalSignerErrors/too_few_signatures2477=== PAUSE TestSignErrors/nil_key2478=== RUN TestGenerateFingerprint/no_references2479=== PAUSE TestGenerateFingerprint/no_references2480=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2481=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2482=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2483=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2484=== CONT TestExternalSignerRejectsInvalidPublicKey/#002485=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2486=== PAUSE TestParseSigningKey/invalid_base642487=== RUN TestParseSigningKey/wrong_length2488=== PAUSE TestParseSigningKey/wrong_length2489=== CONT TestParseSigningKey/valid_32-byte_key2490=== RUN TestExternalSignerErrors/exit_on_request2491=== PAUSE TestExternalSignerErrors/exit_on_request2492=== RUN TestExternalSignerErrors/invalid_JSON2493=== PAUSE TestExternalSignerErrors/invalid_JSON2494=== RUN TestSignErrors/nil_narinfo2495=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2496=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2497=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2498=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2499=== RUN TestGenerateFingerprint/invalid_nar_hash_length2500=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2501=== RUN TestGenerateFingerprint/invalid_store_path_prefix2502=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2503=== RUN TestGenerateFingerprint/invalid_reference_prefix2504=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2505=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2506=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2507=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2508=== CONT TestParseSigningKey/empty_name2509=== CONT TestParseSigningKey/wrong_length2510=== CONT TestParseSigningKey/invalid_base642511=== CONT TestParseSigningKey/no_colon2512=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2513=== RUN TestExternalSignerErrors/missing_signatures2514=== PAUSE TestSignErrors/nil_narinfo2515=== RUN TestSignErrors/invalid_narinfo2516=== CONT TestGenerateFingerprint/basic_with_references2517=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2518=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2519=== CONT TestGenerateFingerprint/invalid_nar_hash_length2520=== CONT TestGenerateFingerprint/no_references2521=== CONT TestGenerateFingerprint/invalid_store_path_prefix2522=== CONT TestGenerateFingerprint/invalid_reference_prefix2523--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2524 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2525 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2526 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2527 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2528 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2529--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2530--- PASS: TestParseSigningKey (0.00s)2531 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2532 --- PASS: TestParseSigningKey/empty_name (0.00s)2533 --- PASS: TestParseSigningKey/wrong_length (0.00s)2534 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2535 --- PASS: TestParseSigningKey/no_colon (0.00s)2536 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2537=== PAUSE TestExternalSignerErrors/missing_signatures2538--- PASS: TestExternalSignerClose (0.00s)2539=== PAUSE TestSignErrors/invalid_narinfo2540=== RUN TestSignErrors/canceled2541=== PAUSE TestSignErrors/canceled2542=== CONT TestSignErrors/nil_key2543=== CONT TestSignErrors/invalid_narinfo2544=== RUN TestExternalSignerErrors/null_signatures2545=== PAUSE TestExternalSignerErrors/null_signatures2546=== RUN TestExternalSignerErrors/unrequested_key2547=== PAUSE TestExternalSignerErrors/unrequested_key2548=== RUN TestExternalSignerErrors/missing_signature_name2549=== PAUSE TestExternalSignerErrors/missing_signature_name2550=== RUN TestExternalSignerErrors/wrong_signature_length2551=== CONT TestSignErrors/canceled2552--- PASS: TestGenerateFingerprint (0.00s)2553 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2554 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2555 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2556 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2557 --- PASS: TestGenerateFingerprint/no_references (0.00s)2558 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2559 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2560=== CONT TestSignErrors/nil_narinfo2561--- PASS: TestExternalSignerWrongPublicKey (0.00s)2562=== PAUSE TestExternalSignerErrors/wrong_signature_length2563=== RUN TestExternalSignerErrors/exit_at_startup2564=== PAUSE TestExternalSignerErrors/exit_at_startup2565=== RUN TestExternalSignerErrors/wrong_shape2566--- PASS: TestSignErrors (0.00s)2567 --- PASS: TestSignErrors/nil_key (0.00s)2568 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2569 --- PASS: TestSignErrors/canceled (0.00s)2570 --- PASS: TestSignErrors/nil_narinfo (0.00s)2571=== PAUSE TestExternalSignerErrors/wrong_shape2572=== RUN TestExternalSignerErrors/null2573=== PAUSE TestExternalSignerErrors/null2574=== RUN TestExternalSignerErrors/wrong_signatures_shape2575=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2576=== RUN TestExternalSignerErrors/wrong_signature_name2577=== PAUSE TestExternalSignerErrors/wrong_signature_name2578=== RUN TestExternalSignerErrors/program_error2579=== PAUSE TestExternalSignerErrors/program_error2580=== RUN TestExternalSignerErrors/invalid_signature_base642581=== PAUSE TestExternalSignerErrors/invalid_signature_base642582=== CONT TestExternalSignerErrors/wrong_id2583=== CONT TestExternalSignerErrors/wrong_signature_length2584=== CONT TestExternalSignerErrors/invalid_signature_base642585=== CONT TestExternalSignerErrors/program_error2586=== CONT TestExternalSignerErrors/wrong_signature_name2587=== CONT TestExternalSignerErrors/wrong_shape2588=== CONT TestExternalSignerErrors/null2589=== CONT TestExternalSignerErrors/exit_at_startup2590=== CONT TestExternalSignerErrors/missing_signatures2591=== CONT TestExternalSignerErrors/missing_signature_name2592=== CONT TestExternalSignerErrors/wrong_signatures_shape2593=== CONT TestExternalSignerErrors/unrequested_key2594=== CONT TestExternalSignerErrors/null_signatures2595=== CONT TestExternalSignerErrors/exit_on_request2596=== CONT TestExternalSignerErrors/invalid_JSON2597=== CONT TestExternalSignerErrors/too_few_signatures2598--- PASS: TestExternalSigner (0.01s)2599--- PASS: TestExternalSignerCancellation (0.03s)2600--- PASS: TestExternalSignerRestartsAfterCrash (0.03s)2601--- PASS: TestExternalSignerErrors (0.00s)2602 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2603 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.02s)2604 --- PASS: TestExternalSignerErrors/program_error (0.02s)2605 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.02s)2606 --- PASS: TestExternalSignerErrors/wrong_id (0.02s)2607 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.02s)2608 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2609 --- PASS: TestExternalSignerErrors/exit_at_startup (0.02s)2610 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2611 --- PASS: TestExternalSignerErrors/exit_on_request (0.02s)2612 --- PASS: TestExternalSignerErrors/null_signatures (0.02s)2613 --- PASS: TestExternalSignerErrors/missing_signatures (0.02s)2614 --- PASS: TestExternalSignerErrors/null (0.02s)2615 --- PASS: TestExternalSignerErrors/missing_signature_name (0.02s)2616 --- PASS: TestExternalSignerErrors/unrequested_key (0.02s)2617 --- PASS: TestExternalSignerErrors/wrong_shape (0.02s)2618PASS2619Running OpenBao signer tests...2620=== RUN TestSign2621=== PAUSE TestSign2622=== RUN TestSignErrors2623=== PAUSE TestSignErrors2624=== RUN TestServe2625=== PAUSE TestServe2626=== RUN TestServeRejectsGarbage2627=== PAUSE TestServeRejectsGarbage2628=== CONT TestSign2629=== CONT TestServeRejectsGarbage2630=== CONT TestSignErrors2631--- PASS: TestServeRejectsGarbage (0.00s)2632=== CONT TestServe2633=== RUN TestSignErrors/invalid_json2634=== PAUSE TestSignErrors/invalid_json2635=== RUN TestSignErrors/no_prefix2636=== PAUSE TestSignErrors/no_prefix2637=== RUN TestSignErrors/invalid_base642638=== PAUSE TestSignErrors/invalid_base642639=== RUN TestSignErrors/http_error2640--- PASS: TestServe (0.00s)2641=== PAUSE TestSignErrors/http_error2642=== CONT TestSignErrors/invalid_json2643=== CONT TestSignErrors/no_prefix2644=== CONT TestSignErrors/invalid_base642645=== CONT TestSignErrors/http_error2646--- PASS: TestSign (0.00s)2647--- PASS: TestSignErrors (0.00s)2648 --- PASS: TestSignErrors/http_error (0.00s)2649 --- PASS: TestSignErrors/no_prefix (0.00s)2650 --- PASS: TestSignErrors/invalid_base64 (0.00s)2651 --- PASS: TestSignErrors/invalid_json (0.00s)2652PASS